zormandi / logcraft

A zero-configuration structured logging solution for pure Ruby or Ruby on Rails projects.
MIT License
36 stars 2 forks source link

duplicate logs in rails console #7

Open michael-groble opened 7 months ago

michael-groble commented 7 months ago

I'm not sure if it's something I can configure or something related to the implementation of logcraft. When I use "plain" rails logging in the console, I get one line:

$ bin/rails c
Loading development environment (Rails 7.1.2)
irb(main):001> Rails.logger.info('hiya');
hiya

but when I use logcraft, I get two:

$ bin/rails c
Loading development environment (Rails 7.1.2)
irb(main):001> Rails.logger.info('hiya');
{"timestamp":"2023-12-09T08:59:33.540-06:00","level":"INFO","logger":"Application","hostname":"MBP.localdomain","pid":123,"message":"hiya"}
hiya

I'd love to figure out a way to hide/remove that second line (which looks more confusing when you log a hash instead of a plain string)

Note, this is only an issue in the console:

$ bin/rails runner "Rails.logger.info('hiya')"
{"timestamp":"2023-12-09T09:07:48.477-06:00","level":"INFO","logger":"Application","hostname":"MBP.localdomain","pid":138,"message":"hiya"}
$
zormandi commented 6 months ago

Okay, so I finally figured out where the additional line comes from; it's ActiveRecord. For some reason, if you're running a console then it forces an ActiveSupport::Logger onto the stack: https://github.com/rails/rails/blob/9280ad25f7d97cd700080f1adf87f0a9a8ce1702/activerecord/lib/active_record/railtie.rb#L70

I'm trying to figure out how to prevent this without having to override configuration that's meant to be customizable.

zormandi commented 6 months ago

I pushed a fix to main - feel free to give it a whirl. I'll release it in a couple of days with - hopefully - another issue fix.

michael-groble commented 6 months ago

yes @zormandi that does the trick for me. thanks!!

zormandi commented 6 months ago

New version is released with the fix.