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

I believe it would make more sense for this to be a single log line, not 3. #5680

Open
ioquatix opened this issue Dec 2, 2022 · 13 comments
Open

Comments

@ioquatix
Copy link

ioquatix commented Dec 2, 2022

https://github.com/mperham/sidekiq/blob/8e3f8f50727914e4c74f4bb41539131d4161cfed/lib/sidekiq/config.rb#L39-L41

Logs often get combined into a log stream, and without enough context, these three lines will get lost.

We are currently providing our own error handler, but it was surprising to see the default.

@mperham
Copy link
Collaborator

mperham commented Dec 2, 2022

The default is meant to be useful for development. Many people switch to json logging in production for example. Do you have suggestions for improving the default?

@ioquatix
Copy link
Author

ioquatix commented Dec 2, 2022

Let me think about this, I'll test a few options.

@mperham mperham closed this as completed Jan 11, 2023
@ioquatix
Copy link
Author

Was anything done to fix this or was the issue just closed without being completed?

@mperham
Copy link
Collaborator

mperham commented Jan 11, 2023

Nothing was done, I considered this stale.

@ioquatix
Copy link
Author

The problem still exists?

@mperham
Copy link
Collaborator

mperham commented Jan 11, 2023

What problem? This is a matter of taste and opinion. If you aren't going to move the ball forward, I'm not going to do it for you; I'm fine with it as is.

@ioquatix
Copy link
Author

ioquatix commented Jan 11, 2023

In a cluster of 80 instances, the context often gets lost as the log lines are not always kept together.

It would make more sense IMHO for this to be a single log line.

Ideally, it's a single log line so that the context and error message are kept together.

We are also paying for Sidekiq support - is there a better channel to raise this through?

@mperham
Copy link
Collaborator

mperham commented Jan 11, 2023

Putting it on one line could make it unreadable, no? This logging is primarily meant for localhost development, I've always strongly urged people to use an error service in production.

As I said, I'm open to suggestions for improvement but nobody followed up. Are you suggesting something as simple as replacing the three log.warn calls with one? Do you want to send a PR?

@ioquatix
Copy link
Author

The best we can do right now with the current logger gem interface is use newlines to encode the message with sufficient details. I think that's probably better than what we have as a default, but as you said, people are mostly just replacing it. But it would be nice if the logger interface was rich enough to actually handle these cases, and format errors in a consistent way. It's not uncommon to run into logging code that tries to format errors (backtrace, etc) but it's not ideal for every app to have a bespoke implementation of this behaviour (all slightly different as you'd imagine). It also doesn't take advantage of output formatting (e.g. encoding the backtrace as an array for JSON, or use xterm colors, etc).

I'd suggest there are two options here:

  1. Do nothing.
  2. Newline encoding of the message.

However, I'd personally suggest we explore expanding the Ruby logger gem interface to have a richer interface. Basically, that gem is holding back the entire eco-system of advanced logging in Ruby. The alternative is to use a custom logger gem but none of them have the same level of utilization as the logger gem. If you wanted a more advanced logger, for example, I use https://rubygems.org/gems/console/ for all my own projects (and we now have a sidekiq adapter for it).

My general thought is we should separate logging the interface vs logging the implementation. Unfortunately the logger gem in Ruby does not do a good job of that and is also used poorly in practice.

@mperham mperham reopened this Jan 12, 2023
@mperham
Copy link
Collaborator

mperham commented Jan 12, 2023

I really don't want to choose between a dozen "advanced, modern" logger gems. Sidekiq already has a few monkeypatches for ::Logger to add things like Context and per-thread log levels; I'm reluctant to add any more customizations. If you want more functionality, I'd suggest opening an issue with ruby-core. Maybe they are open to moving Logger to a stdlib gem where you can add functionality.

I'm open to logging those three lines as one, as long as it doesn't make the development experience worse.

@ioquatix
Copy link
Author

Sidekiq already has a few monkeypatches for ::Logger to add things like Context and per-thread log levels

While I may agree with the specific use cases, this is generally a bad idea and I suggest you remove them, because it ossifies the core Logger gem interface and makes it hard to evolve. We had a lot of trouble making a compatible logger because of the bespoke interface. Rails does the same thing, but in different ways. It would be much better to either (1) wrap the logger interface with your own specific adapter or (2) upstream those interfaces to the logger gem.

@mperham
Copy link
Collaborator

mperham commented Jan 12, 2023

The issue is that a LOT of Sidekiq users do this:

Sidekiq.configure_server do |cfg|
  cfg.logger = ::Logger.new("/my/logfile.log")
end

making it hard to wrap. Logging is the #1 thing that people customize the most and it's hugely painful to maintain 100% compatibility with any change.

I agree that it would be good to upstream these changes. The main one is the per-thread log level, which should be easy to upstream. I will send a PR.

@mperham
Copy link
Collaborator

mperham commented Jan 12, 2023

ruby/logger#84

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

2 participants