Analyze Invantive Script executions using the Invantive Script data dictionary

Wiki (nl)
, ,
1

From release 26.0.213 an Invantive Script can report on itself. The new script service provider exposes the execution profile of the running script as four SQL tables of metadata (data dictionary). The duration, row counts and outcome of every statement can be queried with a simple select statement instead of being read back from a log file afterwards.

This article describes what the provider holds, how to find the slow statements in an Invantive Script, and which limitations apply.

What the script Service Provider Contains

The service provider script is always present in a database and needs no entry in the settings file. It provides four read-only tables:

  • Runs@script: one row per run of a script, with its source, its nesting and its outcome.
  • StatementExecutions@script: one row per script statement executed, with its text, its measurements and its outcome.
  • Variables@script: the scripting variables in effect, with their origin.
  • OsCommands@script: the operating-system commands started on behalf of the script.

SQL statements display the data as always:

image
image1250×732 36.1 KB

The covers the process in which the statements run. It is held in memory and starts empty each time the Invantive program is started, so a query returns the statements of the current process only.

The provider is available in the products which include Invantive Script, such as Invantive Data Hub and Invantive Query Tool. It is not available on Invantive Cloud, in line with Invantive Script itself, since Invantive Script is for client side processing.

Find the Slowest Statements in a Script

The most common use is finding out where the time of a nightly ETL script goes. The following statement lists the ten slowest statements which have finished:

select sen.id
,      sen.statement_type
,      sen.sql_operation
,      sen.duration_ms
,      sen.rows_affected
,      substr(sen.statement_text, 1, 60) statement_text
from   StatementExecutions@script sen
where  sen.ended_utc is not null
order 
by     sen.duration_ms desc
limit  10

In additionto the wall-clock duration DURATION_MS the table holds CPU_MS, IO_MS and SLEEP_MS, which separate calculation from waiting. A statement with a high SLEEP_MS is waiting on a rate limit of a platform rather than doing work.

Report the Statements Which Failed

The outcome of each statement is registered whether it succeeded or not:

select sen.id
,      sen.statement_type
,      sen.error_message_code
,      sen.error_message
from   StatementExecutions@script sen
whe    sen.successful = false
order 
by     sen.id desc

ON_ERROR_MODE states the behaviour which was in effect when the statement failed, being one of EXIT, CONTINUE, IGNORE and DEFAULT. That makes it possible to tell a statement which was allowed to fail from one which should have stopped the run.

Total the Time per Kind of Statement

A script mixes SQL statements, local statements of Invantive Script and operating-system commands. The following statement totals the time per kind:

select sen.statement_type
,      count(*) statements
,      sum(sen.duration_ms) duration_ms
from   StatementExecutions@script sen
group 
by     sen.statement_type
order 
by     sen.duration_ms desc

Repeated Statements

STATEMENT_HASH holds the SHA-256 hash of the statement as it was written, before the scripting variables were replaced by their values. Grouping on it therefore brings together the executions of one statement in a loop, even though each execution ran with different values:

select sen.statement_hash
,      count(*) executions
,      sum(sen..duration_ms) duration_ms
,      max(substr(sen.statement_text_raw, 1, 60)) statement_start
from   StatementExecutions@script sen
group 
by     sen.statement_hash
order 
by     sen.duration_ms desc

See also: