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

[22.05] Disable translogger middleware by default #14467

Merged
merged 1 commit into from
Aug 17, 2022

Conversation

natefoo
Copy link
Member

@natefoo natefoo commented Aug 16, 2022

Setting to draft for discussion, I have partially talked myself out of this

gunicorn/uvicorn have built in transaction (access) logging which makes the translogger middleware somewhat redundant. Also, because translogger sets up its own console logger, these messages are only written to stdout and thus only captured by methods that capture stdout (that means gunicorn with --error-logfile, but not custom Python logging setups like setting log_destination or the logging dict as in #14457). In the latter case, the access log is lost.

This change makes it so both ways of execution (default logging, custom/rotation logging) will produce the same log output in a single log file, via the standard Python logging mechanisms.

It is worth noting that translogger and uvicorn access log messages will be different:

# translogger
127.0.0.1 - - [16/Aug/2022:12:30:49 -0400] "GET / HTTP/1.1" 200 - "-" "curl/7.81.0"
# uvicorn
uvicorn.access INFO 2022-08-16 12:30:49,907 [pN:main.1,p:462180,tN:MainThread] 127.0.0.1:53896 - "GET / HTTP/1.1" 200

I couldn't see a way to set a formatter just for the gunicorn.access logger to override the format so it is just the bare "access log" style message but still have it logged to the same handler, since formatters are specified per-handler, not per-logger. This is not a big deal IMO. Also, the uvicorn access logger is missing the remote address, referer, and user-agent fields, and that is not currently fixable as per encode/uvicorn#527. I also don't know if it logs the remote IP or the proxy IP. This is a bigger deal and could be a motivation to keep translogger. That said, uvicorn logging is probably faster.

The motivation for access logs in the application logs are so that you can more easily correlate them with application log messages that may be relevant to that request. Having them in a separate file is not particularly useful IMO. Having a separate access log file is also essentially a duplication of the proxy's access log files.

If you want to disable the access log entries, you can do so with a custom logging config (as described in the Galaxy logging config docs) but replacing the gunicorn.access logger like so:

galaxy:
  logging:
    # ... other logging config stuff
    loggers:
      # ... other loggers
      gunicorn.access:
        level: WARNING
        handlers: [console]
        propagate: false

Alternatively, to log to a separate file, set up a handler (and in this example, a formatter, if you like):

galaxy:
  logging:
    # ... other logging config stuff
    formatters:
      # ... other formatters
      access:
        format: "%(message)s"
        class: logging.Formatter
    handlers:
      access_file:
        class: logging.FileHandler
        formatter: access
        level: INFO
        filename: /srv/galaxy/log/access.log
    loggers:
      # ... other loggers
      gunicorn.access:
        level: INFO
        handlers: [access_file]
        propagate: false
        qualname: gunicorn.access

Alternatively, to get translogger statements into non-captured logs we can initialize it with setup_console_handler=False. Then it appears in the default log format like so:

wsgi INFO 2022-08-16 13:45:02,093 [pN:main.1,p:467428,tN:WSGI_0] 127.0.0.1 - - [16/Aug/2022:13:45:02 -0400] "GET / HTTP/1.1" 200 - "-" "curl/7.81.0"

TL;DR we can have log rotation with Python's builtin logging facilities or we can have translogger but not both.

It might be possible with some hacking to translogger to get it to log to the "console" handler in the Galaxy logging config rather than its own.

How to test the changes?

(Select all options that apply)

  • I've included appropriate automated tests.
  • This is a refactoring of components with existing test coverage.
  • Instructions for manual testing are as follows:
    1. [add testing steps and prerequisites here if you didn't write automated tests covering all your changes]

License

  • I agree to license these contributions under Galaxy's current license.
  • I agree to allow the Galaxy committers to license these and all my past contributions to the core galaxy codebase under the MIT license. If this condition is an issue, uncheck and just let us know why with an e-mail to [email protected].

@mvdbeek
Copy link
Member

mvdbeek commented Aug 16, 2022

Let's disable translogger, it's also specific to WSGI routes, of which we have increasingly fewer.

@mvdbeek
Copy link
Member

mvdbeek commented Aug 16, 2022

And we should deprecate and remove it completely in 22.09

@natefoo natefoo marked this pull request as ready for review August 16, 2022 19:09
@natefoo natefoo changed the title Disable translogger middleware by default [22.05] Disable translogger middleware by default Aug 16, 2022
@github-actions github-actions bot added this to the 22.09 milestone Aug 16, 2022
@mvdbeek
Copy link
Member

mvdbeek commented Aug 17, 2022

Very nice, thank you!

@mvdbeek mvdbeek merged commit 1b1d015 into galaxyproject:release_22.05 Aug 17, 2022
@galaxyproject galaxyproject deleted a comment from github-actions bot Aug 17, 2022
@nsoranzo nsoranzo modified the milestones: 22.09, 22.05 Aug 17, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants