查询执行的统计
- FE:Frontend,Doris 的前端节点。负责元数据管理和请求接入。
- BE:Backend,Doris 的后端节点。负责查询执行和数据存储。
- Fragment:FE会将具体的SQL语句的执行转化为对应的Fragment并下发到BE进行执行。BE上执行对应Fragment,并将结果汇聚返回给FE。
FE将查询计划拆分成为Fragment下发到BE进行任务执行。BE在执行Fragment时记录了运行状态时的统计值,并将Fragment执行的统计信息输出到日志之中。 FE也可以通过开关将各个Fragment记录的这些统计值进行搜集,并在FE的Web页面上打印结果。
通过Mysql命令,将FE上的Report的开关打开
之后执行对应的SQL语句之后,在FE的Web页面就可以看到对应SQL语句执行的Report信息:
这里会列出最新执行完成的100条语句,我们可以通过Profile查看详细的统计信息。
这里列出了Fragment的ID;hostname
指的是执行Fragment的BE节点;Active:10s270ms
表示该节点的执行总时间;non-child: 0.14%
表示执行节点自身的执行时间(不包含子节点的执行时间)占总时间的百分比;
PeakMemoryUsage
表示EXCHANGE_NODE
内存使用的峰值;RowsReturned
表示EXCHANGE_NODE
结果返回的行数;RowsReturnedRate
\=RowsReturned
/ActiveTime
;这三个统计信息在其他NODE
中的含义相同。
后续依次打印子节点的统计信息,这里可以通过缩进区分节点之间的父子关系。
BE端收集的统计信息较多,下面列出了各个参数的对应含义:
Fragment
- AverageThreadTokens: 执行Fragment使用线程数目,不包含线程池的使用情况
- Buffer Pool PeakReservation: Buffer Pool使用的内存的峰值
- MemoryLimit: 查询时的内存限制
- PeakMemoryUsage: 整个Instance在查询时内存使用的峰值
- RowsProduced: 处理列的行数
BlockMgr
- BlocksCreated: BlockMgr创建的Blocks数目
- BlocksRecycled: 重用的Blocks数目
- BytesWritten: 总的落盘写数据量
- MaxBlockSize: 单个Block的大小
- TotalReadBlockTime: 读Block的总耗时
DataStreamSender
- BytesSent: 发送的总数据量 = 接受者 * 发送数据量
- IgnoreRows: 过滤的行数
- OverallThroughput: 总的吞吐量 = BytesSent / 时间
- SerializeBatchTime: 发送数据序列化消耗的时间
EXCHANGE_NODE
- BytesReceived: 通过网络接收的数据量大小
- DataArrivalWaitTime: 等待Sender发送数据的总时间
- FirstBatchArrivalWaitTime: 等待第一个batch从Sender获取的时间
- DeserializeRowBatchTimer: 反序列化网络数据的耗时
- SendersBlockedTotalTimer(*): DataStreamRecv的队列的内存被打满,Sender端等待的耗时
- ConvertRowBatchTime: 接收数据转为RowBatch的耗时
- RowsReturned: 接收行的数目
- RowsReturnedRate: 接收行的速率
SORT_NODE
- InMemorySortTime: 内存之中的排序耗时
- InitialRunsCreated: 初始化排序的趟数(如果内存排序的话,该数为1)
- SortDataSize: 总的排序数据量
- MergeGetNext: MergeSort从多个sort_run获取下一个batch的耗时 (仅在落盘时计时)
- MergeGetNextBatch: MergeSort提取下一个sort_run的batch的耗时 (仅在落盘时计时)
- TotalMergesPerformed: 进行外排merge的次数
- PartitionsCreated: 聚合查询拆分成Partition的个数
- GetResultsTime: 从各个partition之中获取聚合结果的时间
- HTResizeTime: HashTable进行resize消耗的时间
- HTResize: HashTable进行resize的次数
- HashBuckets: HashTable中Buckets的个数
- HashBucketsWithDuplicate: HashTable有DuplicateNode的Buckets的个数
- HashCollisions: HashTable产生哈希冲突的次数
- HashDuplicateNodes: HashTable出现Buckets相同DuplicateNode的个数
- HashFailedProbe: HashTable Probe操作失败的次数
- HashFilledBuckets: HashTable填入数据的Buckets数目
- HashProbe: HashTable查询的次数
- HashTravelLength: HashTable查询时移动的步数
HASH_JOIN_NODE
- ExecOption: 对右孩子构造HashTable的方式(同步or异步),Join中右孩子可能是表或子查询,左孩子同理
- BuildBuckets: HashTable中Buckets的个数
- BuildRows: HashTable的行数
- BuildTime: 构造HashTable的耗时
- LoadFactor: HashTable的负载因子(即非空Buckets的数量)
- ProbeRows: 遍历左孩子进行Hash Probe的行数
- ProbeTime: 遍历左孩子进行Hash Probe的耗时,不包括对左孩子RowBatch调用GetNext的耗时
- PushDownTime: 谓词下推的总耗时,Join时对满足要求的右孩子,转为左孩子的in查询
CROSS_JOIN_NODE
- ExecOption: 对右孩子构造RowBatchList的方式(同步or异步)
- BuildRows: RowBatchList的行数(即右孩子的行数)
- BuildTime: 构造RowBatchList的耗时
- LeftChildRows: 左孩子的行数
- LeftChildTime: 遍历左孩子,和右孩子求笛卡尔积的耗时,不包括对左孩子RowBatch调用GetNext的耗时
UNION_NODE
- MaterializeExprsEvaluateTime: Union两端字段类型不一致时,类型转换表达式计算及物化结果的耗时
ANALYTIC_EVAL_NODE
- EvaluationTime: 分析函数(窗口函数)计算总耗时
- GetNewBlockTime: 初始化时申请一个新的Block的耗时,Block用来缓存Rows窗口或整个分区,用于分析函数计算
- PinTime: 后续申请新的Block或将写入磁盘的Block重新读取回内存的耗时
- UnpinTime: 对暂不需要使用的Block或当前操作符内存压力大时,将Block的数据刷入磁盘的耗时
OLAP_SCAN_NODE
查询中的部分或全部谓词条件会推送给 OLAP_SCAN_NODE
。这些谓词条件中一部分会继续下推给存储引擎,以便利用存储引擎的索引进行数据过滤。另一部分会保留在 OLAP_SCAN_NODE
中,用于过滤从存储引擎中返回的数据。
OLAP_SCAN_NODE
节点的 Profile 通常用于分析数据扫描的效率,依据调用关系分为 OLAP_SCAN_NODE
、OlapScanner
、SegmentIterator
三层。
一个典型的 OLAP_SCAN_NODE
节点的 Profile 如下。部分指标会因存储格式的不同(V1 或 V2)而有不同含义。
通过 Profile 中数据行数相关指标可以推断谓词条件下推和索引使用情况。以下仅针对 Segment V2 格式数据读取流程中的 Profile 进行说明。Segment V1 格式中,这些指标的含义略有不同。
- 当读取一个 V2 格式的 Segment 时,若查询存在 key_ranges(前缀key组成的查询范围),首先通过 SortkeyIndex 索引过滤数据,过滤的行数记录在
RowsKeyRangeFiltered
。 - 之后,对查询条件中含有 bitmap 索引的列,使用 Bitmap 索引进行精确过滤,过滤的行数记录在
RowsBitmapIndexFiltered
。 - 之后,按查询条件中的等值(eq,in,is)条件,使用BloomFilter索引过滤数据,记录在
RowsBloomFilterFiltered
。RowsBloomFilterFiltered
的值是 Segment 的总行数(而不是Bitmap索引过滤后的行数)和经过 BloomFilter 过滤后剩余行数的差值,因此 BloomFilter 过滤的数据可能会和 Bitmap 过滤的数据有重叠。 - 之后,按查询条件和删除条件,使用 ZoneMap 索引过滤数据,记录在
RowsStatsFiltered
。 RowsConditionsFiltered
是各种索引过滤的行数,包含了RowsBloomFilterFiltered
和RowsStatsFiltered
的值。- 至此 Init 阶段完成,Next 阶段删除条件过滤的行数,记录在
RowsDelFiltered
。因此删除条件实际过滤的行数,分别记录在RowsStatsFiltered
和RowsDelFiltered
中。 RawRowsRead
是经过上述过滤后,最终需要读取的行数。- 是最终返回给 Scanner 的行数。
RowsRead
通常小于RawRowsRead
,是因为从存储引擎返回到 Scanner,可能会经过一次数据聚合。如果RawRowsRead
和RowsRead
差距较大,则说明大量的行被聚合,而聚合可能比较耗时。 RowsReturned
是 ScanNode 最终返回给上层节点的行数。RowsReturned
通常也会小于RowsRead
。因为在 Scanner 上会有一些没有下推给存储引擎的谓词条件,会进行一次过滤。如果RowsRead
和RowsReturned
差距较大,则说明很多行在 Scanner 中进行了过滤。这说明很多选择度高的谓词条件并没有推送给存储引擎。而在 Scanner 中的过滤效率会比在存储引擎中过滤效率差。
OlapScanner
下的很多指标,如IOTimer
,BlockFetchTime
等都是所有 Scanner 线程指标的累加,因此数值可能会比较大。并且因为 Scanner 线程是异步读取数据的,所以这些累加指标只能反映 Scanner 累加的工作时间,并不直接代表 ScanNode 的耗时。ScanNode 在整个查询计划中的耗时占比为Active
字段记录的值。有时会出现比如IOTimer
有几十秒,而Active
实际只有几秒钟。这种情况通常因为:IOTimer
为多个 Scanner 的累加时间,而 Scanner 数量较多。- 上层节点比较耗时。比如上层节点耗时 100秒,而底层 ScanNode 只需 10秒。则反映在
Active
的字段可能只有几毫秒。因为在上层处理数据的同时,ScanNode 已经异步的进行了数据扫描并准备好了数据。当上层节点从 ScanNode 获取数据时,可以获取到已经准备好的数据,因此 Active 时间很短。
NumScanners
表示 Scanner 提交到线程池的Task个数,由RuntimeState
中的线程池调度,doris_scanner_thread_pool_thread_num
和doris_scanner_thread_pool_queue_size
两个参数分别控制线程池的大小和队列长度。线程数过多或过少都会影响查询效率。同时可以用一些汇总指标除以线程数来大致的估算每个线程的耗时。TabletCount
表示需要扫描的 tablet 数量。数量过多可能意味着需要大量的随机读取和数据合并操作。UncompressedBytesRead
间接反映了读取的数据量。如果该数值较大,说明可能有大量的 IO 操作。CachedPagesNum
和TotalPagesNum
可以查看命中 PageCache 的情况。命中率越高,说明 IO 和解压操作耗时越少。
Buffer pool
- AllocTime: 内存分配耗时
- CumulativeAllocationBytes: 累计内存分配的量
- CumulativeAllocations: 累计的内存分配次数
- PeakReservation: Reservation的峰值
- PeakUnpinnedBytes: unpin的内存数据量
- PeakUsedReservation: Reservation的内存使用量