Skip to content

add new log output formatting and asf trace logging #6424

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

Merged
merged 2 commits into from
Jul 11, 2022
Merged

add new log output formatting and asf trace logging #6424

merged 2 commits into from
Jul 11, 2022

Conversation

thrau
Copy link
Member

@thrau thrau commented Jul 9, 2022

This PR overhauls log formatting and restructures the setup routine of the logs a bit

  • move logging related code into it's own module localstack.logging
  • change log output format to spring-inspired format
  • to that end i had to introduce a couple of new constructs (see format.py)

Not super happy with the LS_LOG=trace|trace-internal solution. But I did my best to use what was already there and not introduce additional/different configuration.

  • there are two modes of logging: trace and normal log
  • internal calls are only logged if LS_LOG=trace|trace-interal
  • internal calls are only logged as trace when LS_LOG=trace-internal
  • in trace mode, AWS requests are logged visually similar like they are without tracing (AWS sqs.ListQueues => 200), but we add in the same line the request dictionary and the headers (ListQueueRequest({}, headers={..http-headers..}), and the response also with the headers (ListQueueResponse(...)). this keeps everything neatly in one line
  • in trace mode, HTTP requests that cannot be parsed as AWS requests are logged entirely

Demo

Here you can see trace logging in action:

Screenshot at 2022-07-09 02-01-19

@thrau thrau requested review from whummer and dfangl July 9, 2022 00:08
@thrau thrau temporarily deployed to localstack-ext-tests July 9, 2022 00:08 Inactive
@thrau thrau marked this pull request as draft July 9, 2022 00:49
@github-actions
Copy link

github-actions bot commented Jul 9, 2022

LocalStack integration with Pro

       3 files         3 suites   1h 7m 1s ⏱️
1 126 tests 1 087 ✔️ 39 💤 0
1 441 runs  1 373 ✔️ 68 💤 0

Results for commit 0bc037c.

♻️ This comment has been updated with latest results.

@localstack-bot localstack-bot temporarily deployed to localstack-ext-tests July 11, 2022 09:13 Inactive
@dfangl dfangl temporarily deployed to localstack-ext-tests July 11, 2022 15:39 Inactive
@dfangl
Copy link
Member

dfangl commented Jul 11, 2022

Updated view (changed HTML, changed logger names):
image

Copy link
Member

@dfangl dfangl left a comment

Choose a reason for hiding this comment

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

LGTM (since I wrote some of it :D)

@coveralls
Copy link

Coverage Status

Coverage decreased (-0.07%) to 91.917% when pulling 0bc037c on logging into 6989fcd on v1.

@thrau thrau marked this pull request as ready for review July 11, 2022 16:21
Copy link
Member

@whummer whummer left a comment

Choose a reason for hiding this comment

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

Looks awesome, great set of changes @thrau @dfangl ! 💯

Just gave this a quick try with the SQS event source polling, and a few other use cases - nice approach with LS_LOG=trace and LS_LOG=trace-internal, so we don't need to manually define specific logger rules for the internal calls.. 👌 Excited to get this in!

# x.x.x requires 5 = 2n - 1 characters
cur_length = (len(parts) * 2) - 1

for i in range(len(parts)):
Copy link
Member

Choose a reason for hiding this comment

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

Nice algorithm!

MAX_THREAD_NAME_LEN = 12
MAX_NAME_LEN = 26

LOG_FORMAT = f"%(asctime)s.%(msecs)03d %(ls_level)5s --- [%(ls_thread){MAX_THREAD_NAME_LEN}s] %(ls_name)-{MAX_NAME_LEN}s : %(message)s"
Copy link
Member

Choose a reason for hiding this comment

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

nit: Great to have the thread information also available in the logs, although potentially we could think about adding that to the trace-enabled logs only. Just a thought for future iterations, let's see how things are evolving with having the thread info in all logs for now.. 👍

@thrau thrau merged commit 599e59d into v1 Jul 11, 2022
@thrau thrau deleted the logging branch July 11, 2022 17:08
@localstack localstack locked and limited conversation to collaborators Jul 11, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants