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 allDEBUG
-level events, as well as contextual information, such as log level and thread name. The location of this file can be configured via thelog-path
flag.
21:35:48 6 of 7 OK created view model dbt_testing.name_list......................... [CREATE VIEW in 0.17s]
============================== 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 anode_info
dictionary with common attributes.
info
fields
Field | Description |
---|---|
category | Placeholder for future use (see dbt-labs/dbt-core#5958) |
code | Unique shorthand identifier for this event type, e.g. A123 |
extra | Dictionary of custom environment metadata, based on environment variables prefixed with DBT_ENV_CUSTOM_ENV_ |
invocation_id | A unique identifier for this invocation of dbt |
level | A string representation of the log level (debug , info , warn , error ) |
log_version | Integer indicating version |
msg | Human-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. |
name | Unique name for this event type, matching the proto schema name |
pid | The process ID for the running dbt invocation which produced this log message |
thread_name | The thread in which the log message was produced, helpful for tracking queries when dbt is run with multiple threads |
ts | When 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:
Field | Description |
---|---|
materialized | view, table, incremental, etc. |
meta | User-configured meta dictionary for this node |
node_finished_at | Timestamp when node processing completed |
node_name | Name of this model/seed/test/etc |
node_path | File path to where this resource is defined |
node_relation | Nested object containing this node's database representation: database , schema , alias , and full relation_name with quoting & inclusion policies applied |
node_started_at | Timestamp when node processing started |
node_status | Current status of the node, either RunningStatus (while running) or NodeStatus (finished) as defined in the result contract |
resource_type | model , test , seed , snapshot , etc. |
unique_id | The 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.