Skip to main content

processors_profile_log

This table contains profiling on processors level (that you can find in EXPLAIN PIPELINE).

Columns:

  • hostname (LowCardinality(String)) — Hostname of the server executing the query.
  • event_date (Date) — The date when the event happened.
  • event_time (DateTime) — The date and time when the event happened.
  • event_time_microseconds (DateTime64) — The date and time with microseconds precision when the event happened.
  • id (UInt64) — ID of processor
  • parent_ids (Array(UInt64)) — Parent processors IDs
  • plan_step (UInt64) — ID of the query plan step which created this processor. The value is zero if the processor was not added from any step.
  • plan_group (UInt64) — Group of the processor if it was created by query plan step. A group is a logical partitioning of processors added from the same query plan step. Group is used only for beautifying the result of EXPLAIN PIPELINE result.
  • initial_query_id (String) — ID of the initial query (for distributed query execution).
  • query_id (String) — ID of the query
  • name (LowCardinality(String)) — Name of the processor.
  • elapsed_us (UInt64) — Number of microseconds this processor was executed.
  • input_wait_elapsed_us (UInt64) — Number of microseconds this processor was waiting for data (from other processor).
  • output_wait_elapsed_us (UInt64) — Number of microseconds this processor was waiting because output port was full.
  • input_rows (UInt64) — The number of rows consumed by processor.
  • input_bytes (UInt64) — The number of bytes consumed by processor.
  • output_rows (UInt64) — The number of rows generated by processor.
  • output_bytes (UInt64) — The number of bytes generated by processor. Example

Query:

EXPLAIN PIPELINE
SELECT sleep(1)
┌─explain─────────────────────────┐
(Expression)
│ ExpressionTransform │
(SettingQuotaAndLimits)
(ReadFromStorage)
│ SourceFromSingleChunk 01
└─────────────────────────────────┘

SELECT sleep(1)
SETTINGS log_processors_profiles = 1
Query id: feb5ed16-1c24-4227-aa54-78c02b3b27d4
┌─sleep(1)─┐
0
└──────────┘
1 rows in set. Elapsed: 1.018 sec.

SELECT
name,
elapsed_us,
input_wait_elapsed_us,
output_wait_elapsed_us
FROM system.processors_profile_log
WHERE query_id = 'feb5ed16-1c24-4227-aa54-78c02b3b27d4'
ORDER BY name ASC

Result:

┌─name────────────────────┬─elapsed_us─┬─input_wait_elapsed_us─┬─output_wait_elapsed_us─┐
│ ExpressionTransform │ 1000497 │ 2823 │ 197 │
│ LazyOutputFormat │ 36 │ 1002188 │ 0 │
│ LimitsCheckingTransform │ 10 │ 1002994 │ 106 │
│ NullSource │ 5 │ 1002074 │ 0 │
│ NullSource │ 1 │ 1002084 │ 0 │
│ SourceFromSingleChunk │ 45 │ 4736 │ 1000819 │
└─────────────────────────┴────────────┴───────────────────────┴────────────────────────┘

Here you can see:

  • ExpressionTransform was executing sleep(1) function, so it work will takes 1e6, and so elapsed_us > 1e6.
  • SourceFromSingleChunk need to wait, because ExpressionTransform does not accept any data during execution of sleep(1), so it will be in PortFull state for 1e6 us, and so output_wait_elapsed_us > 1e6.
  • LimitsCheckingTransform/NullSource/LazyOutputFormat need to wait until ExpressionTransform will execute sleep(1) to process the result, so input_wait_elapsed_us > 1e6.

See Also