Rails 解决 Rails 项目容器化途中日志时差问题
这是笔者对项目进行容器化的时候发现的，简单写个文章来记录一下。
容器里的日志时间跟当前时间对不上
以下是我的 Rails 项目的Dockfile文件全貌
FROM ruby:2.7.2
RUN curl https://deb.nodesource.com/setup_14.x | bash
RUN apt-get update && apt-get install -y nodejs postgresql-client
RUN npm install --global yarn
RUN mkdir /app
WORKDIR /app
COPY Gemfile Gemfile.lock ./
RUN gem install bundler
# RUN bundle config set force_ruby_platform true
RUN bundle install
RUN yarn install
COPY . .
ENV RAILS_ENV=production
RUN rails assets:precompile
EXPOSE 3000
CMD ["rails", "server", "-b", "0.0.0.0"]
通过命令
> docker build -t lanzhiheng/stone .
就能构建出想要的镜像，先把项目跑起来
> docker run -it -p 4000:3000 lanzhiheng/stone
有意思的事情来了，我随便贴几条日志
I, [2022-12-26T14:17:24.775420 #1] INFO -- : [be1b63ce-4696-4f70-acd9-425c37bd9f0e] Processing by HomeController#index as HTML
D, [2022-12-26T14:17:24.799921 #1] DEBUG -- : [be1b63ce-4696-4f70-acd9-425c37bd9f0e] Rendering layout layouts/application.html.erb
D, [2022-12-26T14:17:24.801253 #1] DEBUG -- : [be1b63ce-4696-4f70-acd9-425c37bd9f0e] Rendering home/index.html.erb within layouts/application
笔者请求发送于北京时间2022-12-26 22:17:24，然而日志记录到的时间是2022-12-26 14:17:24相差了整整八个小时，如果没猜错容器里面使用的时间应该是格林威治时间，也就是常说的零时区。然而我查了一下 Rails 的配置
> docker run -it lanzhiheng/stone bin/rails c
> Rails.application.config.time_zone
=> "Asia/Shanghai"
> Time.current
=> Mon, 26 Dec 2022 22:23:06.614421836 CST +08:00
确认已经设置好东八区，这么看来，日志系统所认的时区可能跟 Rails 本身的设置没有太大关系。
Time.now 还是 Time.current
从 Rails 的配置信息可知，Rails 的默认日志系统会依赖于Logger::Formatter
> Rails.application.config.log_formatter
=> #<Logger::Formatter:0x000000010ad622d8 @datetime_format=nil>
这是 Ruby 标准库所定义的类，再去窥探一下 Ruby 标准库的源代码，发现每次写日志都会调用这行代码
...
@logdev.write(
format_message(format_severity(severity), Time.now, progname, message))
调用的时候会获取当前时间。真相大白了，看来日志的时间是按照Time.now来定，而不是笔者直觉所认为的Time.current。
刚开始接触 Rails 的时候，有个前辈就告知我Time.now跟Time.current的不同。简单来说Time.current会根据 Rails 系统设置的时区来返回当前时间，而Time.now则不会。为啥这样？其实也很简单，毕竟Time.current是 Rails 引入的扩展方法，而Time.now是 Ruby 标准库里面固有的方法。
> irb
> Time.now
=> 2022-12-26 22:28:15.066059 +0800
> Time.current
Traceback (most recent call last):
.....
NoMethodError (undefined method `current' for Time:Class)
标准库本来就有的东西，确实没必要认 Rails 体系所设置的时区信息，它始终以所在系统时区为准。在 Rails 上下文中测试，两者确实是足足差了 8 个小时。
> bin/rails c
> Time.current
=> Mon, 26 Dec 2022 22:29:37.818203586 CST +08:00
> Time.now
=> 2022-12-26 14:29:39.691374504 +0000
简单解决一下
要解决这个问题其实也简单，毕竟容器技术的优势就在于我们可以灵活把控运行时的系统环境。既然Time.now是根据系统的时区来返回当前时间，我们只需要把系统强行设置成东八区即可。简单修改Dockerfile文件就能做到这一点
...
RUN mkdir /app
WORKDIR /app
COPY Gemfile Gemfile.lock ./
+
+ENV TZ="Asia/Shanghai"
+
RUN gem install bundler
...
添加一行来设置环境变量TZ="Asia/Shanghai"，就能让我们得到一台时区为东八区的机器。我们在“新的机器”上再运行目标服务，应该就能看到上面的日志时间跟你自己电脑上的时间能对得上了。
> docker run -it -p 4000:3000 lanzhiheng/stone
看看这次日志对不对
D, [2022-12-28T21:48:08.376092 #1] DEBUG -- : [f01bea0d-a85b-4f85-b67a-1e9cfdb27801] Rendered application/_header.html.erb (Duration: 496.8ms | Allocations: 26874)
I, [2022-12-28T21:48:08.376501 #1] INFO -- : [f01bea0d-a85b-4f85-b67a-1e9cfdb27801] Rendered layout layouts/application.html.erb (Duration: 521.9ms | Allocations: 30795)
I, [2022-12-28T21:48:08.377159 #1] INFO -- : [f01bea0d-a85b-4f85-b67a-1e9cfdb27801] Completed 404 Not Found in 526ms (Views: 268.9ms | ActiveRecord: 256.2ms | Allocations: 31453)
这次就正常了，容器内外的时差消失了。笔者确实是在北京时间2022-12-28 21:48:08发送的请求。
总结
项目的容器化之路是一条不归路，路途十分遥远且艰难，有数不尽的深坑在前方等待。镜像所导致的日志时差问题仅仅是迈向深坑之前的一点小磕碰。笔者简单记录，并解决一下，读者请酌情参考。
