Request: Change Log Level for Middleware Request Logging

[lukasrabener]

Description
Currently, wfx logs request in the middleware logging function with info level. This can result in excessive log noise in production environments.

wfx/middleware/logging/log.go

Line 76 in 8cc2b1f

contextLogger.Info().

Suggested Change
Modify the log level from info to debug to reduce unnecessary log volume in production while still allowing detailed request logging for debugging purposes.

[stormc]

This is the (sane) default. You can change that default log level via command line parameters (e.g., wfx --log-level panic, see wfx –help) or via a yaml configuration file (for locations, see here) in which you put, e.g., log-level: warn. Configuration files even hot-load so that you can change logging on the fly without downtime.

[michaeladler]

Alternatively, we could consider introducing a dedicated access log, similar to what Nginx uses. This access log could be turned off or redirected to /dev/null (to be determined). Would that solve your issue?

[stormc]

Alternatively, we could consider introducing a dedicated access log, [...]

Hm, I would not want to go that route: It's pretty standard nowadays with systemd (and others) to have services "log" to stdout / stderr with the service supervisor capturing their output in a proper logging system such as journald. What we may do, however, is to massage the logging format a bit to be more structured such as, e.g., prefixing a log line with <%d> signaling the log line's severity...

[lukasrabener]

for me wfx --log-level warning will just work fine, although i will loose other info level logs with that. I just wanted to mention that maybe debug level would be enough for this request logging, but maybe that is just my personal preference.

Also i will make use of SSE to reduce the number of requests to wfx from our client in future, until than i will use the --log-level option. Thanks for reaching out

[stormc]

Hm, can you explain what it is that you want to see in the logs, i.e., what the behavior should be? Seems like you want "subsystems" to have different log levels, inferred from your description of running with warning and then not seeing info logs?

[michaeladler]

I think the main goal is to reduce the log output/noise (but preserving all the other useful INFO messages), especially when many clients (e.g., thousands) poll every X seconds for new jobs (this feedback was also given during a conference).

It's pretty standard nowadays with systemd (and others) to have services "log" to stdout/stderr with the service supervisor capturing their output in a proper logging system such as journald.

Yes, this isn't a contradiction though. We could, for example, dedicate stderr for the access log. Currently, we use stdout for logging and stderr for early failures when logging might not be set up yet.

What we may do, however, is to massage the logging format a bit to be more structured such as, e.g., prefixing a log line with <%d> signaling the log line's severity...

We already support JSON as a structured logging format, which is compatible with popular log aggregation tools. I agree that logging in a structured way to journald would be beneficial, and I've prepared a MR (see #295) for this. However, this doesn't directly address the original poster's issue, because the "noise" is still there.

[lukasrabener]

I think the main goal is to reduce the log output/noise (but preserving all the other useful INFO messages), especially when many clients (e.g., thousands) poll every X seconds for new jobs (this feedback was also given during a conference).

exactly