googleapis / googleapis/google-cloud-ruby
logging: The mismatch of timing of replaceing the Rails default logger with Google::Cloud::Logging::Logger
- Ngôn ngữ chính
- Ruby
- Star
- 1.4k
- Fork
- 578
- Merge trung bình
- 1 ngày 11 giờ
- Pull request đã merge (30 ngày)
- 166
Mô tả
## Overview
When`Logging.configure.set_default_logger_on_rails_init` is `false`
various loggers in Rails framework(such as `ActiveRecord::Base.logger`) will not be replaced with `Google::Cloud::Logging::Logger`.
This may be because it is too late to replace the Rails default logger with `Google::Cloud::Logging::Logger`.
parhaps related: https://github.com/googleapis/google-cloud-ruby/issues/4510
On the other hand, when `Logging.configure.set_default_logger_on_rails_init` is `true`,
it is too early to replace the Rails default logger.
We got an error trying to reference `Rails.logger.level` when `Rails.logger` is uninitialized.
## Detail
When rails app requires [google/cloud/logging/rails](https://github.com/googleapis/google-cloud-ruby/blob/5da8dc88a4c0b6f101043c8b35ec4ae8627f0b31/google-cloud-logging/lib/google/cloud/logging/rails.rb), the cloud logging initializer will be set as `Railtie#initializer`.
This initializer runs `init_middleware`. In `init_middleware` method,
#### 1. If `Logging.configure.set_default_logger_on_rails_init = false`(default)
`set_default_logger` will be called later.
`Google::Cloud::Logging::Middleware` will be loaded into rack middleware. After rack middlewares were build, then `init_callback` will be called, and `Rails.logger` will be replaced with `Google::Cloud::Logging::Logger` in `set_default_logger` method.
However, when `init_callback` is called, various loggers in Rails framework are already initialized and never will be replaced.
for example:
* https://github.com/rails/rails/blob/v6.1.4.1/activerecord/lib/active_record/railtie.rb#L77-L79
* https://github.com/rails/rails/blob/v6.1.4.1/actionview/lib/action_view/railtie.rb#L58-L60
This is perhaps because Rack middlewares are loaded after `Railtie#initializer` .
https://github.com/rails/rails/blob/90357af08048ef5076730505f6e7b14a81f33d0c/railties/lib/rails/application.rb#L48-L59
#### 2. If `Logging.configure.set_default_logger_on_rails_init = true`
`set_default_logger` is called immediately.
https://github.com/googleapis/google-cloud-ruby/blob/5da8dc88a4c0b6f101043c8b35ec4ae8627f0b31/google-cloud-logging/lib/google/cloud/logging/rails.rb#L82
But at this point, `Rails.logger` is undefined, because `init_middleware` is called before initialize_logger.
So `NoMethodError: undefined method `level' for nil:NilClass` is raised here.
https://github.com/googleapis/google-cloud-ruby/blob/5da8dc88a4c0b6f101043c8b35ec4ae8627f0b31/google-cloud-logging/lib/google/cloud/logging/rails.rb#L120
#### Environment details
- OS: [ruby:3.0.2-slim-buster](https://hub.docker.com/layers/ruby/library/ruby/3.0.2-slim-buster/images/sha256-64d8b5be06054b8b4c79b8c01dec6776401552eebaf91f36ee70be3b3d3d0515?context=explore)
- Ruby version: 3.0.2
- Rails version: 6.1.4.1
- Gem name and version: google-cloud-logging (2.2.2)
#### Steps to reproduce
#### 1. If `Logging.configure.set_default_logger_on_rails_init = false`(default)
1. ` bundle exec rails new sample -d mysql --api`
2. `cd sample`
3. `bundle add google-cloud-logging`
4. make some controller/action
5. require in `config/application.rb` before `Bundler.require`
```rb
require "google/cloud/logging/rails"
```
6. configure in `config/environments/development.rb`
```rb
config.google_cloud.use_logging = true
config.google_cloud.project_id = "someproject"
config.google_cloud.keyfile = "/opt/config.json"
config.google_cloud.logging.log_name = "some_name"
```
7. run server and access the url
8. Got log in Cloud Logging: `Started GET "/" for 127.0.0.1 at 2021-12-02 07:34:43 +0000`, but got other logs in local `log/development.log`
#### 2. `Logging.configure.set_default_logger_on_rails_init = true`
9. add `config.google_cloud.logging.set_default_logger_on_rails_init = true` in `config/environments/development.rb`
10. run server, and got Error:
```
/usr/local/bundle/gems/google-cloud-logging-2.2.2/lib/google/cloud/logging/rails.rb:120:in `set_default_logger': undefined method `level' for nil:NilClass (NoMethodError)
from /usr/local/bundle/gems/google-cloud-logging-2.2.2/lib/google/cloud/logging/rails.rb:82:in `init_middleware'
from /usr/local/bundle/gems/google-cloud-logging-2.2.2/lib/google/cloud/logging/rails.rb:59:in `block in '
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/initializable.rb:32:in `instance_exec'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/initializable.rb:32:in `run'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/initializable.rb:61:in `block in run_initializers'
from /usr/local/lib/ruby/3.0.0/tsort.rb:228:in `block in tsort_each'
from /usr/local/lib/ruby/3.0.0/tsort.rb:350:in `block (2 levels) in each_strongly_connected_component'
from /usr/local/lib/ruby/3.0.0/tsort.rb:422:in `block (2 levels) in each_strongly_connected_component_from'
from /usr/local/lib/ruby/3.0.0/tsort.rb:431:in `each_strongly_connected_component_from'
from /usr/local/lib/ruby/3.0.0/tsort.rb:421:in `block in each_strongly_connected_component_from'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/initializable.rb:50:in `each'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/initializable.rb:50:in `tsort_each_child'
from /usr/local/lib/ruby/3.0.0/tsort.rb:415:in `call'
from /usr/local/lib/ruby/3.0.0/tsort.rb:415:in `each_strongly_connected_component_from'
from /usr/local/lib/ruby/3.0.0/tsort.rb:349:in `block in each_strongly_connected_component'
from /usr/local/lib/ruby/3.0.0/tsort.rb:347:in `each'
from /usr/local/lib/ruby/3.0.0/tsort.rb:347:in `call'
from /usr/local/lib/ruby/3.0.0/tsort.rb:347:in `each_strongly_connected_component'
from /usr/local/lib/ruby/3.0.0/tsort.rb:226:in `tsort_each'
from /usr/local/lib/ruby/3.0.0/tsort.rb:205:in `tsort_each'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/initializable.rb:60:in `run_initializers'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/application.rb:391:in `initialize!'
from /app/sample/config/environment.rb:5:in `'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `require'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `block in require_with_bootsnap_lfi'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/loaded_features_index.rb:100:in `register'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22:in `require_with_bootsnap_lfi'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:31:in `require'
from /usr/local/bundle/gems/zeitwerk-2.5.1/lib/zeitwerk/kernel.rb:35:in `require'
from /usr/local/bundle/gems/activesupport-6.1.4.1/lib/active_support/dependencies.rb:332:in `block in require'
from /usr/local/bundle/gems/activesupport-6.1.4.1/lib/active_support/dependencies.rb:299:in `load_dependency'
from /usr/local/bundle/gems/activesupport-6.1.4.1/lib/active_support/dependencies.rb:332:in `require'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:54:in `require_relative'
from config.ru:3:in `block in '
from /usr/local/bundle/gems/rack-2.2.3/lib/rack/builder.rb:116:in `eval'
from /usr/local/bundle/gems/rack-2.2.3/lib/rack/builder.rb:116:in `new_from_string'
from /usr/local/bundle/gems/rack-2.2.3/lib/rack/builder.rb:105:in `load_file'
from /usr/local/bundle/gems/rack-2.2.3/lib/rack/builder.rb:66:in `parse_file'
from /usr/local/bundle/gems/rack-2.2.3/lib/rack/server.rb:349:in `build_app_and_options_from_config'
from /usr/local/bundle/gems/rack-2.2.3/lib/rack/server.rb:249:in `app'
from /usr/local/bundle/gems/rack-2.2.3/lib/rack/server.rb:422:in `wrapped_app'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/commands/server/server_command.rb:77:in `log_to_stdout'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/commands/server/server_command.rb:37:in `start'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/commands/server/server_command.rb:144:in `block in perform'
from :90:in `tap'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/commands/server/server_command.rb:135:in `perform'
from /usr/local/bundle/gems/thor-1.1.0/lib/thor/command.rb:27:in `run'
from /usr/local/bundle/gems/thor-1.1.0/lib/thor/invocation.rb:127:in `invoke_command'
from /usr/local/bundle/gems/thor-1.1.0/lib/thor.rb:392:in `dispatch'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/command/base.rb:69:in `perform'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/command.rb:48:in `invoke'
from /usr/local/bundle/gems/railties-6.1.4.1/lib/rails/commands.rb:18:in `'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `require'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:23:in `block in require_with_bootsnap_lfi'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/loaded_features_index.rb:100:in `register'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:22:in `require_with_bootsnap_lfi'
from /usr/local/bundle/gems/bootsnap-1.9.3/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:31:in `require'
from /app/sample/bin/rails:5:in `'
from /usr/local/bundle/gems/spring-3.1.1/lib/spring/client/rails.rb:30:in `load'
from /usr/local/bundle/gems/spring-3.1.1/lib/spring/client/rails.rb:30:in `call'
from /usr/local/bundle/gems/spring-3.1.1/lib/spring/client/command.rb:7:in `call'
from /usr/local/bundle/gems/spring-3.1.1/lib/spring/client.rb:30:in `run'
from /usr/local/bundle/gems/spring-3.1.1/bin/spring:49:in `'
from /usr/local/bundle/gems/spring-3.1.1/lib/spring/binstub.rb:11:in `load'
from /usr/local/bundle/gems/spring-3.1.1/lib/spring/binstub.rb:11:in `'
from /app/sample/bin/spring:10:in `require'
from /app/sample/bin/spring:10:in `block in '
from :90:in `tap'
from /app/sample/bin/spring:7:in `'
from bin/rails:2:in `load'
from bin/rails:2:in `'
```
#### Code example
described above
#### Full backtrace
described above
Hướng dẫn đóng góp
Hướng nghiên cứu
Bắt đầu trong google-cloud-logging/lib/google/cloud/logging/rails.rb, đặc biệt là Railtie initializer, init_middleware và set_default_logger. Tái hiện cả hai thiết lập của set_default_logger_on_rails_init với ví dụ Rails 6.1.4.1 và kiểm tra thứ tự initializer được mô tả trong issue. Được xem là hoàn tất khi Rails khởi động mà không có lỗi nil logger và các logger framework Rails liên quan được thay thế như dự kiến.
Do mô hình lập chỉ mục viết ra từ nội dung của issue.
Đánh giá
- Công nghệ
- rails, ruby
- Lĩnh vực
- observability
- Loại issue
- Lỗi
- Độ khó
- 4/5
- Thời gian dự kiến
- 3-5 ngày
- Mức độ hoạt động
- Đình trệ
- Độ rõ ràng
- Khá rõ ràng
- Mức phù hợp với người mới
- 35/100