ApsaraDB for SelectDB:Query profiles

Profile parameters

The following tables describe the parameters in the collected statistics.

Fragment

BlockMgr

DataStreamSender

ODBC_TABLE_SINK

EXCHANGE_NODE

SORT_NODE

AGGREGATION_NODE

HASH_JOIN_NODE

CROSS_JOIN_NODE

UNION_NODE

ANALYTIC_EVAL_NODE

OLAP_SCAN_NODE

OLAP_SCAN_NODE is responsible for specific data scan tasks. It generates one or more OLAP scanners. Each scanner thread is responsible for scanning partial data.

Some or all of the predicate conditions in the query are pushed to OLAP_SCAN_NODE. Some of these predicate conditions are pushed down to the storage engine for data filtering by using the indexes of the storage engine. The other predicate conditions are retained in OLAP_SCAN_NODE and are used to filter the data returned from the storage engine.

The profile of OLAP_SCAN_NODE is generally used to analyze the efficiency of data scanning. The profile is divided into the following three layers based on the call relationships: OLAP_SCAN_NODE, OlapScanner, and SegmentIterator.

The following sample code shows a typical OLAP_SCAN_NODE node. The meanings of some metrics may vary with the storage format (V1 or V2).

OLAP_SCAN_NODE (id=0):(Active: 1.2ms, % non-child: 0.00%)
  - BytesRead: 265.00 B                 # The size of data that is read from the data file. For example, if 10 32-bit integers are read, the data size is 10 × 4 bytes = 40 bytes. This parameter indicates only the size of the data that is fully displayed in the memory, and does not indicate the actual I/O size.  
  - NumDiskAccess: 1                    # The number of disks that are involved in the ScanNode node. 
  - NumScanners: 20                     # The number of scanners that are generated by the ScanNode node. 
  - PeakMemoryUsage: 0.00               # The peak memory usage during query. The memory is not used.
  - RowsRead: 7                         # The number of rows that are returned from the storage engine to the scanner, excluding the number of rows that are filtered by the scanner. 
  - RowsReturned: 7                     # The number of rows that are returned from the ScanNode node to the parent node. 
  - RowsReturnedRate: 6.979K /sec       # RowsReturned/ActiveTime
  -TabletCount: 20 # The number of tablets involved in the ScanNode node. 
  - TotalReadThroughput: 74.70 KB/sec   # The total read throughout that is calculated by dividing BytesRead by the total execution time on this node from the initiation to the completion of the query. For I/O constrained queries, the value is close to the total throughput of the disk. 
  - ScannerBatchWaitTime: 426.886us     # The time for the transfer thread to wait for the scanner thread to return RowBatch data. 
  - ScannerWorkerWaitTime: 17.745us     # The time for the scanner thread to wait for the available worker threads in the thread pool. 
  OlapScanner:
    - BlockConvertTime: 8.941us         # The time consumed to convert a vectorized block to a row-structured RowBlock. A vectorized block is VectorizedRowBatch in V1 and RowBlockV2 in V2. 
    - BlockFetchTime: 468.974us         # The time for the rowset reader to obtain blocks. 
    - ReaderInitTime: 5.475ms           # The time for the OLAP scanner to initialize readers. The MergeHeap creation time is included in V1. The time consumed for generating all levels of Iterators and reading the first group of blocks is included in V2. 
    - RowsDelFiltered: 0                # The number of rows that are filtered out, including those based on the DELETE information in the tablet and those for rows that are marked for deletion in the Unique Key model. 
    - RowsPushedCondFiltered: 0         # The condition that is filtered out based on the predicate that is pushed down, such as the condition that is passed from BuildTable to ProbeTable in the join operation. This value is not accurate. If the filtering effect is poor, no filtering operation is performed. 
    - ScanTime: 39.24us                 # The time for the data to be returned from ScanNode to the parent node. 
    - ShowHintsTime_V1: 0ns             # This parameter is not applicable in V2. Some data is read for ScanRange splitting in V1. 
    SegmentIterator:
      - BitmapIndexFilterTimer: 779ns   # The time consumed to filter data by using bitmap indexes. 
      - BlockLoadTime: 415.925us        # The time consumed for the segment reader (V1) or segment iterator (V2) to obtain blocks. 
      - BlockSeekCount: 12              # The number of times that block seeking is performed during segment reading. 
      - BlockSeekTime: 222.556us        # The time consumed for block seeking during segment reading. 
      - BlocksLoad: 6                   # The number of blocks that are read.
      - CachedPagesNum: 30              # The number of pages that hit the cache after page cache is enabled only in V2. 
      - CompressedBytesRead: 0.00       # The size of data before decompression that is read from the file in V1, or the size of the read pages before compression that do not hit the page cache in V2. 
      - DecompressorTimer: 0ns          # The time consumed for data decompression. 
      - IOTimer: 0ns                    # The actual I/O time of reading data from the operating system. 
      - IndexLoadTime_V1: 0ns           # The time consumed to read index streams only in V1. 
      - NumSegmentFiltered: 0           # The number of segments that are completely filtered out based on the column statistics and query conditions. 
      - NumSegmentTotal: 6              # The number of all segments that are involved in the query. 
      - RawRowsRead: 7                  # The number of source data rows that are read from the storage engine. For more information, see the following section. 
      - RowsBitmapIndexFiltered: 0      # The number of rows that are filtered by using bitmap indexes only in V2. 
      - RowsBloomFilterFiltered: 0      # The number of rows that are filtered out by using BloomFilter indexes only in V2. 
      - RowsKeyRangeFiltered: 0         # The number of rows that are filtered out by using SortkeyIndex indexes only in V2. 
      - RowsStatsFiltered: 0            # The number of rows that are filtered out by using ZoneMap indexes in V2, including delete conditions. The number of rows that are filtered out by using BloomFilter indexes is included in V1. 
      - RowsConditionsFiltered: 0       # The number of rows that are filtered out by using various column indexes only in V2. 
      - RowsVectorPredFiltered: 0       # The number of rows that are filtered out by using filtering operations based on vectorized conditions. 
      - TotalPagesNum: 30               # The total number of pages that are read only in V2. 
      - UncompressedBytesRead: 0.00     # The size of the data file that is read after decompression in V1. If decompression is not required, this parameter specifies the size of the file. This parameter specifies the size of pages that do not hit the page cache after decompression in V2. If decompression is not required, this parameter specifies the size of pages.
      - VectorPredEvalTime: 0ns         # The time consumed to perform filtering by vectorized condition. 
      - ShortPredEvalTime: 0ns          # The time consumed to perform filtering by short circuit predicate. 
      - PredColumnReadTime: 0ns         # The time consumed for predicate column reading. 
      - LazyReadTime: 0ns               # The time consumed to read non-predicate columns. 
      - OutputColumnTime: 0ns           # The time consumed for column materialization.

Predicate condition pushdown and index usage can be inferred from the metrics related to the number of data rows in the profile. The following section describes the profile information during the reading of segments in the V2 format. These metrics have slightly different meanings for segments in the V1 format.

Initialization phase

1. During the reading of a segment in the V2-format, if the query has key_ranges (a query range consisting of prefix keys), the data is first filtered by using SortkeyIndex indexes. The number of rows that are filtered out is recorded in RowsKeyRangeFiltered.

2. Accurate filtering is performed on columns by using bitmap indexes if the query conditions contain bitmap indexes. The number of rows that is filtered out is recorded in RowsBitmapIndexFiltered.

3. Data is filtered based on the equivalent (eq, in, and is) condition in query conditions by using BloomFilter indexes. The number of rows that are filtered out is recorded in RowsBloomFilterFiltered. RowsBloomFilterFiltered specifies the difference between the total number of rows in the segment (not the number of rows that are filtered out by using bitmap indexes) and the remaining number of rows after filtering by using BloomFilter indexes. As a result, the data that is filtered by using BloomFilter indexes may overlap with the data that is filtered by using bitmap indexes.

4. Data is filtered by using ZoneMap indexes based on query and delete conditions. The number of rows that are filtered out is recorded in RowsStatsFiltered.

5. RowsConditionsFiltered specifies the number of rows that are filtered out by using various indexes, including the values of RowsBloomFilterFiltered and RowsStatsFiltered.

Next phase

• The number of rows that are filtered out by using the delete conditions in the next phase is recorded in RowsDelFiltered. The number of rows that are actually filtered by using the delete conditions is recorded in RowsStatsFiltered and RowsDelFiltered.

• RawRowsRead specifies the number of rows to be read after the preceding filtering operations are performed.

• RowsRead specifies the number of rows that are returned to the scanner. Generally, the value of RowsRead is less than that of RawRowsRead. This is because the data that is returned from the storage engine to the scanner may be aggregated. If the difference between the value of RawRowsRead and that of RowsRead is larger than expected, a large number of rows are aggregated, which may be time-consuming.

• RowsReturned specifies the number of rows that are finally returned by ScanNode to the parent node. Generally, the value of RowsReturned is also less than that of RowsRead. Some predicate conditions are not pushed down to the storage engine on the scanner. This indicates that filtering is performed. If the difference between the value of RowsRead and that of RowsReturned is larger than expected, a large number of rows are filtered on the scanner. This indicates that multiple predicate conditions with high selectivity are not pushed to the storage engine. The filtering efficiency of the scanner is lower than that of the storage engine.

Based on the preceding metrics, you can roughly analyze the number of rows that are processed by the storage engine and the number of rows in the final results after the filtering. This set of metrics (Rows***Filtered) also allows you to analyze whether the query conditions are pushed down to the storage engine and the filtering effect of different indexes.

Other metrics

You can also perform analysis based on the following metrics:

• Metrics under OlapScanner, such as IOTimer and BlockFetchTime, are the accumulation of all scanner thread metrics. As a result, the metrics values may be relatively large. Scanner threads asynchronously read data. In this case, these accumulated metric values can only reflect the accumulated working time of the scanner, and cannot directly indicate the time consumed by ScanNode. The proportion of the time consumed by ScanNode in the entire execution plan is recorded in Active. In some cases, the value of IOTimer is tens of seconds, whereas the value of Active is only a few seconds. The following items may describe the causes.

  • IOTimer is the cumulative time of multiple scanners, and a large number of scanners are available.

  • The parent node is time-consuming. For example, the parent node consumes 100 seconds, whereas ScanNode consumes only 10 seconds. The value of the Active parameter may be only a few milliseconds. When the parent node is processing data, ScanNode has asynchronously scanned the data and prepared the data. Therefore, the parent node can obtain the data that are prepared in ScanNode. In this case, the active time is short.

• NumScanners indicates the number of tasks that the scanner submits to the thread pool, which is scheduled by the thread pool in RuntimeState. The doris_scanner_thread_pool_thread_num and doris_scanner_thread_pool_queue_size parameters respectively specify the size and queue length of the thread pool. If the number of threads is excessive or insufficient, the query efficiency is affected. You can also divide some metrics by the number of threads to roughly estimate the time consumed by each thread.

• TabletCount indicates the number of tablets to be scanned. Excessive tablets indicate that a large number of random read and data merge operations are required.

• UncompressedBytesRead indirectly reflects the size of data that is read. If the value is large, a large number of I/O operations may be performed.

• You can check the page cache hits based on CachedPagesNum and TotalPagesNum. A higher hit ratio indicates that the I/O and decompression operations consume less time.

Buffer pool