Real-time profiling

You can monitor long-running queries while they execute by querying system table EXECUTION_ENGINE_PROFILES.

You can monitor long-running queries while they execute by querying system table EXECUTION_ENGINE_PROFILES. This table contains available profiling counters for internal operations and user statements. You can use the Linux watch command to query this table at frequent intervals.

Queries for real-time profiling data require a transaction ID. If the transaction executes multiple statements, the query also requires a statement ID to identify the desired statement. If you profile individual queries, the query returns with the statement's transaction and statement IDs. You can also obtain transaction and statement IDs from the SYSTEM_SESSIONS system table.

Profiling counters

The EXECUTION_ENGINE_PROFILES system table contains available profiling counters for internal operations and user statements. Real-time profiling counters are available for all statements while they execute, including internal operations such as mergeout, recovery, and refresh. Unless you explicitly enable profiling using the keyword PROFILE on a specific SQL statement, or generally enable profiling for the database and/or the current session, profiling counters are unavailable after the statement completes.

Useful counters include:

  • Execution time (µs)

  • Rows produced

  • Total merge phases

  • Completed merge phases

  • Current size of temp files (bytes)

You can view all available counters by querying EXECUTION_ENGINE_PROFILES:

=> SELECT DISTINCT(counter_name) FROM EXECUTION_ENGINE_PROFILES;

To monitor the profiling counters, you can run a command like the following using a retrieved transaction ID (a000000000027):

=> SELECT * FROM execution_engine_profiles
   WHERE TO_HEX(transaction_id)='a000000000027'
   AND counter_name = 'execution time (us)'
   ORDER BY node_name, counter_value DESC;

The following example finds operators with the largest execution time on each node:

=> SELECT node_name, operator_name, counter_value execution_time_us FROM V_MONITOR.EXECUTION_ENGINE_PROFILES WHERE counter_name='execution time (us)' LIMIT 1 OVER(PARTITION BY node_name ORDER BY counter_value DESC);
    node_name     | operator_name | execution_time_us
------------------+---------------+-------------------
 v_vmart_node0001 | Join          |            131906
 v_vmart_node0002 | Join          |            227778
 v_vmart_node0003 | NetworkSend   |            524080
(3 rows)

Linux watch command

You can use the Linux watch command to monitor long-running queries at frequent intervals. Common use cases include:

  • Observing executing operators within a query plan on each Vertica cluster node.

  • Monitoring workloads that might be unbalanced among cluster nodes—for example, some nodes become idle while others are active. Such imbalances might be caused by data skews or by hardware issues.

In the following example, watch queries operators with the largest execution time on each node. The command specifies to re-execute the query each second:

watch -n 1 -d "vsql VMart -c\"SELECT node_name, operator_name, counter_value execution_time_us
FROM v_monitor.execution_engine_profiles WHERE counter_name='execution time (us)'
LIMIT 1 OVER(PARTITION BY node_name ORDER BY counter_value DESC);

Every 1.0s: vsql VMart -c"SELECT node_name, operator_name, counter_value execution_time_us FROM v_monitor.execu...  Thu Jan 21 15:00:44 2016

    node_name     | operator_name | execution_time_us
------------------+---------------+-------------------
 v_vmart_node0001 | Root          |            110266
 v_vmart_node0002 | UnionAll      |             38932
 v_vmart_node0003 | Scan          |             22058
(3 rows)