ApsaraDB for SelectDB:Sorgu profili

SHOW QUERY PROFILE "/<profile_id>"\G

SHOW QUERY PROFILE "/c257c52f93e149ee-ace8ac14e8c9fef9"\G
*************************** 1. row ***************************
Fragments:
             ┌──────────────────────┐
             │[-1: DataBufferSender]│
             │Fragment: 0           │
             │MaxActiveTime: 6.626 ms│
             └──────────────────────┘
                         │
               ┌──────────────────┐
               │[9: EXCHANGE_NODE]│
               │Fragment: 0       │
               └──────────────────┘
                         │
             ┌──────────────────────┐
             │[9: DataStreamSender] │
             │Fragment: 1           │
             │MaxActiveTime: 5.449 ms│
             └──────────────────────┘
                         │
                 ┌──────────────┐
                 │[4: SORT_NODE]│
                 │Fragment: 1   │
                 └──────────────┘
                        ┌┘
             ┌─────────────────────┐
             │[8: AGGREGATION_NODE]│
             │Fragment: 1          │
             └─────────────────────┘
                        └┐
               ┌──────────────────┐
               │[7: EXCHANGE_NODE]│
               │Fragment: 1       │
               └──────────────────┘
                         │
             ┌──────────────────────┐
             │[7: DataStreamSender] │
             │Fragment: 2           │
             │MaxActiveTime: 3.505 ms│
             └──────────────────────┘
                        ┌┘
             ┌─────────────────────┐
             │[3: AGGREGATION_NODE]│
             │Fragment: 2 │
             └─────────────────────┘
                        │
              ┌───────────────────┐
              │[2: HASH_JOIN_NODE]│
              │Fragment: 2        │
              └───────────────────┘
           ┌────────────┴────────────┐
 ┌──────────────────┐      ┌──────────────────┐
 │[5: EXCHANGE_NODE]│      │[6: EXCHANGE_NODE]│
 │Fragment: 2       │      │Fragment: 2       │
 └──────────────────┘      └──────────────────┘
           │                         │
┌─────────────────────┐ ┌────────────────────────┐
│[5: DataStreamSender]│ │[6: DataStreamSender] │
│Fragment: 4          │ │Fragment: 3             │
│MaxActiveTime: 1.87 ms│ │MaxActiveTime: 636.767 us│
└─────────────────────┘ └────────────────────────┘
           │                        ┌┘
 ┌───────────────────┐    ┌───────────────────┐
 │[0: OLAP_SCAN_NODE]│    │[1: OLAP_SCAN_NODE]│
 │Fragment: 4        │    │Fragment: 3        │
 └──────────────────┘      └──────────────────┘
           │                        │
    ┌─────────────┐          ┌─────────────┐
    │[OlapScanner]│          │[OlapScanner]│
    │Fragment: 4  │          │Fragment: 3  │
    └─────────────┘          └─────────────┘
           │                        │
  ┌─────────────────┐      ┌─────────────────┐
  │[SegmentIterator]│      │[SegmentIterator]│
  │Fragment: 4      │      │Fragment: 3      │
  └─────────────────┘      └─────────────────┘

1 row in set (0.02 sec)

SHOW QUERY PROFILE "/<profile_id>/<fragment_id>";

SHOW QUERY PROFILE "/c257c52f93e149ee-ace8ac14e8c9fef9/1";
+-----------------------------------+-------------------+------------+
| Instances                         | Host              | ActiveTime |
+-----------------------------------+-------------------+------------+
| c257c52f93e149ee-ace8ac14e8c9ff03 | 10.200.00.01:9060 | 5.449ms    |
| c257c52f93e149ee-ace8ac14e8c9ff05 | 10.200.00.02:9060 | 5.367ms    |
| c257c52f93e149ee-ace8ac14e8c9ff04 | 10.200.00.03:9060 | 5.358ms    |
+-----------------------------------+-------------------+------------+

SHOW QUERY PROFILE "/<profile_id>/<fragment_id>/<instance_id>"\G

SHOW QUERY PROFILE "/c257c52f93e149ee-ace8ac14e8c9fef9/1/c257c52f93e149ee-ace8ac14e8c9ff03"\G
*************************** 1. row ***************************
Instance:
 ┌───────────────────────────────────────┐
 │[9: DataStreamSender]                  │
 │(Active: 37.222 us, non-child: 0.40)    │
 │  - Counters:                          │
 │      - BytesSent: 0.00                │
 │      - IgnoreRows: 0                  │
 │      - OverallThroughput: 0.0 /sec    │
 │      - PeakMemoryUsage: 8.00 KB       │
 │      - SerializeBatchTime: 0ns        │
 │      - UncompressedRowBatchSize: 0.00 │
 └───────────────────────────────────────┘
                     └┐
                      │
    ┌──────────────────────────────────┐
    │[4: SORT_NODE]                    │
    │(Active: 5.421 ms, non-child: 0.71)│
    │  - Counters:                     │
    │      - PeakMemoryUsage: 12.00 KB │
    │ - RowsReturned: 0 │
    │      - RowsReturnedRate: 0       │
    └──────────────────────────────────┘
                     ┌┘
                     │
   ┌───────────────────────────────────┐
   │[8: AGGREGATION_NODE]              │
   │(Active: 5.355 ms, non-child: 10.68)│
   │  - Counters:                      │
   │      - BuildTime: 3.701us         │
   │      - GetResultsTime: 0 ns        │
   │      - HTResize: 0                │
   │      - HTResizeTime: 1.211 us      │
   │      - HashBuckets: 0             │
   │      - HashCollisions: 0          │
   │      - HashFailedProbe: 0         │
   │      - HashFilledBuckets: 0       │
   │      - HashProbe: 0               │
   │      - HashTravelLength: 0        │
   │      - LargestPartitionPercent: 0 │
   │      - MaxPartitionLevel: 0       │
   │      - NumRepartitions: 0         │
   │      - PartitionsCreated: 16      │
   │      - PeakMemoryUsage: 34.02 MB  │
   │      - RowsProcessed: 0           │
   │      - RowsRepartitioned: 0       │
   │      - RowsReturned: 0            │
   │      - RowsReturnedRate: 0        │
   │      - SpilledPartitions: 0       │
   └───────────────────────────────────┘
                     └┐
                      │
┌──────────────────────────────────────────┐
│[7: EXCHANGE_NODE]                        │
│(Active: 4.360 ms, non-child: 46.84)       │
│  - Counters:                             │
│      - BytesReceived: 0.00               │
│      - ConvertRowBatchTime: 387 ns        │
│      - DataArrivalWaitTime: 4.357 ms      │
│      - DeserializeRowBatchTimer: 0 ns     │
│      - FirstBatchArrivalWaitTime: 4.356 ms│
│      - PeakMemoryUsage: 0.00             │
│      - RowsReturned: 0                   │
│      - RowsReturnedRate: 0               │
│      - SendersBlockedTotalTimer(*): 0 ns  │
└──────────────────────────────────────────┘

OLAP_SCAN_NODE (id=0):(Active: 1.2ms, % non-child: 0.00%)
  - BytesRead: 265.00 B                 # Size of data read from data files. For example, 10 x 32-bit integers = 40 bytes. This reflects data fully loaded into memory, not raw I/O size.
  - NumDiskAccess: 1                    # Number of disks accessed by the ScanNode.
  - NumScanners: 20                     # Number of scanners created by the ScanNode.
  - PeakMemoryUsage: 0.00               # Peak memory usage during the query.
  - RowsRead: 7                         # Rows returned from the storage engine to the scanner, excluding rows filtered by the scanner.
  - RowsReturned: 7                     # Rows returned from the ScanNode to the parent node.
  - RowsReturnedRate: 6.979K /sec       # RowsReturned / ActiveTime.
  - TabletCount: 20                     # Number of tablets accessed by the ScanNode.
  - TotalReadThroughput: 74.70 KB/sec   # BytesRead divided by total execution time. For I/O-bound queries, this approaches total disk throughput.
  - ScannerBatchWaitTime: 426.886us     # Time for the transfer thread to wait for the scanner thread to return RowBatch data.
  - ScannerWorkerWaitTime: 17.745us     # Time for the scanner thread to wait for available worker threads in the thread pool.
  OlapScanner:
    - BlockConvertTime: 8.941us         # Time to convert a vectorized block to a row-structured RowBlock. The vectorized block is VectorizedRowBatch (V1) or RowBlockV2 (V2).
    - BlockFetchTime: 468.974us         # Time for the rowset reader to get blocks.
    - ReaderInitTime: 5.475ms           # Time for the OLAP scanner to initialize readers. Includes MergeHeap creation time (V1) and the time to generate all iterator levels and read the first block group (V2).
    - RowsDelFiltered: 0                # Rows filtered based on DELETE information in the tablet and rows marked for deletion in the Unique Key model.
    - RowsPushedCondFiltered: 0         # Rows filtered by predicates pushed down from a join operation (e.g., from BuildTable to ProbeTable). This value is approximate; filtering may be skipped if the effect is poor.
    - ScanTime: 39.24us                 # Time for data to travel from ScanNode to the parent node.
    - ShowHintsTime_V1: 0ns             # V1 only: time to read some data for ScanRange splitting.
    SegmentIterator:
      - BitmapIndexFilterTimer: 779ns   # Time to filter data using bitmap indexes.
      - BlockLoadTime: 415.925us        # Time for the segment reader (V1) or segment iterator (V2) to get blocks.
      - BlockSeekCount: 12              # Number of block seeks during segment reading.
      - BlockSeekTime: 222.556us        # Time consumed for block seeks during segment reading.
      - BlocksLoad: 6                   # Number of blocks read.
      - CachedPagesNum: 30              # V2 only: number of pages that hit the page cache.
      - CompressedBytesRead: 0.00       # V1: size of data before decompression read from file. V2: size of pages before compression that did not hit the page cache.
      - DecompressorTimer: 0ns          # Time consumed for data decompression.
      - IOTimer: 0ns                    # Actual I/O time for reading data from the operating system.
      - IndexLoadTime_V1: 0ns           # V1 only: time to read index streams.
      - NumSegmentFiltered: 0           # Number of segments completely filtered out based on column statistics and query conditions.
      - NumSegmentTotal: 6              # Total number of segments involved in the query.
      - RawRowsRead: 7                  # Source data rows read from the storage engine after all preceding filtering.
      - RowsBitmapIndexFiltered: 0      # V2 only: rows filtered using bitmap indexes.
      - RowsBloomFilterFiltered: 0      # V2 only: rows filtered using BloomFilter indexes.
      - RowsKeyRangeFiltered: 0         # V2 only: rows filtered using SortkeyIndex indexes.
      - RowsStatsFiltered: 0            # V2: rows filtered using ZoneMap indexes, including delete conditions. V1: includes rows filtered using BloomFilter indexes.
      - RowsConditionsFiltered: 0       # V2 only: rows filtered by all column indexes combined.
      - RowsVectorPredFiltered: 0       # Rows filtered by vectorized condition operations.
      - TotalPagesNum: 30               # V2 only: total number of pages read.
      - UncompressedBytesRead: 0.00     # V1: size of data after decompression (or file size if not compressed). V2: size of pages that did not hit the page cache after decompression (or page size if not compressed).
      - VectorPredEvalTime: 0ns         # Time to perform filtering by vectorized condition.
      - ShortPredEvalTime: 0ns          # Time to perform filtering by short-circuit predicate.
      - PredColumnReadTime: 0ns         # Time consumed for predicate column reading.
      - LazyReadTime: 0ns               # Time consumed to read non-predicate columns.
      - OutputColumnTime: 0ns           # Time consumed for column materialization.

Filtreleme ölçümlerinin birbirleriyle ilişkisi

Bir OLAP_SCAN_NODE profilindeki satır sayısı ölçümleri, koşulların ve dizinlerin her aşamada veri hacmini ne kadar etkili bir şekilde azalttığını ortaya koyar. Aşağıda V2 biçimli filtreleme sırası açıklanmaktadır. V1 biçimli ölçümlerin anlamları biraz farklıdır.

Başlatma aşaması

Filtreleme şu sırayla gerçekleşir:

1. SortkeyIndex — Sorguda anahtar aralıkları (ön ek anahtar aralıkları) varsa veriler önce filtrelenir. Elenen satırlar RowsKeyRangeFiltered içinde kaydedilir.

2. Bitmap dizinleri — Bitmap dizinleriyle eşleşen koşullar için doğru sütun filtrelemesi uygulanır. Elenen satırlar RowsBitmapIndexFiltered içinde kaydedilir.

3. BloomFilter dizinleri — Eşitlik koşulları (=, IN, IS) BloomFilter dizinleri kullanılarak filtrelenir. Elenen satırlar RowsBloomFilterFiltered içinde kaydedilir.

   Not

   RowsBloomFilterFiltered, toplam bölüm satırları eksi BloomFilter filtrelemesinden sonraki kalan satırlar olarak hesaplanır. Zaten bitmap dizinleri tarafından elenen satırlarla örtüşebilir.

4. ZoneMap dizinleri — Veriler sorgu ve silme koşullarına göre filtrelenir. Elenen satırlar RowsStatsFiltered içinde kaydedilir.

5. RowsConditionsFiltered , RowsBloomFilterFiltered ve RowsStatsFiltered dahil olmak üzere tüm dizinler tarafından birlikte filtrelenen toplam satırdır.

Sonraki aşama

Başlatmadan sonra kalan veriler ek aşamalardan geçer:

• RowsDelFiltered : Silme koşulları tarafından elenen satırlar. Bunlar ayrıca RowsStatsFiltered içinde de sayılır.

• RawRowsRead : Tüm önceki filtrelemeden sonra kalan satırlar.

• RowsRead : Depolama motorundan tarayıcıya döndürülen satırlar. Depolama motoru satırları birleştirebileceğinden bu değer genellikle RawRowsRead değerinden daha düşüktür. RawRowsRead ile RowsRead arasında büyük bir fark, performans sorunu olabilecek yoğun bir birleştirmeyi gösterir.

• RowsReturned : ScanNode tarafından üst düğüme nihai olarak döndürülen satırlar. Depolama motoruna yüklenmeyen koşullar tarayıcı düzeyinde uygulandığından bu değer genellikle RowsRead değerinden daha düşüktür. RowsRead ile RowsReturned arasında büyük bir fark, filtrelemenin daha verimli olduğu depolama motoruna ulaşmayan birçok yüksek seçicilikli koşul olduğunu gösterir.

Rows***Filtered ölçümleri birlikte, sorgu koşullarının depolama motoruna yüklenip yüklenmediğini ve her dizin türünün ne kadar etkili olduğunu değerlendirmenizi sağlar.

Diğer ölçümler

• OlapScanner altındaki ölçümler (IOTimer ve BlockFetchTime gibi) tüm tarayıcı iş parçacıklarında kümülatiftir. Tarayıcı iş parçacıkları verileri eşzamansız olarak okuduğundan bu birikmiş değerler toplam tarayıcı çalışma süresini yansıtır, ScanNode duvar saati süresini değil. Active yüzdesi, ScanNode'un genel çalıştırma planına katkıda bulunduğu zamanın gerçek oranını kaydeder. IOTimer onlarca saniye iken Active yalnızca birkaç saniye olması iki nedenden dolayı normaldir:

  • IOTimer paralel çalışan birçok tarayıcıda birikir.

  • Üst düğüm yavaşsa (örneğin, 100 saniye) ScanNode (10 saniye) erken biter ve arka planda verileri hazırlar. Üst düğüm ardından hazırlanan verileri alır, bu nedenle ScanNode'un Active süresi kısadır.

• NumScanners , tarayıcının RuntimeState tarafından yönetilen iş parçacığı havuzuna gönderdiği görev sayısıdır. doris_scanner_thread_pool_thread_num ve doris_scanner_thread_pool_queue_size parametreleri iş parçacığı havuzu boyutunu ve kuyruk uzunluğunu kontrol eder. İş parçacığı sayısı çok fazla veya yetersiz olursa sorgu verimliliği etkilenir. Bazı ölçümleri iş parçacığı sayısına bölerek her iş parçacığı için harcanan süreyi kabaca tahmin edebilirsiniz.

• TabletCount , taranacak tablet sayısıdır. Yüksek tablet sayısı, daha fazla rastgele okuma ve veri birleştirme işlemi anlamına gelir.

• UncompressedBytesRead , okunan veri hacmini yansıtır. Yüksek bir değer, yoğun G/Ç'yi gösterebilir.

• Sayfa önbelleği isabet oranını değerlendirmek için CachedPagesNum değerini TotalPagesNum ile karşılaştırın. Daha yüksek isabet oranı hem G/Ç hem de sıkıştırma açma ek yükünü azaltır.