Skip to main content

Events and logs

As dbt runs, it generates events. The most common way to see those events is as log messages, written in real time to two places:

  • The command line terminal (stdout), to provide interactive feedback while running dbt.
  • The debug log file (logs/dbt.log), to enable detailed debugging of errors when they occur. The text-formatted log messages in this file include all DEBUG-level events, as well as contextual information, such as log level and thread name. The location of this file can be configured via the log-path flag.
CLI
21:35:48  6 of 7 OK created view model dbt_testing.name_list......................... [CREATE VIEW in 0.17s]
logs/dbt.log
============================== 21:21:15.272780 | 48cef052-3819-4550-a83a-4a648aef5a31 ==============================
21:21:15.272780 [info ] [MainThread]: Running with dbt=1.5.0-b5
21:21:15.273802 [debug] [MainThread]: running dbt with arguments {'printer_width': '80', 'indirect_selection': 'eager', 'log_cache_events': 'False', 'write_json': 'True', 'partial_parse': 'True', 'cache_selected_only': 'False', 'warn_error': 'None', 'fail_fast': 'False', 'debug': 'False', 'log_path': '/Users/jerco/dev/scratch/testy/logs', 'profiles_dir': '/Users/jerco/.dbt', 'version_check': 'False', 'use_colors': 'False', 'use_experimental_parser': 'False', 'no_print': 'None', 'quiet': 'False', 'log_format': 'default', 'static_parser': 'True', 'introspect': 'True', 'warn_error_options': 'WarnErrorOptions(include=[], exclude=[])', 'target_path': 'None', 'send_anonymous_usage_stats': 'True'}
21:21:16.190990 [debug] [MainThread]: Partial parsing enabled: 0 files deleted, 0 files added, 0 files changed.
21:21:16.191404 [debug] [MainThread]: Partial parsing enabled, no changes found, skipping parsing
21:21:16.207330 [info ] [MainThread]: Found 2 models, 0 tests, 0 snapshots, 1 analysis, 535 macros, 0 operations, 1 seed file, 0 sources, 0 exposures, 0 metrics, 0 groups

Structured logging

For more details about how the eventing system has been implemented in dbt-core, see the events module README.

The structure of each event in dbt-core is backed by a schema defined using protocol buffers. All schemas are defined in the types.proto file within the dbt-core codebase.

Every event has the same two top-level keys:

  • info: Information common to all events. See the table below for the breakdown.
  • data: Additional structured data specific to this event. If this event relates to a specific node within your dbt project, it will contain a node_info dictionary with common attributes.

info fields

FieldDescription
categoryPlaceholder for future use (see dbt-labs/dbt-core#5958)
codeUnique shorthand identifier for this event type, e.g. A123
extraDictionary of custom environment metadata, based on environment variables prefixed with DBT_ENV_CUSTOM_ENV_
invocation_idA unique identifier for this invocation of dbt
levelA string representation of the log level (debug, info, warn, error)
log_versionInteger indicating version
msgHuman-friendly log message, constructed from structured data. Note: This message is not intended for machine consumption. Log messages are subject to change in future versions of dbt.
nameUnique name for this event type, matching the proto schema name
pidThe process ID for the running dbt invocation which produced this log message
thread_nameThe thread in which the log message was produced, helpful for tracking queries when dbt is run with multiple threads
tsWhen the log line was printed

node_info fields

Many events are fired while compiling or running a specific DAG node (model, seed, test, etc). When it's available, the node_info object will include:

FieldDescription
materializedview, table, incremental, etc.
metaUser-configured meta dictionary for this node
node_finished_atTimestamp when node processing completed
node_nameName of this model/seed/test/etc
node_pathFile path to where this resource is defined
node_relationNested object containing this node's database representation: database, schema, alias, and full relation_name with quoting & inclusion policies applied
node_started_atTimestamp when node processing started
node_statusCurrent status of the node, either RunningStatus (while running) or NodeStatus (finished) as defined in the result contract
resource_typemodel, test, seed, snapshot, etc.
unique_idThe unique identifier for this resource, which can be used to look up more contextual information in the manifest

Example

{
"data": {
"description": "sql view model dbt_jcohen.my_model",
"index": 1,
"node_info": {
"materialized": "view",
"meta": {
"first": "some_value",
"second": "1234"
},
"node_finished_at": "",
"node_name": "my_model",
"node_path": "my_model.sql",
"node_relation": {
"alias": "my_model",
"database": "my_database",
"relation_name": "\"my_database\".\"my_schema\".\"my_model\"",
"schema": "my_schema"
},
"node_started_at": "2023-04-12T19:27:27.435364",
"node_status": "started",
"resource_type": "model",
"unique_id": "model.my_dbt_project.my_model"
},
"total": 1
},
"info": {
"category": "",
"code": "Q011",
"extra": {
"my_custom_env_var": "my_custom_value"
},
"invocation_id": "206b4e61-8447-4af7-8035-b174ab3ac991",
"level": "info",
"msg": "1 of 1 START sql view model my_database.my_model ................................ [RUN]",
"name": "LogStartLine",
"pid": 95894,
"thread": "Thread-1",
"ts": "2023-04-12T19:27:27.436283Z"
}
}

Python interface

Older versions of dbt-core made available a full history of events fired during an invocation, in the form of an EVENT_HISTORY object.

When invoking dbt programmatically, it is possible to register a callback on dbt's EventManager. This allows access to structured events as Python objects, to enable custom logging and integration with other systems.

The Python interface into events is significantly less mature than the structured logging interface. For all standard use cases, we recommend parsing JSON-formatted logs.

0