Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Rails 5.2.2.1 tagged logger casts log attributes to string #77

Closed
calleo opened this issue May 14, 2019 · 7 comments
Closed

Rails 5.2.2.1 tagged logger casts log attributes to string #77

calleo opened this issue May 14, 2019 · 7 comments

Comments

@calleo
Copy link

calleo commented May 14, 2019

I am seeing some weird behavior using Rails 5.2.2.1. I have followed the setup guide on the wiki and integrated it with lograge.

The message payload (which is a hash) is turned into a string. This is how it looks in the log:

{"name":"rails","hostname":"computer.local","pid":19340,"level":30,"time":1557826080140,"v":1,"msg":"{:msg=>\"Request\", :request=>{:method=>\"GET\", :path=>\"/products/card\", :format=>\"*/*\", :controller=>\"ProductsController\", :action=>\"card\", :status=>200, :duration=>713.12, :view=>223.27, :db=>135.91}, :request_id=>\"dade881f-4fc7-4171-a503-2937d33fe648\"}"}

I noticed that ActiveSupport::TaggedLogging is required by other gems (like webpacker and active job) and it extends the Rails.logger (which is now my custom Ougai logger). The tagged logger converts the message to a string in its call method:

def call(severity, timestamp, progname, msg) super(severity, timestamp, progname, "#{tags_text}#{msg}") end

Any idea why I am seeing this problem and how to avoid it?

I solved it for now by monkey patching the tagged logger module, but that doesn't feel like a long term solution.

@calleo
Copy link
Author

calleo commented May 14, 2019

Ok, looks like an issue caused by webpacker: rails/webpacker#1155

@calleo
Copy link
Author

calleo commented May 14, 2019

Instead of monkey patching I added a 'tagged' method to my custom logger (inheriting from Ougai::Logger

def tagged(*tags)
  yield self
end

@flippakitten
Copy link

I ended up using SemanticLogger, which I really enjoy.

@tilfin
Copy link
Owner

tilfin commented May 14, 2019

I didn't know that ActionJob requires TaggedLogging. In the sense of supporting Rails, I think that there is nothing but to support the interface of TaggedLogging.

@tilfin
Copy link
Owner

tilfin commented May 14, 2019

@calleo I realized this complex problem. ActionJob can support a logger without TaggedLogging at https://github.com/rails/rails/blob/master/activejob/lib/active_job/logging.rb#L47 . But Webpacker forcely uses wrapping
Ougai::Logger by TaggedLogging at https://github.com/rails/webpacker/blob/master/lib/webpacker/railtie.rb#L77 and it causes the original logger instance to extend TaggedLogging.

@tilfin
Copy link
Owner

tilfin commented May 14, 2019

@calleo I think that this problem will be resolved on Rails 6 by rails/rails@62fba74#diff-f5b84c8292ccf226ce319abbd6953fa0R60 so I want you to use monkey patch at present.

@tilfin
Copy link
Owner

tilfin commented Jun 29, 2019

@tilfin tilfin closed this as completed Jun 29, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants