Skip to content
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

Allowed and default values for LOG_FORMAT and LOG_FORMAT_FILE #5578

Merged
merged 13 commits into from
May 30, 2024

Conversation

dbeatty10
Copy link
Contributor

@dbeatty10 dbeatty10 commented May 29, 2024

Preview

What are you changing in this pull request and why?

resolves #5577

Allowed and default values are in the source code here.

TLDR

The LOG_FORMAT and LOG_FORMAT_FILE global config flags in dbt control the format of log outputs. There are three formats:

  1. text

    • Outputs unstructured text with minimal metadata and second-precision timestamps in UTC.
    • Default format for console output.

    Example:

    23:30:16  Running with dbt=1.8.0
    23:30:17  Registered adapter: postgres=1.8.0
    
  2. debug

    • Outputs unstructured text with detailed metadata including log level, thread ID, and microsecond-precision timestamps in the system's local time zone.
    • Default format for the logs/dbt.log file.

    Example:

    ============================== 16:12:08.555032 | 9089bafa-4010-4f38-9b42-564ec9106e07 ==============================
    16:12:08.555032 [info ] [MainThread]: Running with dbt=1.8.0
    16:12:08.751069 [info ] [MainThread]: Registered adapter: postgres=1.8.0
    
  3. json

    • Outputs structured JSON-L format logs.

    Example:

    {"data": {"log_version": 3, "version": "=1.8.0"}, "info": {"category": "", "code": "A001", "extra": {}, "invocation_id": "82131fa0-d2b4-4a77-9436-019834e22746", "level": "info", "msg": "Running with dbt=1.8.0", "name": "MainReportVersion", "pid": 7875, "thread": "MainThread", "ts": "2024-05-29T23:32:54.993336Z"}}
    {"data": {"adapter_name": "postgres", "adapter_version": "=1.8.0"}, "info": {"category": "", "code": "E034", "extra": {}, "invocation_id": "82131fa0-d2b4-4a77-9436-019834e22746", "level": "info", "msg": "Registered adapter: postgres=1.8.0", "name": "AdapterRegistered", "pid": 7875, "thread": "MainThread", "ts": "2024-05-29T23:32:56.437986Z"}}
    

Note: The debug log format should not be confused with the debug log level. The log level determines the number of log messages, while the log format determines the detail in each log message.

More info

There are two different sub-classes of _Logger:

  1. _TextLogger (default)
  2. _JsonLogger

_TextLogger has two different line formats:

  1. DebugText (default)
    • Same as PlainText below except it includes a header at the beginning of each invocation (which has a timestamp and the invocation ID) and each message includes the log level of the message, thread ID, and the timestamp has a microsecond precision using the Python system time zone
  2. PlainText
    • Same as DebugText above except it does not include a header at the beginning of each invocation and each message does not include the log level of the message or the thread ID. The timestamp for each message has a second precision represented in UTC.

_JsonLogger has a single line format:

  1. Json

Those (3) line formats correspond to the options for the LOG_FORMAT and LOG_FORMAT_FILE global config flags:

  1. debug -> DebugText line format (default for the logs/dbt.log file) outputs unstructured text with more metadata at the beginning of each log line and upon each dbt invocation
  2. text -> PlainText line format (default for console output) outputs unstructured text with minimal metadata at the beginning of each log line and none upon each dbt invocation
  3. json -> Json line format outputs structured JSON-L

Warning

The debug log_level can easily be confused with the debug log_format since they have the same name. But the log_level and log_format are independent configurations whose options can be mixed'n'matched.

Think of log levels as affecting the total number of log messages and the log format as affecting the length of each log message: the debug log level includes the maximal number of log messages whereas the debug log format includes more detailed information per log message

e.g. The debug log level filters out the least number of potential log messages -- none! And the debug log format has longer lines because it includes the most detailed debugging metadata per log message.

To avoid confusion, we would have been better off giving the debug log format a unique name instead (like detailed). A better name for the text log format would have been basic, simple, or brief.

Note

I don't know the precision reasons why the PlainText line format is in UTC with low-resolution while the DebugText with a local time zone and high resolution

Checklist

Copy link

vercel bot commented May 29, 2024

The latest updates on your projects. Learn more about Vercel for Git ↗︎

Name Status Preview Comments Updated (UTC)
docs-getdbt-com ✅ Ready (Inspect) Visit Preview 💬 Add feedback May 30, 2024 3:03pm

@github-actions github-actions bot added content Improvements or additions to content size: x-small This change will take under 3 hours to fix. labels May 29, 2024
@dbeatty10 dbeatty10 marked this pull request as ready for review May 29, 2024 14:22
@dbeatty10 dbeatty10 requested a review from a team as a code owner May 29, 2024 14:22
@github-actions github-actions bot added size: medium This change will take up to a week to address and removed size: x-small This change will take under 3 hours to fix. labels May 30, 2024
@github-actions github-actions bot added size: small This change will take 1 to 2 days to address and removed size: medium This change will take up to a week to address labels May 30, 2024
@github-actions github-actions bot added size: medium This change will take up to a week to address and removed size: small This change will take 1 to 2 days to address labels May 30, 2024
@github-actions github-actions bot added size: small This change will take 1 to 2 days to address and removed size: medium This change will take up to a week to address labels May 30, 2024
@iamtodor
Copy link
Contributor

@dbeatty10 thank you!

Copy link
Contributor

@iamtodor iamtodor left a comment

Choose a reason for hiding this comment

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

LGTM! 🔥

Copy link
Contributor

@matthewshaver matthewshaver left a comment

Choose a reason for hiding this comment

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

Thanks @dbeatty10

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
content Improvements or additions to content size: small This change will take 1 to 2 days to address
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[Bug] Enhance Log Formatting Documentation
3 participants