Logging messages in Snowflake Scripting¶

You can log messages from a stored procedure handler written in Snowflake Scripting by using the Snowflake SYSTEM$LOG, SYSTEM$LOG_<level> (for Snowflake Scripting) function. When you’ve set up an event table to store log entries, Snowflake stores log entries generated by your handler code in the table.

Before logging from code, be sure you have the logging level set so that the messages you want are stored in the event table. For more information, see Setting levels for logging, metrics, and tracing.

Note

Before you can begin logging messages, you must set up an event table. For more information, see Event table overview.

You can access log messages by executing a SELECT command on the event table. For more information, see Viewing log messages.

For general information about setting up logging and retrieving messages in Snowflake, see Logging messages from functions and procedures.

Snowflake Scripting example¶

Code in the following example uses the SYSTEM$LOG function to log messages at each of the supported levels. Note that a message logged from code that processes an input row will be logged for every row processed by the handler. If the handler is executed in a large table, this can result in a large number of messages in the event table.

-- The following calls are equivalent.
-- Both log information-level messages.
SYSTEM$LOG('info', 'Information-level message');
SYSTEM$LOG_INFO('Information-level message');

-- The following calls are equivalent.
-- Both log error messages.
SYSTEM$LOG('error', 'Error message');
SYSTEM$LOG_ERROR('Error message');


-- The following calls are equivalent.
-- Both log warning messages.
SYSTEM$LOG('warning', 'Warning message');
SYSTEM$LOG_WARN('Warning message');

-- The following calls are equivalent.
-- Both log debug messages.
SYSTEM$LOG('debug', 'Debug message');
SYSTEM$LOG_DEBUG('Debug message');

-- The following calls are equivalent.
-- Both log trace messages.
SYSTEM$LOG('trace', 'Trace message');
SYSTEM$LOG_TRACE('Trace message');

-- The following calls are equivalent.
-- Both log fatal messages.
SYSTEM$LOG('fatal', 'Fatal message');
SYSTEM$LOG_FATAL('Fatal message');

Automatically add log messages about blocks and child jobs¶

You can automatically log the following additional information about the execution of a Snowflake Scripting stored procedure:

BEGIN/END of a Snowflake Scripting block.
BEGIN/END of a child job request.

Automatic logging is intended for the following use cases:

You want to generate the additional log messages without modifying the body of the stored procedure.
You want comprehensive information about the execution of the stored procedure.
You want more visibility into stored procedure execution to make it easier to develop and debug it without manually adding logging code in the procedure.

To automatically log these Snowflake Scripting messages for a stored procedure, set the AUTO_EVENT_LOGGING parameter for the stored procedure to LOGGING or ALL using the ALTER PROCEDURE command. When you set this parameter to ALL, additional trace events are also emitted automatically for the stored procedure.

Important

The additional information is added to the event table only if the effective LOG_LEVEL is set to TRACE. For more information, see Setting levels for logging, metrics, and tracing.

For example, create a simple table and insert data:

CREATE OR REPLACE TABLE test_auto_event_logging (id INTEGER, num NUMBER(12, 2));

INSERT INTO test_auto_event_logging (id, num) VALUES
  (1, 11.11),
  (2, 22.22);

Next, create a stored procedure named auto_event_logging_sp. This sample stored procedure updates a table row and then queries the table:

CREATE OR REPLACE PROCEDURE auto_event_logging_sp(
  table_name VARCHAR,
  id_val INTEGER,
  num_val NUMBER(12, 2))
RETURNS TABLE()
LANGUAGE SQL
AS
$$
BEGIN
  UPDATE IDENTIFIER(:table_name)
    SET num = :num_val
    WHERE id = :id_val;
  LET res RESULTSET := (SELECT * FROM IDENTIFIER(:table_name) ORDER BY id);
  RETURN TABLE(res);
EXCEPTION
  WHEN statement_error THEN
    res := (SELECT :sqlcode sql_code, :sqlerrm error_message, :sqlstate sql_state);
    RETURN TABLE(res);
END;
$$
;

The following examples set the AUTO_EVENT_LOGGING parameter for the stored procedure:

ALTER PROCEDURE auto_event_logging_sp(VARCHAR, INTEGER, NUMBER)
  SET AUTO_EVENT_LOGGING = 'LOGGING';

ALTER PROCEDURE auto_event_logging_sp(VARCHAR, INTEGER, NUMBER)
  SET AUTO_EVENT_LOGGING = 'ALL';

Call the stored procedure:

CALL auto_event_logging_sp('test_auto_event_logging', 2, 33.33);

+----+-------+
| ID |   NUM |
|----+-------|
|  1 | 11.11 |
|  2 | 33.33 |
+----+-------+

Query the event table for messages logged by the stored procedure named auto_event_logging_sp. For each message, print out the timestamp, log level, and text of the message.

SELECT
    TIMESTAMP as time,
    RECORD['severity_text'] as severity,
    VALUE as message
  FROM
    my_db.public.my_events
  WHERE
    RESOURCE_ATTRIBUTES['snow.executable.name'] LIKE '%AUTO_EVENT_LOGGING_SP%'
    AND RECORD_TYPE = 'LOG';

+-------------------------+----------+----------------------------------+
| TIME                    | SEVERITY | MESSAGE                          |
|-------------------------+----------+----------------------------------|
| 2024-10-25 20:42:24.134 | "TRACE"  | "Entering outer block at line 2" |
| 2024-10-25 20:42:24.135 | "TRACE"  | "Entering block at line 2"       |
| 2024-10-25 20:42:24.135 | "TRACE"  | "Starting child job"             |
| 2024-10-25 20:42:24.633 | "TRACE"  | "Ending child job"               |
| 2024-10-25 20:42:24.633 | "TRACE"  | "Starting child job"             |
| 2024-10-25 20:42:24.721 | "TRACE"  | "Ending child job"               |
| 2024-10-25 20:42:24.721 | "TRACE"  | "Exiting with return at line 7"  |
+-------------------------+----------+----------------------------------+