From 7e175400abf90ffdb49bd79c435272f786facb29 Mon Sep 17 00:00:00 2001 From: Heikki Linnakangas Date: Tue, 8 Oct 2024 13:11:49 +0300 Subject: [PATCH] Reduce noise from moto GET/PUT operations Moto prints messages like this: 127.0.0.1 - - [07/Oct/2024 12:35:16] "PUT /bucket-name/path?x-id=PutObject HTTP/1.1" 200 - After the root logger adds its context information, this is what actually gets printed to the log: 2024-10-07 22:35:16.371 INFO [_internal.py:97] 127.0.0.1 - - [07/Oct/2024 22:35:16] "PUT /bucket-name/path?x-id=PutObject HTTP/1.1" 200 - That's very verbose. Remove the hostname and the extra timestamp, to make it a little less verbose. With this PR, the final output looks like this: 2024-10-07 22:35:16.371 INFO [_internal.py:97] "PUT /bucket-name/path?x-id=PutObject HTTP/1.1" 200 - --- test_runner/fixtures/log_helper.py | 11 ++++++++++ test_runner/fixtures/log_helper_internal.py | 24 +++++++++++++++++++++ 2 files changed, 35 insertions(+) create mode 100644 test_runner/fixtures/log_helper_internal.py diff --git a/test_runner/fixtures/log_helper.py b/test_runner/fixtures/log_helper.py index 70d76a39c4..8d986a0235 100644 --- a/test_runner/fixtures/log_helper.py +++ b/test_runner/fixtures/log_helper.py @@ -24,9 +24,20 @@ https://docs.pytest.org/en/6.2.x/logging.html # log format is specified in pytest.ini file LOGGING = { "version": 1, + "filters": { + "wzfilter": { + "()": "fixtures.log_helper_internal.WerkzeugNoiseFilter", + }, + }, "loggers": { "root": {"level": "INFO"}, "root.safekeeper_async": {"level": "INFO"}, # a lot of logs on DEBUG level + + # Use a custom filter to make werkzeug's messages less verbose. + "werkzeug": { + "filters": ["wzfilter"], + "level": "INFO", + }, }, } diff --git a/test_runner/fixtures/log_helper_internal.py b/test_runner/fixtures/log_helper_internal.py new file mode 100644 index 0000000000..8dbc640a56 --- /dev/null +++ b/test_runner/fixtures/log_helper_internal.py @@ -0,0 +1,24 @@ +# These are logically part of in log_helper.py, but need to be in a +# different file because these get loaded from the logging config +# file. If you try to included these in log_helper.py directly, you +# get an error about circular dependency. +import re + +class WerkzeugNoiseFilter(object): + """Moto server that we use for mocking S3 uses werkzeug, which + logs all HTTP operations. It constructs log messages like this: + + 127.0.0.1 - - [08/Oct/2024 12:43:46] "PUT /bucket-name/path?x-id=PutObject HTTP/1.1" 200 - + + The IP address is not interesting in tests, as it's always just + 127.0.0.1. And the timestamp is redundant with the timestamp we + print for all log messages anyway, with millisecond precision. + Unfortunately those are "etched" in the message, and cannot be + overriden by setting a custom formatter. To reduce the noise in + the test output, this filter removes those fields from the log + messages. + """ + + def filter(self, logRecord): + logRecord.msg = re.sub(r'127\.0\.0\.1 - - \[.+\] (".*".*)', r'\1', logRecord.msg) + return True