イベントテーブルのトレースデータにハンドラーコード内で実行される SQL テキストを含めることができるようになりました #SnowflakeDB
2025.08.18はじめに
2025年8月のリリースで、Snowflake のストアドプロシージャやユーザー定義関数（UDF）のハンドラーコード内で実行される SQL ステートメントのトレース情報を取得する機能が一般提供となりました。
こちらの機能を試してみましたので、記事としました。
アップデートの概要
Snowflake では、ストアドプロシージャや UDF などの実行時に発生するテレメトリデータを自動的に収集する「イベントテーブル」が提供されています。トレースレベルの設定を有効化することで、このイベントテーブルに詳細なトレースイベントが取り込まれるようになります。
これまで、ストアドプロシージャや UDF が内部で実行した SQL ステートメントのトレースデータは取得できても、実行された SQL テキストそのものは含まれていませんでした。
今回のアップデートにより、アカウントレベルの SQL_TRACE_QUERY_TEXT パラメーターを有効化することで、ハンドラーコード内で実行された SQL のテキスト（最大1024文字）もトレースデータに含めることが可能になりました。これにより、より詳細な実行状況の分析やデバッグが可能となります
本機能でトレース可能となる対象などは以下に記載があります。
試してみる
パラメータの有効化前後で、ストアドプロシージャを実行し、イベントテーブルのクエリ結果を比較します。
事前準備
はじめに、検証用のデータベース・スキーマ、ストアドプロシージャ、イベントテーブルを作成し、作成したイベントテーブルをデータベースに関連付けておきました。
--変数を定義
----環境名
SET env_name = 'test';
----データベース名
SET db_name = concat($env_name,'_db');
----イベントテーブル名
SET event_table_name = concat($env_name,'_events');
--イベントテーブルとストアドプロシージャの作成先となるデータベースを作成
CREATE OR REPLACE DATABASE identifier($db_name);
--スキーマを作成
USE DATABASE identifier($db_name);
----イベントテーブルの作成
CREATE OR REPLACE SCHEMA event_tables;
----ストアドプロシージャの作成
CREATE OR REPLACE SCHEMA procedures;
--イベントテーブルを作成
USE DATABASE identifier($db_name);
USE SCHEMA event_tables;
CREATE OR REPLACE EVENT TABLE identifier($event_table_name);
--ストアドプロシージャの作成
USE DATABASE identifier($db_name);
USE SCHEMA procedures;
----サンプルテーブルを作成
CREATE OR REPLACE TABLE parent (ID INTEGER);
CREATE OR REPLACE TABLE child (ID INTEGER);
----Snowflakeスクリプトでストアドプロシージャを定義
CREATE OR REPLACE PROCEDURE insert_data()
RETURNS VARCHAR NOT NULL
LANGUAGE SQL
AS
$$
BEGIN
BEGIN TRANSACTION;
INSERT INTO procedures.parent VALUES (1);
SELECT 1/0; --エラーを発生させる
INSERT INTO procedures.child VALUES (1);
COMMIT;
RETURN 'complete';
EXCEPTION
WHEN OTHER THEN
ROLLBACK;
RAISE;
END;
$$
;
--データベースにイベントテーブルを関連付け
USE ROLE ACCOUNTADMIN;
ALTER DATABASE test_db SET EVENT_TABLE = test_db.event_tables.test_events;
イベントテーブルの設定を確認し、データベースのデフォルト値が先の手順で作成したイベントテーブルになっていることを確認します。
--設定値を確認
SHOW PARAMETERS LIKE 'event_table' IN DATABASE test_db;
+-------------+----------------------------------+----------------------------+----------+-----------------------------------------+--------+
| key | value | default | level | description | type |
|-------------+----------------------------------+----------------------------+----------+-----------------------------------------+--------|
| EVENT_TABLE | test_db.event_tables.test_events | snowflake.telemetry.events | DATABASE | Event destination for the given target. | STRING |
+-------------+----------------------------------+----------------------------+----------+-----------------------------------------+--------+
さらにデータベースレベルでログレベルを以下のように変更しておきました。
--ログレベルを設定
ALTER DATABASE test_db SET LOG_LEVEL = WARN;
>SHOW PARAMETERS LIKE '%LOG_LEVEL%' IN DATABASE test_db;
+-----------+-------+---------+----------+----------------------------------------+--------+
| key | value | default | level | description | type |
|-----------+-------+---------+----------+----------------------------------------+--------|
| LOG_LEVEL | WARN | OFF | DATABASE | LOG_LEVEL to use when filtering events | STRING |
+-----------+-------+---------+----------+----------------------------------------+--------+
ストアドプロシージャを実行しイベントテーブルにログが収集されることを確認しておきます。
--ストアドプロシージャを実行
USE SCHEMA test_db.procedures;
>CALL insert_data();
100051 (22012): Uncaught exception of type 'STATEMENT_ERROR' on line 5 at position 4 : Division by zero
--イベントテーブルをクエリ
>SELECT * FROM test_db.event_tables.test_events
->> SELECT TIMESTAMP,RECORD_TYPE,RECORD,RESOURCE_ATTRIBUTES,RECORD_ATTRIBUTES FROM $1 ORDER BY 1 DESC;
+-------------------------+-------------+----------------------------+------------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------+
| TIMESTAMP | RECORD_TYPE | RECORD | RESOURCE_ATTRIBUTES | RECORD_ATTRIBUTES |
|-------------------------+-------------+----------------------------+------------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------|
| 2025-08-17 13:18:05.590 | LOG | { | { | { |
| | | "severity_text": "FATAL" | "db.user": "TOMOKIYASUHARA", | "exception.escaped": true, |
| | | } | "snow.database.id": 21, | "exception.message": "Uncaught exception of type 'STATEMENT_ERROR' on line 5 at position 4 : Division by zero", |
| | | | "snow.database.name": "TEST_DB", | "exception.type": "100051" |
| | | | "snow.executable.id": 708, | } |
| | | | "snow.executable.name": "INSERT_DATA():VARCHAR", | |
| | | | "snow.executable.type": "PROCEDURE", | |
| | | | "snow.owner.id": 2, | |
| | | | "snow.owner.name": "ACCOUNTADMIN", | |
| | | | "snow.query.id": "01be6e3e-0002-b1d7-0002-b03a0004560a", | |
| | | | "snow.schema.id": 71, | |
| | | | "snow.schema.name": "PROCEDURES", | |
| | | | "snow.session.id": 11546585273, | |
| | | | "snow.session.role.primary.id": 2, | |
| | | | "snow.session.role.primary.name": "ACCOUNTADMIN", | |
| | | | "snow.user.id": 1, | |
| | | | "snow.warehouse.id": 4, | |
| | | | "snow.warehouse.name": "COMPUTE_WH", | |
| | | | "telemetry.sdk.language": "sql" | |
| | | | } | |
+-------------------------+-------------+----------------------------+------------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------+
上記手順やイベントテーブルについては以下の記事をご参照ください。
トレースを有効化
このままではトレースイベントは記録されないので、トレースレベルを変更します。ここではアカウントレベルで設定しています。
--トレースを有効化
ALTER ACCOUNT SET TRACE_LEVEL = 'ALWAYS';
>SHOW PARAMETERS LIKE '%TRACE_LEVEL%' IN ACCOUNT;
+-------------+--------+---------+---------+-----------------------------------------------------------------+--------+
| key | value | default | level | description | type |
|-------------+--------+---------+---------+-----------------------------------------------------------------+--------|
| TRACE_LEVEL | ALWAYS | OFF | ACCOUNT | Trace level value to use when generating/filtering trace events | STRING |
+-------------+--------+---------+---------+-----------------------------------------------------------------+--------+
この状態でストアドプロシージャを実行します。
--ストアドプロシージャを実行
>CALL insert_data();
100051 (22012): Uncaught exception of type 'STATEMENT_ERROR' on line 5 at position 4 : Division by zero
イベントテーブルを確認します。先のクエリのままでは情報が多いので、以下の通り整形しました。
トレースを有効化したのでSPANというレコードタイプが増えており、個々の操作のログが詳細に記録されるようになっています。
またsnow.executable.nameよりクエリの種類はわかりますが、具体的な内容（db.query.text）は現在の設定では出力されません。
>SELECT
TIMESTAMP,
RECORD_TYPE,
-- RECORDカラムから情報を抽出
RECORD:parent_span_id::STRING AS parent_span_id,
RECORD:name::STRING AS name,
RECORD:status.code::STRING AS staus_code,
-- RESOURCE_ATTRIBUTESカラムから情報を抽出
RESOURCE_ATTRIBUTES:"snow.executable.name"::STRING AS executable_name,
RESOURCE_ATTRIBUTES:"snow.executable.type"::STRING AS executable_type,
-- RECORD_ATTRIBUTESカラムから情報を抽出
RECORD_ATTRIBUTES:"db.query.text"::STRING AS DB_QUERY_TEXT,
FROM test_db.event_tables.test_events
WHERE RECORD_TYPE IN ('SPAN','EVENT')
ORDER BY TIMESTAMP DESC;
+-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------+
| TIMESTAMP | RECORD_TYPE | PARENT_SPAN_ID | NAME | STAUS_CODE | EXECUTABLE_NAME | EXECUTABLE_TYPE | DB_QUERY_TEXT |
|-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------|
| 2025-08-17 13:21:12.290 | SPAN | cf628b9ae62503d7 | snow.auto_instrumented | STATUS_CODE_ERROR | INSERT_DATA():VARCHAR | PROCEDURE | NULL |
| 2025-08-17 13:21:12.287 | SPAN | e8994f1b8065d12c | rollback | STATUS_CODE_OK | NULL | QUERY | NULL |
| 2025-08-17 13:21:12.046 | SPAN | e8994f1b8065d12c | select | STATUS_CODE_ERROR | NULL | QUERY | NULL |
| 2025-08-17 13:21:11.879 | SPAN | e8994f1b8065d12c | insert | STATUS_CODE_OK | NULL | QUERY | NULL |
| 2025-08-17 13:21:11.502 | SPAN | e8994f1b8065d12c | begin | STATUS_CODE_OK | NULL | QUERY | NULL |
+-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------+
トレースに SQL テキストを含める
パラメータを有効化し、トレースに SQL テキストを含めてみます。パラメータは現在アカウントレベルでのみ設定可能です。
--有効化
USE ROLE ACCOUNTADMIN;
ALTER ACCOUNT SET SQL_TRACE_QUERY_TEXT = 'ON';
>SHOW PARAMETERS LIKE '%SQL_TRACE_QUERY_TEXT%' IN ACCOUNT;
+----------------------+-------+---------+---------+------------------------------------------------------------------+--------+
| key | value | default | level | description | type |
|----------------------+-------+---------+---------+------------------------------------------------------------------+--------|
| SQL_TRACE_QUERY_TEXT | ON | OFF | ACCOUNT | If set to be 'on', we allow collecting query text in sql tracing | STRING |
+----------------------+-------+---------+---------+------------------------------------------------------------------+--------+
再度ストアドプロシージャを実行し、先のクエリでイベントテーブルを確認します。出力の [DB_QUERY_TEXT] を見ると、先頭5行のトレース（パラメータ有効化後のストアドプロシージャのトレース）では、ストアドプロシージャ内の各 SQL テキストを確認が収集され、確認できるようになっていました。
CALL insert_data();
>SELECT
TIMESTAMP,
RECORD_TYPE,
-- RECORDカラムから情報を抽出
RECORD:parent_span_id::STRING AS parent_span_id,
RECORD:name::STRING AS name,
RECORD:status.code::STRING AS staus_code,
-- RESOURCE_ATTRIBUTESカラムから情報を抽出
RESOURCE_ATTRIBUTES:"snow.executable.name"::STRING AS executable_name,
RESOURCE_ATTRIBUTES:"snow.executable.type"::STRING AS executable_type,
-- RECORD_ATTRIBUTESカラムから情報を抽出
RECORD_ATTRIBUTES:"db.query.text"::STRING AS DB_QUERY_TEXT,
FROM test_db.event_tables.test_events
WHERE RECORD_TYPE IN ('SPAN','EVENT')
ORDER BY TIMESTAMP DESC;
+-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------+
| TIMESTAMP | RECORD_TYPE | PARENT_SPAN_ID | NAME | STAUS_CODE | EXECUTABLE_NAME | EXECUTABLE_TYPE | DB_QUERY_TEXT |
|-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------|
| 2025-08-17 13:28:44.583 | SPAN | 923190a6454d8247 | snow.auto_instrumented | STATUS_CODE_ERROR | INSERT_DATA():VARCHAR | PROCEDURE | NULL |
| 2025-08-17 13:28:44.580 | SPAN | 288d2ca9a5f5c1df | rollback | STATUS_CODE_OK | NULL | QUERY | ROLLBACK |
| 2025-08-17 13:28:44.321 | SPAN | 288d2ca9a5f5c1df | select | STATUS_CODE_ERROR | NULL | QUERY | SELECT 1/0 |
| 2025-08-17 13:28:44.165 | SPAN | 288d2ca9a5f5c1df | insert | STATUS_CODE_OK | NULL | QUERY | INSERT INTO procedures.parent VALUES (1) |
| 2025-08-17 13:28:43.748 | SPAN | 288d2ca9a5f5c1df | begin | STATUS_CODE_OK | NULL | QUERY | BEGIN TRANSACTION |
| 2025-08-17 13:21:12.290 | SPAN | cf628b9ae62503d7 | snow.auto_instrumented | STATUS_CODE_ERROR | INSERT_DATA():VARCHAR | PROCEDURE | NULL |
| 2025-08-17 13:21:12.287 | SPAN | e8994f1b8065d12c | rollback | STATUS_CODE_OK | NULL | QUERY | NULL |
| 2025-08-17 13:21:12.046 | SPAN | e8994f1b8065d12c | select | STATUS_CODE_ERROR | NULL | QUERY | NULL |
| 2025-08-17 13:21:11.879 | SPAN | e8994f1b8065d12c | insert | STATUS_CODE_OK | NULL | QUERY | NULL |
| 2025-08-17 13:21:11.502 | SPAN | e8994f1b8065d12c | begin | STATUS_CODE_OK | NULL | QUERY | NULL |
+-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------+
ストアドプロシージャを実行するタスクでも同様に確認できます。
--ストアドプロシージャを実行するタスク作成
CREATE OR REPLACE TASK test_task
WAREHOUSE = compute_wh
SCHEDULE ='using cron 0 */1 * * * utc'
AS
--ストアドプロシージャを実行
CALL insert_data();
;
-- タスクを有効化して手動実行
EXECUTE TASK test_task;
イベントテーブルを確認（先頭6行がタスクのイベント）
>SELECT
TIMESTAMP,
RECORD_TYPE,
-- RECORDカラムから情報を抽出
RECORD:parent_span_id::STRING AS parent_span_id,
RECORD:name::STRING AS name,
RECORD:status.code::STRING AS staus_code,
-- RESOURCE_ATTRIBUTESカラムから情報を抽出
RESOURCE_ATTRIBUTES:"snow.executable.name"::STRING AS executable_name,
RESOURCE_ATTRIBUTES:"snow.executable.type"::STRING AS executable_type,
-- RECORD_ATTRIBUTESカラムから情報を抽出
RECORD_ATTRIBUTES:"db.query.text"::STRING AS DB_QUERY_TEXT,
FROM test_db.event_tables.test_events
WHERE RECORD_TYPE IN ('SPAN','EVENT')
ORDER BY TIMESTAMP DESC;
+-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------+
| TIMESTAMP | RECORD_TYPE | PARENT_SPAN_ID | NAME | STAUS_CODE | EXECUTABLE_NAME | EXECUTABLE_TYPE | DB_QUERY_TEXT |
|-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------|
| 2025-08-17 13:37:16.925 | EVENT | NULL | execution.status | NULL | TEST_TASK | TASK | NULL |
| 2025-08-17 13:37:16.308 | SPAN | 1b74cede6674989b | snow.auto_instrumented | STATUS_CODE_ERROR | INSERT_DATA():VARCHAR | PROCEDURE | NULL |
| 2025-08-17 13:37:16.306 | SPAN | 564c238d33953219 | rollback | STATUS_CODE_OK | NULL | QUERY | ROLLBACK |
| 2025-08-17 13:37:16.072 | SPAN | 564c238d33953219 | select | STATUS_CODE_ERROR | NULL | QUERY | SELECT 1/0 |
| 2025-08-17 13:37:15.871 | SPAN | 564c238d33953219 | insert | STATUS_CODE_OK | NULL | QUERY | INSERT INTO procedures.parent VALUES (1) |
| 2025-08-17 13:37:15.432 | SPAN | 564c238d33953219 | begin | STATUS_CODE_OK | NULL | QUERY | BEGIN TRANSACTION |
| 2025-08-17 13:28:44.583 | SPAN | 923190a6454d8247 | snow.auto_instrumented | STATUS_CODE_ERROR | INSERT_DATA():VARCHAR | PROCEDURE | NULL |
| 2025-08-17 13:28:44.580 | SPAN | 288d2ca9a5f5c1df | rollback | STATUS_CODE_OK | NULL | QUERY | ROLLBACK |
| 2025-08-17 13:28:44.321 | SPAN | 288d2ca9a5f5c1df | select | STATUS_CODE_ERROR | NULL | QUERY | SELECT 1/0 |
| 2025-08-17 13:28:44.165 | SPAN | 288d2ca9a5f5c1df | insert | STATUS_CODE_OK | NULL | QUERY | INSERT INTO procedures.parent VALUES (1) |
| 2025-08-17 13:28:43.748 | SPAN | 288d2ca9a5f5c1df | begin | STATUS_CODE_OK | NULL | QUERY | BEGIN TRANSACTION |
| 2025-08-17 13:21:12.290 | SPAN | cf628b9ae62503d7 | snow.auto_instrumented | STATUS_CODE_ERROR | INSERT_DATA():VARCHAR | PROCEDURE | NULL |
| 2025-08-17 13:21:12.287 | SPAN | e8994f1b8065d12c | rollback | STATUS_CODE_OK | NULL | QUERY | NULL |
| 2025-08-17 13:21:12.046 | SPAN | e8994f1b8065d12c | select | STATUS_CODE_ERROR | NULL | QUERY | NULL |
| 2025-08-17 13:21:11.879 | SPAN | e8994f1b8065d12c | insert | STATUS_CODE_OK | NULL | QUERY | NULL |
| 2025-08-17 13:21:11.502 | SPAN | e8994f1b8065d12c | begin | STATUS_CODE_OK | NULL | QUERY | NULL |
+-------------------------+-------------+------------------+------------------------+-------------------+-----------------------+-----------------+------------------------------------------+
さいごに
簡単な内容ではありましたが、ストアドプロシージャなどで実行される SQL ステートメントのトレース情報を取得する機能を試してみました。
こちらの内容が何かの参考になれば幸いです。
