Skip to main content
Version: 2.5

Analyze query profile

This topic describes how to check the query profile. A query profile records the execution information of all worker nodes involved in a query. Query profiles help you quickly identify the bottlenecks that affect the query performance of your StarRocks cluster.

Enable query profile

For StarRocks versions earlier than v2.5, you can enable query profile by setting the variable is_report_success to true:

set is_report_success = true;

For StarRocks v2.5 or later versions, you can enable query profile by setting the variable enable_profile to true:

set enable_profile = true;

Access query profiles

Follow these steps to access your query profiles:

  1. Enter http://<fe_ip>:<fe_http_port> in your browser.
  2. On the page this is displayed, click queries on the top navigation pane.
  3. In the Finished Queries list, choose the query you want to check and click the link in the Profile column.

img

The browser redirects you to a new page that contains the corresponding query profile.

img

Interpret a query profile

Structure of a query profile

Following is an example query profile:

Query:
Summary:
Planner:
Execution Profile 7de16a85-761c-11ed-917d-00163e14d435:
Fragment 0:
Pipeline (id=2):
EXCHANGE_SINK (plan_node_id=18):
LOCAL_MERGE_SOURCE (plan_node_id=17):
Pipeline (id=1):
LOCAL_SORT_SINK (plan_node_id=17):
AGGREGATE_BLOCKING_SOURCE (plan_node_id=16):
Pipeline (id=0):
AGGREGATE_BLOCKING_SINK (plan_node_id=16):
EXCHANGE_SOURCE (plan_node_id=15):
Fragment 1:
...
Fragment 2:
...

A query profile consists of three sections:

  • Fragment: the execution tree. One query can be divided into one or more fragments.
  • Pipeline: the execution chain. An execution chain does not have branches. A fragment can be split into several pipelines.
  • Operator: A pipeline consists of a number of operators.

img

A fragment consists of several pipelines.

Key metrics

A query profile encompasses a mass of metrics that show the details of the query execution. In most cases, you only need to observe the execution time of the operators and the size of the data that they processed. After finding the bottlenecks, you can solve them accordingly.

Summary

MetricDescription
TotalTotal time consumed by the query, including the time spent in planning, executing, and profiling.
QueryCpuCostTotal CPU time cost of the query. CPU time costs are aggregated for concurrent processes. As a result, the value of this metric may be greater than the actual execution time of the query.
QueryMemCostTotal memory cost of the query.

Universal metrics for operators

MetricDescription
OperatorTotalTimeTotal CPU time cost of the operator.
PushRowNumTotal row count of the data that the operator pushed.
PullRowNumTotal row count of the data that the operator pulled.

Scan operator

MetricDescription
TableTable name.
ScanTimeTotal scan time. Scans are performed in the asynchronous I/O thread pool.
TabletCountNumber of tablets.
PushdownPredicatesNumber of the predicates that were pushed down.
BytesReadSize of the data read by StarRocks.
CompressedBytesReadSize of the compressed data read by StarRocks.
IOTimeTotal I/O time.
BitmapIndexFilterRowsRow count of the data that were filtered out by Bitmap index.
BloomFilterFilterRowsRow count of the data that were filtered out by Bloomfilter.
SegmentRuntimeZoneMapFilterRowsRow count of the data that were filtered out by runtime Zone Map.
SegmentZoneMapFilterRowsRow count of the data that were filtered out by Zone Map.
ShortKeyFilterRowsRow count of the data that were filtered out by Short Key.
ZoneMapIndexFilterRowsRow count of the data that were filtered out by Zone Map index.

Exchange operator

MetricDescription
PartTypeData distribution type. Valid values: UNPARTITIONED, RANDOM, HASH_PARTITIONED, and BUCKET_SHUFFLE_HASH_PARTITIONED.
BytesSentSize of the data that were sent.
OverallThroughputOverall throughput.
NetworkTimeData package transmission time (excluding the time of post-receiving processing). See FAQ below for more about how this metric is calculated and how it can hit an exception.
WaitTimeTime to wait because the queue at the sender side is full.

Aggregate operator

MetricDescription
GroupingKeysName of the grouping keys (GROUP BY columns).
AggregateFunctionsAggregate functions.
AggComputeTimeCompute time consumed by aggregate functions.
ExprComputeTimeCompute time consumed by the expression.
HashTableSizeSize of the hash table.

Join operator

MetricDescription
JoinPredicatesPredicates of the JOIN operation.
JoinTypeThe JOIN type.
BuildBucketsBucket number of the hash table.
BuildHashTableTimeTime used to build the hash table.
ProbeConjunctEvaluateTimeTime consumed by Probe Conjunct.
SearchHashTableTimerTime used to search the hash table.

Window Function operator

MetricDescription
ComputeTimeCompute time consumed by the window function.
PartitionKeysName of the partitioning keys (PARTITION BY columns).
AggregateFunctionsAggregate functions.

Sort operator

MetricDescription
SortKeysName of the sort keys (ORDER BY columns).
SortTypeResult sorting type: to list all results, or to list top n results.

TableFunction operator

MetricDescription
TableFunctionExecTimeCompute time consumed by the table function.
TableFunctionExecCountNumber of times the table function is executed.

Project operator

MetricDescription
ExprComputeTimeCompute time consumed by the expression.
CommonSubExprComputeTimeCompute time consumed by the common sub-expression.

LocalExchange operator

metricDescription
TypeLocal Exchange type. Valid values: Passthrough, Partition, and Broadcast.
ShuffleNumNumber of shuffles. This metric is valid only when Type is Partition.

Time consumed by operators

  • For the OlapScan and ConnectorScan operators, their time consumption is equivalent to OperatorTotalTime + ScanTime. Because the Scan operators perform I/O operations in the asynchronous I/O thread pool, ScanTime represents asynchronous I/O time.
  • The time consumption of the Exchange operator is equivalent to OperatorTotalTime + NetworkTime. Because the Exchange operator sends and receives data packages in the bRPC thread pool, NetworkTime represents the time consumed by network transmission.
  • For all other operators, their time cost is OperatorTotalTime.

Metric merging and MIN/MAX

Pipeline engine is a parallel computing engine. Each fragment is distributed to multiple machines for parallel processing, and pipelines on each machine are executed in parallel as multiple concurrent instances. Therefore, while profiling, StarRocks merges same metrics, and records the minimum and maximum values of each metric among all the concurrent instances.

Different merging strategies are adopted for different types of metrics:

  • Time metrics are averages. For example:
    • OperatorTotalTime represents the average time cost of all the concurrent instances.
    • __MAX_OF_OperatorTotalTime is the maximum time cost among all the concurrent instances.
    • __MIN_OF_OperatorTotalTime is the minimum time cost among all the concurrent instances.
             - OperatorTotalTime: 2.192us
- __MAX_OF_OperatorTotalTime: 2.502us
- __MIN_OF_OperatorTotalTime: 1.882us
  • Non-time metrics are totaled. For example:

    • PullChunkNum represents the total number of all concurrent instances.
    • __MAX_OF_PullChunkNum is the maximum value among all the concurrent instances.
    • __MIN_OF_PullChunkNum is the minimum value among all the concurrent instances.
                   - PullChunkNum: 146.66K (146660)
    - __MAX_OF_PullChunkNum: 24.45K (24450)
    - __MIN_OF_PullChunkNum: 24.435K (24435)
  • Some special metrics, which do not have minimum and maximum values, have identical values among all the concurrent instances (for example, DegreeOfParallelism).

Sharp difference between MIN and MAX

Usually, a noticeable difference between MIN and MAX values indicates the data is skewed. It possibly happens during aggregate or JOIN operations.

             - OperatorTotalTime: 2m48s
- __MAX_OF_OperatorTotalTime: 10m30s
- __MIN_OF_OperatorTotalTime: 279.170us

Visualize a query profile

If you are a user of StarRocks Enterprise Edition, you can visualize your query profiles via StarRocks Manager.

The Profile Overview page displays some summary metrics, including the total execution time ExecutionWallTime, I/O metrics, network transmission size, and the proportion of CPU and I/O time.

img

By clicking the card of an operator (a node), you can view its detailed information in the right pane of the page. There are three tabs:

  • Node: core metrics of this operator.
  • Node Detail: all metrics of this operator.
  • Pipeline: metrics of the pipeline to which the operator belongs. You do not need to pay much attention to this tab because it is related only to scheduling.

img

Identify bottlenecks

The larger the proportion of time taken by an operator, the darker color its card becomes. This helps you easily identify bottlenecks of the query.

img

Check whether data is skewed

Click the card of the operator that takes a large proportion of time, and check its MaxTime and MinTime. A noticeable difference between MaxTime and MinTime usually indicates data is skewed.

img

Then, click the Node Detail tab, and check if any metric shows an exception. In this example, the metric PushRowNum of the Aggregate operator shows data skew.

img

Check whether the partitioning or bucketing strategy takes effect

You can check whether the partitioning or bucketing strategy takes effect by viewing the corresponding query plan using EXPLAIN <sql_statement>.

img

Check whether the correct materialized view is used

Click the corresponding Scan operator and check the Rollup field on the Node Detail tab.

img

Check whether the JOIN plan is proper for left and right tables

Usually, StarRocks selects the smaller table as the right table of Join. An exception occurs if the query profile shows otherwise.

img

Check whether the distribution type of JOIN is correct

Exchange operators are classified into three types in accordance with the data distribution type:

  • UNPARTITIONED: Broadcast. Data is made into several copies and distributed to multiple BEs.
  • RANDOM: Round robin.
  • HASH_PARTITIONED and BUCKET_SHUFFLE_HASH_PARTITIONED: Shuffle. The difference between HASH_PARTITIONED and BUCKET_SHUFFLE_HASH_PARTITIONED lies in the hash functions used to calculate the hash code.

For Inner Join, the right table can be the HASH_PARTITIONED and BUCKET_SHUFFLE_HASH_PARTITIONED type or UNPARTITIONED type. Usually, UNPARTITIONED type is adopted only when there are less than 100K rows in the right table.

In the following example, the type of the Exchange operator is Broadcast, but the size of data transmitted by the operator greatly exceeds the threshold.

img

Check whether JoinRuntimeFilter takes effect

When the right child of Join is building a hash table, it creates a runtime filter. This runtime filter is sent to the left child tree, and is pushed down to the Scan operator if it is possible. You can check JoinRuntimeFilter-related metrics on the Node Detail tab of the Scan operator.

img

FAQ

Why is the time cost of the Exchange operator abnormal?

img

The time cost of an Exchange operator consists of two parts: CPU time and network time. Network time relies on the system clock. Network time is calculated as follows:

  1. The sender records a send_timestamp before calling the bRPC interface to send the package.
  2. The receiver records a receive_timestamp after receiving the package from the bRPC interface (post-receiving processing time excluded).
  3. After the processing is complete, the receiver sends a response and calculates the network latency. The package transmission latency is equivalent to receive_timestamp - send_timestamp.

If system clocks across machines are inconsistent, the time cost of the Exchange operator hits an exception.

Why is the total time cost of all operators significantly less than the query execution time?

Possible cause: In high-concurrency scenarios, some pipeline drivers, despite being schedulable, may not be processed in time because they are queued. The waiting time is not recorded in operators' metrics, but in PendingTime, ScheduleTime, and IOTaskWaitTime.

Example:

From the profile, we can see that ExecutionWallTime is about 55 ms. However, the total time cost of all operators is less than 10 ms, which is significantly less than ExecutionWallTime.

img