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

Setting `log_requests` in puma config file #2074

Closed
jchristie55332 opened this issue Nov 13, 2019 · 4 comments
Closed

Setting `log_requests` in puma config file #2074

jchristie55332 opened this issue Nov 13, 2019 · 4 comments
Labels
bug

Comments

@jchristie55332
Copy link
Contributor

@jchristie55332 jchristie55332 commented Nov 13, 2019

Describe the bug

When log_requests is set in a puma configuration file it is not respected and as such the requests are not logged to standard out.

Puma config:

DATETIME_FORMAT = '%Y-%m-%d %H:%M:%S %z'.freeze

environment ENV.fetch('RAILS_ENV')

log_requests

log_formatter do |str|
  "#{Time.now.strftime DATETIME_FORMAT} : |Puma| #{str}"
end

To Reproduce

Install Puma into rails project and add puma config file
Boot application using rails s

Expected behavior

Application to log all requests to STDOUT

Desktop (please complete the following information):

  • OS: Mac OS 10.14.06
  • Puma Version: 4.3.0
@composerinteralia
Copy link
Contributor

@composerinteralia composerinteralia commented Nov 14, 2019

I tried this out in a non-rails context on puma master by running RAILS_ENV=development bundle exec bin/puma test/rackup/hello.ru -C config.rb where config.rb contained the config from this issue. I did see logs for requests when I ran this, so there may be something going on here outside puma. Are you able to provide a sample Rails application that reproduces this problem?


Curiously, while the standard puma logs did use the custom log_formatter, the request logs did not:

2019-11-13 20:00:08 -0500 : |Puma| Puma starting in single mode...
2019-11-13 20:00:08 -0500 : |Puma| * Version 4.3.0 (ruby 2.6.3-p62), codename: Mysterious Traveller
2019-11-13 20:00:08 -0500 : |Puma| * Min threads: 0, max threads: 16
2019-11-13 20:00:08 -0500 : |Puma| * Environment: development
2019-11-13 20:00:08 -0500 : |Puma| * Listening on tcp://0.0.0.0:9292
2019-11-13 20:00:08 -0500 : |Puma| Use Ctrl-C to stop
127.0.0.1 - - [13/Nov/2019:20:00:12 -0500] "GET / HTTP/1.1" 200 - 0.0001
127.0.0.1 - - [13/Nov/2019:20:03:15 -0500] "GET / HTTP/1.1" 200 - 0.0002

I wonder if that is expected, or if there is a separate bug here with the request logs not using the log_formatter

@jchristie55332
Copy link
Contributor Author

@jchristie55332 jchristie55332 commented Nov 19, 2019

@composerinteralia the test case that you have specified is using the CLI, however this issue specifically affects the rack handler which is why the issue cannot be reproduced. I have pushed a base generated rails app that shows the issue (https://github.com/jchristie55332/puma-rails-test-app)

@jchristie55332
Copy link
Contributor Author

@jchristie55332 jchristie55332 commented Nov 19, 2019

Curiously, while the standard puma logs did use the custom log_formatter, the request logs did not:

2019-11-13 20:00:08 -0500 : |Puma| Puma starting in single mode...
2019-11-13 20:00:08 -0500 : |Puma| * Version 4.3.0 (ruby 2.6.3-p62), codename: Mysterious Traveller
2019-11-13 20:00:08 -0500 : |Puma| * Min threads: 0, max threads: 16
2019-11-13 20:00:08 -0500 : |Puma| * Environment: development
2019-11-13 20:00:08 -0500 : |Puma| * Listening on tcp://0.0.0.0:9292
2019-11-13 20:00:08 -0500 : |Puma| Use Ctrl-C to stop
127.0.0.1 - - [13/Nov/2019:20:00:12 -0500] "GET / HTTP/1.1" 200 - 0.0001
127.0.0.1 - - [13/Nov/2019:20:03:15 -0500] "GET / HTTP/1.1" 200 - 0.0002

I wonder if that is expected, or if there is a separate bug here with the request logs not using the log_formatter

The request logs use the commonlogger.rb which is why they are using a different format. I would like to open a feature request to either allow the logger to be configurable (similar to log_requests) or for commonlogger.rb to respect log_formatter if supplied.

(I'm happy to work on this as is a current issue I am facing)

@nateberkopec
Copy link
Member

@nateberkopec nateberkopec commented Feb 19, 2020

Closed by #2075

@nateberkopec nateberkopec added bug and removed needs-repro labels Feb 19, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
3 participants
You can’t perform that action at this time.