Adds logger filter for TOKENS when logging in DEBUG MODE #539
Conversation
Co-authored-by: Erlend vollset <erlendvollset@gmail.com>
|
@erlendvollset : Github wouldn't let me ping you in the reviewers windows so I'm doing it here @XMoose25X : Thought you might want to take a peek/observe/comment/correct/whatever-your-heart-desires xD |
jtroussard
force-pushed
the
536-access-tokens-leaked-in-logs-when-using-debug-level
branch
from
313fe40 to
a77b392
Compare
|
Converting to a draft until I have time to thoroughly test the regex, and provide evidence. |
requests_oauthlib/log_filters.py
Outdated
| """ | ||
| if record.levelno == logging.DEBUG: | ||
| if self.mode == "MASK": | ||
| record.msg = re.sub(r'Bearer\s+([A-Za-z0-9\-._~+\/]+)', '[MASKED]', record.getMessage()) |
There was a problem hiding this comment.
- I would suggest compiling the regex pattern once to avoid doing that for every log message.
- I would suggest putting this behind an LRU cache as we'll be logging a lot of the same statements repeatedly.
re.subis expensive enough that we would want to avoid doing it each time.
| if self.mode == "MASK": | ||
| record.msg = re.sub(r'Bearer\s+([A-Za-z0-9\-._~+\/]+)', '[MASKED]', record.getMessage()) | ||
| elif self.mode == "SUPPRESS": | ||
| return False |
There was a problem hiding this comment.
Maybe only suppress log messages which match the above regex? Otherwise this equivalent to disabling the logger entirely.
There was a problem hiding this comment.
I am hoping a single space would suffice as a replacement? Or maybe just pass None to the msg?
requests_oauthlib/log_filters.py
Outdated
| environment variable. | ||
| """ | ||
| super().__init__() | ||
| self.mode = os.getenv('DEBUG_MODE_TOKEN_FILTER', 'DEFAULT').upper() |
There was a problem hiding this comment.
I would suggest prefixing the envvar with the library name to reduce likelihood of collisions with other environment variables.
| self.mode = os.getenv('DEBUG_MODE_TOKEN_FILTER', 'DEFAULT').upper() | |
| self.mode = os.getenv('REQUESTS_OAUTHLIB_DEBUG_MODE_TOKEN_FILTER', 'DEFAULT').upper() |
There was a problem hiding this comment.
Love this comment. In fact I was running into this issue in another project. This project then variable name pattern is clean. I'm going to borrow and apply this pattern there as well. 🙏 Thank you!
|
@erlendvollset This is great feedback! I'll try and carve out some time this weekend to address these comments. Thanks again! |
|
Pending TODOs
|
|
Hey @jtroussard! This has been stale for a while now, is there anything I could do to help getting this over the finish line? Please let me know - I'd be happy to help out |
|
Thanks for reaching out! I haven’t forgotten about this and it’s been
bothering me I haven’t been able to set the time aside to finish. Can we
circle back on this, next week? Let’s say Wednesday? I’ll make some time to
draw up what help is need with and we can pair up and get this one done.
…On Mon, Jun 17, 2024 at 7:13 AM Erlend vollset ***@***.***> wrote:
Hey @jtroussard <https://github.com/jtroussard>! This has been stale for
a while now, is there anything I could do to help getting this over the
finish line? Please let me know - I'd be happy to help out
|
|
Sure thing! 🤝 |
|
Thanks for your patience! I apologize for letting this go stale; things have been pretty busy on my end. The major thing holding me back from moving this PR forward is the need for more comprehensive testing. I’ve written some initial tests, but I believe they could be filled out more and would like someone to smoke test this in an environment other than mine to ensure everything works as expected. Provide terminal screen shots sort of thing. All of your suggested changes I thought were great! I just haven't had the time to incorporate them. If you want maybe we could break them up piece meal and tackle them as a team? That along with some help in the testing department and I think that will help a lot in getting this over the finish line. Thanks again! |
…s printed to console when in default mode
|
Yup so that's what happens when things get stale. I completely forgot that I had already implemented your suggestions. I dug in deeper and see that the unit tests need some work. I've updated them so that all but the last one passes. The last one is suppose to test that when the logger is initialized in default mode that it logs a warning to console alerting the user that TOKENS will be logged in debug mode. I'm not super strong with testing but I believe the issue lies with mocking either the init module or the logger itself and properly invoking the constructor in the test. In the test runs you can see that the message does print, it is a matter of "proving" it within the test. I think this might be the last big of work that needs to get done before merging. Did you want to take a stab at that last test? I left my attempt in the last push commented out. |
This PR is a derivative of another #532
This PR addresses the same issue but aims to demonstrate a broader perspective on implementation. While the original PR highlighted a significant concern, the proposed solution here follows an existing patten of configuring the logger and leveraging the features within the logger itself. Following this pattern reinforces and encourages contributions in a more uniform and predictable way for future logger configurations.
This approach also enables a more comprehensive cleansing of sensitive information from logs, extending beyond headers to all areas of the code base.
The necessity to create a new PR stems from the considerable deviation in approach, which couldn't be effectively communicated within the framework of #532's PR discussion. To acknowledge the foundational work laid by the original proposal, this submission incorporates co-authoring commits, reinforcing a collaborative effort towards a scalable and secure logging strategy.
Relevant links
python logger docs
SO