Doris基础知识篇(7):profile解析
profile
查询分析 - Apache Doris
0.15之前：SET is_report_success=true;
0.15及之后：SET [GLOBAL] enable_profile=true;
展示所有profile：show query profile "/"
查询具体的profile：show query profile "/9312f30b1d144b62-b7db78576f34681b" 
查看某一个fragment：show query profile "/9312f30b1d144b62-b7db78576f34681b/2" 
查看一个instance的执行情况：show query profile "/9312f30b1d144b62-b7db78576f34681b/2/9312f30b1d144b62-b7db78576f34683b" 
| 节点 | 指标 | 其他 |
|---|---|---|
| Fragment | - hostname：执行Fragment的BE节点 - Active：表示该节点的执行时间 - non-child:表示执行节点自身的执行时间占总时间的百分比 - AverageThreadTokens: 执行Fragment使用线程数目 - FragmentCpuTime: 该fragment执行CPU耗时 - MemoryLimit: 查询时的内存限制 - PeakMemoryUsage: 内存消耗峰值 - PeakReservation: 内存预留峰值 - PeakUsedReservation: 使用预留内存峰值 - RowsProduced: 该fragment产生的行数 |
hostname指的是执行Fragment的BE节点； Active：10s270ms表示该节点的执行总时间； non-child: 0.14%表示执行节点自身的执行时间（不包含子节点的执行时间）占总时间的百分比； PeakMemoryUsage表示EXCHANGE_NODE内存使用的峰值； RowsReturned表示EXCHANGE_NODE结果返回的行数； RowsReturnedRate=RowsReturned/ActiveTime； 这三个统计信息在其他NODE中的含义相同。 |
| BlockMgr | - BlockWritesOutstanding: - BlocksCreated: BlockMgr创建的Blocks数目 - BlocksRecycled: 重用的Blocks数目 - BufferedPins: - BytesWritten: 总的落盘写数据量 - MaxBlockSize: 单个Block的大小 - TotalBufferWaitTime: - TotalEncryptionTime: - TotalIntegrityCheckTime: - TotalReadBlockTime: 读 Block 的总耗时 |
|
| DataStreamSender | - BytesSent: 发送的总数据量 = 接受者 * 发送数据量 - IgnoreRows: 忽略的行数 - OverallThroughput: 总的吞吐量 = BytesSent / 时间 - PeakMemoryUsage: 内存消耗峰值 - SerializeBatchTime: **发送数据序列化消耗的时间 ** - UncompressedRowBatchSize: **发送数据压缩前的RowBatch的大小 ** |
|
| OLAP_SCAN_NODE 注：OLAP_SCAN_NODE 节点的 Profile 通常用于分析数据扫描的效率，依据调用关系分为 OLAP_SCAN_NODE、OlapScanner、SegmentIterator 三层 |
- BlockLookupCacheTime:** 在缓存中查找pagecache的时间 - BlockPutCacheTime: pagecache放入缓存的时间 - BytesRead: 从数据文件中读取到的数据量。 - GetNextTime: GetNext阶段耗时 - MaxWaitScanTime: OlapScanner的最大打开时间 - NumDiskAccess: 涉及到的磁盘数量 - NumScanners: OlapScanner的数量 - PeakMemoryUsage: 内存使用峰值 - RowsRead: 从下层读到的行数 - RowsReturned: 向上层节点返回的行数，通常小于RowsRead，一些没有下推的条件会在scan node做过滤，scan node的过滤性能比存储层要差 - RowsReturnedRate: RowsReturned/ActiveTime - RowsetNum: 涉及的rowset数量 - RowsetReaderInitTime: RowsetReader 初始化耗时 - ScanCpuTime: 整个Scan的Cpu耗时 - ScannerBlockPutTimer: Scaner Task放入等待队列的阻塞时间 doris_scanner_thread_pool_thread_num 和 doris_scanner_thread_pool_queue_size 两个参数可以控制线程和队列大小 - ScannerMaxPendingTimer: Scaner Task在队列中最大等待时间 - SegmentNum: 涉及的segment数量 - StartScanTime: 调用start_scan方法耗时** - TabletCount : 涉及到的tablet数量 - TotalReadThroughput: BytesRead除以该节点运行的总时间，读取数据的吞吐量 OlapScanner: - BlockConvertTime: 将向量化Block转换为行结构的 RowBlock 的耗时 - BlockFetchTime: Reader 获取 Block 的时间 - ReaderInitTime: OlapScanner的Reader初始化耗时 - RowsDelFiltered:** 根据 Tablet 中存在的 Delete 信息过滤掉的行数，以及 unique key 模型下对被标记的删除行过滤的行数** - RowsPushedCondFiltered:** 被下推谓词过滤掉的行数** - ScanTime: Scan耗时 - ShowHintsTime_V1: SegmentIterator: - BitmapIndexFilterTimer:** 利用 bitmap 索引过滤数据的耗时** - BlockLoadTime: - BlockSeekCount: 读取 Segment 时进行 block seek 的次数 - BlockSeekTime:** 读取 Segment 时进行 block seek 的耗时** - BlocksLoad: 读取 Block 的数量 - CachedPagesNum: **命中的page数目，可以结合TotalPagesNum计算命中率 ** - CompressedBytesRead: 读取到的没有命中 PageCache 的 Page 的压缩前的大小 - DecompressorTimer: 数据解压耗时 - IOTimer: 实际从操作系统读取数据的 IO 时间 - IndexLoadTime_V1: - NumSegmentFiltered: 在生成 Segment Iterator 时，通过列统计信息和查询条件，完全过滤掉的 Segment 数量 - NumSegmentTotal: 涉及到的segment数量 - RawRowsRead: 存储引擎中读取的原始行数（通过各种索引过滤之后读取的行数） - RowsBitmapIndexFiltered: 通过 Bitmap 索引过滤掉的行数 - RowsBloomFilterFiltered: 通过 BloomFilter 索引过滤掉的行数 - RowsConditionsFiltered: **各种索引过滤的行数 ** - RowsKeyRangeFiltered: **通过 SortkeyIndex 索引过滤掉的行数 ** - RowsStatsFiltered: 0 - RowsVectorPredFiltered: 通过向量化条件过滤掉的行数 - TotalPagesNum: 读取的总 Page 数量 - UncompressedBytesRead: 读取的解压之后的数据大小 - VectorPredEvalTime: 向量化过滤操作的耗时 |
- OLAP_SCAN_NODE 节点负责具体的数据扫描任务。一个 OLAP_SCAN_NODE 会生成一个或多个 OlapScanner 。每个 Scanner 线程负责扫描部分（tablet）数据。 - 查询中的部分或全部谓词条件会推送给 OLAP_SCAN_NODE。这些谓词条件中一部分会继续下推给存储引擎，以便利用存储引擎的索引进行数据过滤。另一部分会保留在 OLAP_SCAN_NODE 中，用于过滤从存储引擎中返回的数据。 - OLAP_SCAN_NODE 节点的 Profile 通常用于分析数据扫描的效率，依据调用关系分为 OLAP_SCAN_NODE、OlapScanner、SegmentIterator 三层。- OlapScanNode 在拿到 FE 的请求参数后，会首先将下推到 Scan 节点的谓词表达式转为存储层的数据结构 TCondition，然后为了提高 Scan 的并发，会将 Scan 的范围切分的更细，然每个 Scan 线程可以只 Scan 部分数据，Scan 范围切分完之后，就会通过线程池启动多个线程，让每个 OlapScanner 线程 Scan 特定部分的数据。 - 一个 OlapScanner 会绑定一个 Tablet，OlapScanner 会根据 Scan 的 Tablet 和，Version，构造好 RowsetReader。RowsetReader 会逐行返回数据，每行数据是一个 RowCursor, OlapScanner 会先将 RowCursor 转为 Tuple， 因为在查询计算层，都是基于 Tuple 进行计算的，然后会用没有下推到存储层的 Filter, 对 Tuple 再进行一次过滤，最后会把 Tuple 加入 RowBatch 中，如果 RowBatch 满了，就会加入到 RowBatch 的 Queue 中，OlapScanNode 线程会不断从这个 Queue 中读取数据。 - OlapScanNode 针对大查询做了一个优化，因为 OlapScanner 的线程池是整个 BE 进程共享的，所以可能出现一个大查询占用了所有 OlapScanner 线程，导致小查询迟迟无法 Scan。 OlapScanNode 会根据 Scan Range 的个数，Scan 的数据量确定每个 Scan 的优先级，Scan Range 个数和 Scan 数据量越小，优先级越高，不过也会定期提高大查询的优先级，避免大查询完全饿死。 |
| HASH_JOIN_NODE | - ExecOption: ** 构造HashTable的方式 （同步、异步）【很多节点通用】** - BuildBuckets: HashTable的 bucket 数量，固定值1024 - BuildRows: ** HashTable的行数** - BuildTime: 构建HashTable的时间 - LoadFactor: HashTable的负载因子 - PeakMemoryUsage: 消耗的峰值内存 - ProbeRows: 左孩子进行Hash Probe的行数 - ProbeTime: 探测耗时 - PushDownComputeTime: **构造下推谓词的耗时 ** - PushDownTime: 谓词下推给子节点的耗时 - RowsReturned: 向上层返回的行数 - RowsReturnedRate: 返回吞吐量 |
Broadcast join将小表进行条件过滤后，广播到大表所在的各个节点上，形成一个内存Hash表，然后流式读取大表的数据和这个Hash表中的数据进行join |
| EXCHANGE_NODE | - BytesReceived: 接收的数据大小 - ConvertRowBatchTime: 接收数据转换为rowbatch的耗时 - DataArrivalWaitTime: 等待Sender发送数据的总时间 - DeserializeRowBatchTimer: 反序列化网络数据的耗时 - FirstBatchArrivalWaitTime: 等待第一个batch从Sender获取的时间 - PeakMemoryUsage: 内存消耗峰值 - RowsReturned: 向上层返回的函数，不包过过滤的函数 - RowsReturnedRate: 返回吞吐量 - SendersBlockedTotalTimer(*): DataStreamRecv的队列的内存被打满，Sender端等待的耗时 |
|
| SORT_NODE | - InMemorySortTime: 内存之中的排序耗 - InitialRunsCreated: **初始化排序的趟数，每排序一次都要创建一个 unsorted run ** - SortDataSize: 总的排序数据量 - MergeGetNext: **MergeSort从需要合并的多个sorted run获取下一个batch的耗时 - MergeGetNextBatch: MergeSort提取下一个sorted run的batch的耗时 ** - TotalMergesPerformed: merge的次数 |
|
| AGGREGATION_NODE | - Probe Method: HashTable Linear Probing 探测方法 - BuildTime: 聚合时间 - GetResultsTime: 从各个partition之中获取聚合结果的时间 - HTResize: 分区HashTable大小调整的次数 - HTResizeTime: 分区HashTable大小调整的时间消耗 - HashBuckets: 分区HashTable的bucket数 - HashCollisions: Hash碰撞的次数 - HashFailedProbe: Hash探测失败的次数 - HashFilledBuckets: HashTable填入数据的Buckets数目 - HashProbe: Hash探测的行数 - HashTravelLength: Hash遍历次数 - LargestPartitionPercent: 该值越大，数据倾斜越严重 （aggregated_rows + unaggregated_rows*） 100 / num_input_rows - MaxPartitionLevel: 重分区的最大次数 - NumRepartitions: 重分区的分区数 - PartitionsCreated: 聚合查询拆分成Partition的个数 - PeakMemoryUsage: 内存消耗峰值 - RowsProcessed: 处理的行数，和探测行数一致 - RowsRepartitioned: 重分区的行数 - RowsReturned: ** 向上层节点返回的函数,不包含过滤的行数 - RowsReturnedRate: 返回吞吐量 - SpilledPartitions: 溢出分区数 |
|
| Buffer pool | - AllocTime: 内存分配耗时 - CumulativeAllocationBytes: 累计内存分配的量 - CumulativeAllocations: 累计的内存分配次数 - PeakReservation: 预留内存峰值 - PeakUnpinnedBytes: - PeakUsedReservation: 使用预留内存的峰值 - ReservationLimit: 预留内存最大限制 |
OLAP_SCAN_NODE指标示例&分析
OLAP_SCAN_NODE (id=0):(Active: 1.2ms, % non-child: 0.00%)
- BytesRead: 265.00 B # 从数据文件中读取到的数据量。假设读取到了是10个32位整型，则数据量为 10 * 4B = 40 Bytes。这个数据仅表示数据在内存中全展开的大小，并不代表实际的 IO 大小。
- NumDiskAccess: 1 # 该 ScanNode 节点涉及到的磁盘数量。
- NumScanners: 20 # 该 ScanNode 生成的 Scanner 数量。
- PeakMemoryUsage: 0.00 # 查询时内存使用的峰值，暂未使用
- RowsRead: 7 # 从存储引擎返回到 Scanner 的行数，不包括经 Scanner 过滤的行数。
- RowsReturned: 7 # 从 ScanNode 返回给上层节点的行数。
- RowsReturnedRate: 6.979K /sec # RowsReturned/ActiveTime
- TabletCount : 20 # 该 ScanNode 涉及的 Tablet 数量。
- TotalReadThroughput: 74.70 KB/sec # BytesRead除以该节点运行的总时间（从Open到Close），对于IO受限的查询，接近磁盘的总吞吐量。
- ScannerBatchWaitTime: 426.886us # 用于统计transfer 线程等待scaner 线程返回rowbatch的时间。
- ScannerWorkerWaitTime: 17.745us # 用于统计scanner thread 等待线程池中可用工作线程的时间。
OlapScanner:
- BlockConvertTime: 8.941us # 将向量化Block转换为行结构的 RowBlock 的耗时。向量化 Block 在 V1 中为 VectorizedRowBatch，V2中为 RowBlockV2。
- BlockFetchTime: 468.974us # Rowset Reader 获取 Block 的时间。
- ReaderInitTime: 5.475ms # OlapScanner 初始化 Reader 的时间。V1 中包括组建 MergeHeap 的时间。V2 中包括生成各级 Iterator 并读取第一组Block的时间。
- RowsDelFiltered: 0 # 包括根据 Tablet 中存在的 Delete 信息过滤掉的行数，以及 unique key 模型下对被标记的删除行过滤的行数。
- RowsPushedCondFiltered: 0 # 根据传递下推的谓词过滤掉的条件，比如 Join 计算中从 BuildTable 传递给 ProbeTable 的条件。该数值不准确，因为如果过滤效果差，就不再过滤了。
- ScanTime: 39.24us # 从 ScanNode 返回给上层节点的时间。
- ShowHintsTime_V1: 0ns # V2 中无意义。V1 中读取部分数据来进行 ScanRange 的切分。
SegmentIterator:
- BitmapIndexFilterTimer: 779ns # 利用 bitmap 索引过滤数据的耗时。
- BlockLoadTime: 415.925us # SegmentReader(V1) 或 SegmentIterator(V2) 获取 block 的时间。
- BlockSeekCount: 12 # 读取 Segment 时进行 block seek 的次数。
- BlockSeekTime: 222.556us # 读取 Segment 时进行 block seek 的耗时。
- BlocksLoad: 6 # 读取 Block 的数量
- CachedPagesNum: 30 # 仅 V2 中，当开启 PageCache 后，命中 Cache 的 Page 数量。
- CompressedBytesRead: 0.00 # V1 中，从文件中读取的解压前的数据大小。V2 中，读取到的没有命中 PageCache 的 Page 的压缩前的大小。
- DecompressorTimer: 0ns # 数据解压耗时。
- IOTimer: 0ns # 实际从操作系统读取数据的 IO 时间。
- IndexLoadTime_V1: 0ns # 仅 V1 中，读取 Index Stream 的耗时。
- NumSegmentFiltered: 0 # 在生成 Segment Iterator 时，通过列统计信息和查询条件，完全过滤掉的 Segment 数量。
- NumSegmentTotal: 6 # 查询涉及的所有 Segment 数量。
- RawRowsRead: 7 # 存储引擎中读取的原始行数。详情见下文。
- RowsBitmapIndexFiltered: 0 # 仅 V2 中，通过 Bitmap 索引过滤掉的行数。
- RowsBloomFilterFiltered: 0 # 仅 V2 中，通过 BloomFilter 索引过滤掉的行数。
- RowsKeyRangeFiltered: 0 # 仅 V2 中，通过 SortkeyIndex 索引过滤掉的行数。
- RowsStatsFiltered: 0 # V2 中，通过 ZoneMap 索引过滤掉的行数，包含删除条件。V1 中还包含通过 BloomFilter 过滤掉的行数。
- RowsConditionsFiltered: 0 # 仅 V2 中，通过各种列索引过滤掉的行数。
- RowsVectorPredFiltered: 0 # 通过向量化条件过滤操作过滤掉的行数。
- TotalPagesNum: 30 # 仅 V2 中，读取的总 Page 数量。
- UncompressedBytesRead: 0.00 # V1 中为读取的数据文件解压后的大小（如果文件无需解压，则直接统计文件大小）。V2 中，仅统计未命中 PageCache 的 Page 解压后的大小（如果Page无需解压，直接统计Page大小）
- VectorPredEvalTime: 0ns # 向量化条件过滤操作的耗时。
- ShortPredEvalTime: 0ns # 短路谓词过滤操作的耗时。
- PredColumnReadTime: 0ns # 谓词列读取的耗时。
- LazyReadTime: 0ns # 非谓词列读取的耗时。
- OutputColumnTime: 0ns # 物化列的耗时。
