Adds logger filter for TOKENS when logging in DEBUG MODE #539

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

Jump to bottom

Draft

jtroussard wants to merge 9 commits into master

from 536-access-tokens-leaked-in-logs-when-using-debug-level

Draft

Adds logger filter for TOKENS when logging in DEBUG MODE #539

jtroussard wants to merge 9 commits into master from 536-access-tokens-leaked-in-logs-when-using-debug-level

Conversation

jtroussard

Copy link

Contributor

@jtroussard jtroussard commented Mar 23, 2024 •

edited

Loading

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

logger levels: https://docs.python.org/3/library/logging.html#logrecord-attributes
logger Filters: https://docs.python.org/3/library/logging.html#filter-objects

SO

filter implementation: https://stackoverflow.com/a/879937/5094207

Jacques Troussard and others added 2 commits

March 23, 2024 17:02

@erlendvollset


 532: adds a logger filter for tokens in debug mode

e0e20cd

Co-authored-by: Erlend vollset <erlendvollset@gmail.com>


 532: updates authorship file

f350642

@jtroussard jtroussard linked an issue

Mar 23, 2024

that may be closed by this pull request

Access tokens leaked in logs when using DEBUG level #536

Open

@jtroussard jtroussard requested review from singingwolfboy and JonathanHuot

March 23, 2024 21:25

@coveralls

Copy link

coveralls commented Mar 23, 2024 •

edited

Loading

Coverage Status

coverage: 90.335% (+0.2%) from 90.097%
when pulling 6b8f87c on 536-access-tokens-leaked-in-logs-when-using-debug-level
into 77905a4 on master.

@jtroussard

Copy link

Contributor Author

jtroussard commented Mar 23, 2024 •

edited

Loading

@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

Jacques Troussard added 2 commits

March 23, 2024 17:47


 532: fixes logic so filter checks the logger record level, updates tests

103d28c


 532: moves the logger warning to the requests initializer, updates tests

a77b392

@jtroussard jtroussard force-pushed the 536-access-tokens-leaked-in-logs-when-using-debug-level branch from 313fe40 to a77b392 Compare

March 23, 2024 22:33

@jtroussard jtroussard marked this pull request as draft

March 26, 2024 15:41

@jtroussard

Copy link

Contributor Author

jtroussard commented Mar 26, 2024

Converting to a draft until I have time to thoroughly test the regex, and provide evidence.


 536: updatea regex for log filter

577a085

erlendvollset

erlendvollset reviewed

Apr 3, 2024

View reviewed changes

Copy link

@erlendvollset erlendvollset left a comment •

edited

Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thank you for picking this up 🚀 I think this approach addresses the issue in a better way than in my PR - so I'm all for it! I left a few suggestions that you may want to take into consideration.

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())

Copy link

@erlendvollset erlendvollset Apr 3, 2024 •

edited

Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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.sub is expensive enough that we would want to avoid doing it each time.

requests_oauthlib/log_filters.py

if self.mode == "MASK":

record.msg = re.sub(r'Bearer\s+([A-Za-z0-9\-._~+\/]+)', '[MASKED]', record.getMessage())

elif self.mode == "SUPPRESS":

return False

Copy link

@erlendvollset erlendvollset Apr 3, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe only suppress log messages which match the above regex? Otherwise this equivalent to disabling the logger entirely.

Copy link

Contributor Author

@jtroussard jtroussard Apr 21, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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()

Copy link

@erlendvollset erlendvollset Apr 3, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would suggest prefixing the envvar with the library name to reduce likelihood of collisions with other environment variables.

Suggested change

self.mode = os.getenv('DEBUG_MODE_TOKEN_FILTER', 'DEFAULT').upper()

self.mode = os.getenv('REQUESTS_OAUTHLIB_DEBUG_MODE_TOKEN_FILTER', 'DEFAULT').upper()

Copy link

Contributor Author

@jtroussard jtroussard Apr 21, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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!

@jtroussard

Copy link

Contributor Author

jtroussard commented Apr 18, 2024

@erlendvollset This is great feedback! I'll try and carve out some time this weekend to address these comments. Thanks again!


 Merge branch 'master' into 536-access-tokens-leaked-in-logs-when-usin...

54676d1

...g-debug-level

@jtroussard

Copy link

Contributor Author

jtroussard commented Apr 21, 2024 •

edited

Loading

Pending TODOs

verify regex
compile regex pattern
testing for regex pattern?


 updates env var name, improve SUPRESSED scope implementation, black f...

33d5bb5

...ormatting

@erlendvollset

Copy link

erlendvollset commented Jun 17, 2024

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 ☺️

@jtroussard

Copy link

Contributor Author

jtroussard commented Jun 17, 2024 via email

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 ☺️ — Reply to this email directly, view it on GitHub <#539 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AEFNX7JZRE7SZQDQL3MZPWTZH3AFXAVCNFSM6AAAAABFE6FPFKVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCNZTGEYDMNBZGI> . You are receiving this because you were mentioned.Message ID: ***@***.***>

@erlendvollset

Copy link

erlendvollset commented Jun 18, 2024 •

edited

Loading

Sure thing! 🤝

@jtroussard

Copy link

Contributor Author

jtroussard commented Jul 16, 2024 •

edited

Loading

@erlendvollset

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!

@jtroussard


 updates unit tests, pending one last test to assert warning message i...

6b8f87c

...s printed to console when in default mode

@jtroussard

Copy link

Contributor Author

jtroussard commented Jul 18, 2024

@erlendvollset

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.

@jtroussard


 updates README with correct env var and makes headers render properly

5a6e94a

Labels

None yet

3 participants

@jtroussard @coveralls @erlendvollset

Uh oh!

Adds logger filter for TOKENS when logging in DEBUG MODE #539

Are you sure you want to change the base?

Adds logger filter for TOKENS when logging in DEBUG MODE #539

Uh oh!

Conversation

@jtroussard jtroussard commented Mar 23, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Relevant links

python logger docs

SO

Uh oh!

coveralls commented Mar 23, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jtroussard commented Mar 23, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jtroussard commented Mar 26, 2024

Uh oh!

@erlendvollset erlendvollset left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

@erlendvollset erlendvollset Apr 3, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

@erlendvollset erlendvollset Apr 3, 2024

Choose a reason for hiding this comment

Uh oh!

@jtroussard jtroussard Apr 21, 2024

Choose a reason for hiding this comment

Uh oh!

@erlendvollset erlendvollset Apr 3, 2024

Choose a reason for hiding this comment

Uh oh!

@jtroussard jtroussard Apr 21, 2024

Choose a reason for hiding this comment

Uh oh!

jtroussard commented Apr 18, 2024

Uh oh!

jtroussard commented Apr 21, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

erlendvollset commented Jun 17, 2024

Uh oh!

jtroussard commented Jun 17, 2024 via email

Uh oh!

erlendvollset commented Jun 18, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jtroussard commented Jul 16, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

jtroussard commented Jul 18, 2024

Uh oh!

Uh oh!

@jtroussard jtroussard commented Mar 23, 2024 •

edited

Loading

coveralls commented Mar 23, 2024 •

edited

Loading

jtroussard commented Mar 23, 2024 •

edited

Loading

@erlendvollset erlendvollset left a comment •

edited

Loading

@erlendvollset erlendvollset Apr 3, 2024 •

edited

Loading

jtroussard commented Apr 21, 2024 •

edited

Loading

erlendvollset commented Jun 18, 2024 •

edited

Loading

jtroussard commented Jul 16, 2024 •

edited

Loading