dbt macro tips advent calendar 2022 day 7 - dbtの動作モード

2022/12/07に公開

便利なデータ変換ツールである dbt の中のmacroに関するtipsを書いていく dbt macro tips Advent Calendar 2022 7日目です。

この辺から、文量が少なくなります。

dbtの動作モード

dbtを一言で説明すると、Jinjaテンプレートによって拡張されたSQLの「描画」および「実行」を行ってくれるツールとなります。ここで、重要なこととして、「描画」と「実行」を行ってくれるという点です。

そう、実はdbtには2つの動作モードがあります。
それが、dbtによるJinjaテンプレートの解析・描画を行う parse phaseと、描画されたSQLの実行を行うexecute phaseです。

先日のmacroを再掲します。

macro/noop.sql
{%- macro noop() %}
{%- set numbers = [25, 35, 22, 11] %}
{%- do log('numbers is '~numbers,info=True) %}
{%- endmacro %}
models/noop.sql
{% set ret = noop() %}
{{ ret }}
select 1

これを実行すると

$ dbt compile --select noop           
02:24:46  Running with dbt=1.3.1
02:24:46  numbers is [25, 35, 22, 11]
02:24:46  Found 3 models, 4 tests, 0 snapshots, 0 analyses, 290 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics
02:24:46  
02:24:46  Concurrency: 4 threads (target='dev')
02:24:46  
02:24:46  numbers is [25, 35, 22, 11]
02:24:46  Done. 
$ cat logs/dbt.log | grep 'numbers is'
02:24:46.625232 [info ] [MainThread]: numbers is [25, 35, 22, 11]
02:24:46.843828 [info ] [Thread-1 (]: numbers is [25, 35, 22, 11]

となりますが、

02:24:46  Running with dbt=1.3.1
02:24:46  numbers is [25, 35, 22, 11]
... 中略 ...
02:24:46  numbers is [25, 35, 22, 11]

と2回表示されているということにお気づきでしょうか。
この2回というのが先ほど説明した2つの動作モードの話と関連してきます。
つまりは、最初に出力されたのが、parse phaseでnoop() のmacroが実行されたときに出力されたもので、2回目がexecute phaseで実行されたときの出力です。

では、macro中でexecute phaseであるかどうかを知る術はあるのでしょうか?

それは、こちらのドキュメントに記載されています。

https://docs.getdbt.com/reference/dbt-jinja-functions/execute

こちらのexecute 変数を使って、ログを出し分けてみましょう。

macro/noop.sql
{%- macro noop() %}
{%- if execute %}
	{%- do log('output log in execute phase',info=True) %}
{%- else %}
	{%- do log('output log in parse phase',info=True) %}
{%- endif %} 
{%- endmacro %}
$ dbt compile --select noop           
02:48:01  Running with dbt=1.3.1
02:48:01  output log in parse phase
02:48:01  Found 3 models, 4 tests, 0 snapshots, 0 analyses, 290 macros, 0 operations, 0 seed files, 0 sources, 0 exposures, 0 metrics
02:48:01  
02:48:01  Concurrency: 4 threads (target='dev')
02:48:01  
02:48:01  output log in execute phase
02:48:01  Done.
$ cat logs/dbt.log | grep 'output log in'
02:48:01.424154 [info ] [MainThread]: output log in parse phase
02:48:01.683425 [info ] [Thread-1 (]: output log in execute phase

実は、この動作モードの違いは結構いろいろなところに影響してくるのですが、
今日のところは一旦2つのモードがあるんだな!とおぼえておいてください。

※ 追加で、小耳に入れとくといいかもしれないのは、parse phaseはMainThreadで実行れている。execute phaseは Thread-1(つまりマルチスレッドで並列に実行されてる)という点は小耳に入れておくといいかもしれないですね。


8日目はマニュフェストファイルとgraphについて話します。

Discussion