Add unified detailed error logging #2250
Conversation
|
Please, can you fix the rubocop offenses to the CI run the tests? |
|
@nateberkopec hey, I've got a couple of questions:
|
|
Left some comments
Definitely not, because not all errors are worth logging. Also, I feel like there's a higher-level rescue in Puma somewhere where you can catch most of the exceptions that are re-raised. Instead, concentrate on where we are logging errors today, usually to stderr but maybe in other ways, and replacing those with this interface
I think there should be a global option to dump the rack env. So, if this option is on, we dump the rack env to the output every time the error interface is called. |
|
Well, the CI is weird |
|
I removed the |
lib/puma/events.rb
Outdated
| "#{error.inspect}" \ | ||
| "\n---\n" | ||
| def parse_error(error, env) | ||
| @debug_logger.error_dump(error: error, env: env, text: 'HTTP parse error, malformed request', force: true) |
There was a problem hiding this comment.
(This is more a comment on the concept and not this specific line)
"debug logger" and the "force: true" reads a bit strange to me... what about using different levels instead?
Just throwing this out as an idea, not demanding anything, this is already great work, thanks for doing it 👍
There was a problem hiding this comment.
Yeah, you're definitely right. It's strange and needs to be simplified, I'll have a look what I can do.
There was a problem hiding this comment.
I updated the MR with the new name and the new interface of the logger class.
In my opinion, now it looks better, but there is a couple of things that confuse me:
infoanddebugmethods prints headers and body of the request. As for me, this is ok fordebug, but I'm not sure aboutinfo- Since we replaced all
$stderrinvokes with the new interface,log,write, anddebuguse$stdoutand have the same format, buterroruses the new interface and have a different format
@nateberkopec what do you think about it?
It's because some whitespace snuck in the gemspec recently (@schneems noticed this and fixed it #2253 but if a maintainer can fix it directly in master I think that would be good). Don't know about the latest failures here though |
|
This looks great! I think the approach is now right-on-target. I think I'll wait for you to add the request information, and then I'll add a final round of review. |
nateberkopec
added
waiting-for-review
There was a problem hiding this comment.
Need to try this out locally to see what it looks like. One thing I'm concerned about is whether or not we're dumping info about the request when we did not do so before. We've had security issues in the past re: HTTP parse error specifically where logging request info put sensitive user info into the logs. Basically nothing about the request should ever be logged unless the user opted in via PUMA_DEBUG.
lib/puma/error_logger.rb
Outdated
| require 'puma/const' | ||
|
|
||
| module Puma | ||
| # The implementation of a logging in debug mode. |
There was a problem hiding this comment.
Comment here is out of date now - I think it is uneccessary anyway and can just be deleted.
There was a problem hiding this comment.
Basically nothing about the request should ever be logged unless the user opted in via PUMA_DEBUG.
Agree, so I made the interface to have 2 methods: debug and info. Obviously, info prints only non-sensitive info and debug prints only in debug mode.
|
BTW I think the design now is really top-notch, exactly what it should be. |
|
Example output without debug on, opening an ssl connection to a non-SSL configured Puma: |
|
Not a huge fan of how that "malformed request (" " - (-))" looks. |
Yup, I totally agree, so I fixed it. Now it looks like this: |
|
Looks good. I think we have the infrastructure now to improve specific errors/error messages where needed. This was really impressive work, doing a refactor like this for your first ever contribution to a project is great! I think you can be very proud of what you've done here. |
Description
Hey, it's my humble try to make a unified debug logger for the whole project.
The work isn't finished and I'm not sure if I'm doing what expected so I'm going to just put it here for further discussion.
Closes #2235
Your checklist for this pull request
[changelog skip]the pull request title.[ci skip]to the title of the PR.#issue" to the PR description or my commit messages.