记录一下 StarRocks 点查的 Profile Metrics

背景

Starrocks 3.5
补充两个点查的 profile
一个是没有开启点查的情况，也就是SET enable_short_circuit = false;
一个是开启点查的情况，也就是SET enable_short_circuit = true;
其中建表语句如下：

CREATE TABLE `ac_account` (`id` bigint(20) NOT NULL COMMENT "",`date_created` datetime NOT NULL DEFAULT "1970-01-01 00:00:00" COMMENT "",`date_updated` datetime NOT NULL DEFAULT "1970-01-01 00:00:00" COMMENT "修改时间",) ENGINE=OLAP
PRIMARY KEY(`id`, `date_created`)
COMMENT ""
PARTITION BY date_trunc('day', date_created)
DISTRIBUTED BY HASH(`id`) BUCKETS 2
PROPERTIES (
"compression" = "ZSTD",
"enable_persistent_index" = "true",
"fast_schema_evolution" = "true",
"replicated_storage" = "true",
"replication_num" = "3"
); |

执行的命令如下：

select * from ac_account where id=8469586 and  date_created ='2018-10-01 00:13:02'

差别与时间

指标的说明参考：Query Profile Metrics
具体的BE端的流程参考StarRocks Pipeline 执行框架

这两个之间的的profile如下

Query:Summary:- Query ID: c37b81df-796e-11f0-89a6-00163e164034- Start Time: 2025-08-15 08:28:28- End Time: 2025-08-15 08:28:28- Total: 6ms- Query Type: Query- Query State: Finished- StarRocks Version: 3.3.5-6d81f75- User: root- Default Db: ams- Sql Statement: select * from ac_account where id=8469586 and  date_created ='2018-10-01 00:13:02'- Variables: parallel_fragment_exec_instance_num=8,max_parallel_scan_instance_num=-1,pipeline_dop=0,enable_adaptive_sink_dop=true,enable_runtime_adaptive_dop=false,runtime_profile_report_interval=10,resource_group=default_wg- NonDefaultSessionVariables: {"big_query_profile_threshold":{"defaultValue":"0s","actualValue":"5ms"},"parallel_fragment_exec_instance_num":{"defaultValue":1,"actualValue":8},"enable_adaptive_sink_dop":{"defaultValue":false,"actualValue":true},"enable_short_circuit":{"defaultValue":false,"actualValue":true},"enable_profile":{"defaultValue":false,"actualValue":true}}- Collect Profile Time: 0- IsProfileAsync: truePlanner:- -- Parser[1] 0- -- Total[1] 2ms-     -- Analyzer[1] 0-         -- Lock[1] 0-         -- AnalyzeDatabase[1] 0-         -- AnalyzeTemporaryTable[1] 0-         -- AnalyzeTable[1] 0-     -- Transformer[1] 0-     -- Optimizer[1] 1ms-         -- MVPreprocess[1] 0-             -- MVChooseCandidates[1] 0-             -- MVGenerateMvPlan[1] 0-             -- MVValidateMv[1] 0-             -- MVProcessWithView[1] 0-         -- MVTextRewrite[1] 0-         -- RuleBaseOptimize[1] 1ms-     -- ExecPlanBuild[1] 0- -- Pending[1] 0- -- DeploySerializeTime[1] 0Reason:Short Circuit Executor:TNetworkAddress(hostname:xxx.xxx.xxx.251, port:8060):(Active: 857.455us[857455ns], % non-child: 12.85%)- CloseTime: 7.243us- ExecuteTime: 764.279us- PrepareTime: 81.675usOLAP_SCAN_NODE (id=0):(Active: 747.286us[747286ns], % non-child: 87.15%)- PeakMemoryUsage: 0.000 B- RowsReturned: 1- RowsReturnedRate: 1.338K (1338) /sec

Query:Summary:- Query ID: 7f3db82a-796e-11f0-89a6-00163e164034- Start Time: 2025-08-15 08:26:33- End Time: 2025-08-15 08:26:33- Total: 14ms- Query Type: Query- Query State: Finished- StarRocks Version: 3.3.5-6d81f75- User: root- Default Db: ams- Sql Statement: select * from ac_account where id=8469586 and  date_created ='2018-10-01 00:13:02'- Variables: parallel_fragment_exec_instance_num=8,max_parallel_scan_instance_num=-1,pipeline_dop=0,enable_adaptive_sink_dop=true,enable_runtime_adaptive_dop=false,runtime_profile_report_interval=10,resource_group=default_wg- NonDefaultSessionVariables: {"big_query_profile_threshold":{"defaultValue":"0s","actualValue":"5ms"},"parallel_fragment_exec_instance_num":{"defaultValue":1,"actualValue":8},"enable_adaptive_sink_dop":{"defaultValue":false,"actualValue":true},"enable_profile":{"defaultValue":false,"actualValue":true}}- Collect Profile Time: 2ms- IsProfileAsync: truePlanner:- -- Parser[1] 0- -- Total[1] 2ms-     -- Analyzer[1] 0-         -- Lock[1] 0-         -- AnalyzeDatabase[1] 0-         -- AnalyzeTemporaryTable[1] 0-         -- AnalyzeTable[1] 0-     -- Transformer[1] 0-     -- Optimizer[1] 1ms-         -- MVPreprocess[1] 0-             -- MVChooseCandidates[1] 0-             -- MVGenerateMvPlan[1] 0-             -- MVValidateMv[1] 0-             -- MVProcessWithView[1] 0-         -- MVTextRewrite[1] 0-         -- RuleBaseOptimize[1] 1ms-         -- CostBaseOptimize[1] 0-         -- PhysicalRewrite[1] 0-         -- PlanValidate[1] 0-             -- InputDependenciesChecker[1] 0-             -- TypeChecker[1] 0-             -- CTEUniqueChecker[1] 0-             -- ColumnReuseChecker[1] 0-     -- ExecPlanBuild[1] 0- -- Pending[1] 0- -- Prepare[1] 0- -- Deploy[1] 1ms-     -- DeployLockInternalTime[1] 1ms-         -- DeploySerializeConcurrencyTime[1] 0-         -- DeployStageByStageTime[3] 0-         -- DeployWaitTime[3] 0-             -- DeployAsyncSendTime[1] 0- DeployDataSize: 14654Reason:Execution:- Topology: {"rootId":0,"nodes":[{"id":0,"name":"OLAP_SCAN","properties":{"sinkIds":[],"displayMem":false},"children":[]}]}- FrontendProfileMergeTime: 1.041ms- QueryAllocatedMemoryUsage: 15.679 MB- QueryCumulativeCpuTime: 1.715ms- QueryCumulativeNetworkTime: 0ns- QueryCumulativeOperatorTime: 5.447ms- QueryCumulativeScanTime: 4.506ms- QueryDeallocatedMemoryUsage: 14.438 MB- QueryExecutionWallTime: 6.773ms- QueryPeakMemoryUsagePerNode: 8.513 MB- QueryPeakScheduleTime: 43.383us- QuerySpillBytes: 0.000 B- QuerySumMemoryUsage: 8.513 MB- ResultDeliverTime: 0nsFragment 0:- BackendAddresses: xxx.xxx.xxx.252:9060- InstanceIds: 7f3db82a-796e-11f0-89a6-00163e164035- BackendNum: 1- BackendProfileMergeTime: 897.164us- FragmentInstancePrepareTime: 315.315us- prepare-fragment-ctx: 731ns- prepare-pipeline-driver: 100.410us- prepare-pipeline-driver-factory: 127.601us- prepare-query-ctx: 2.816us- prepare-runtime-state: 81.784us- InitialProcessDriverCount: 0- InitialProcessMem: 2.773 GB- InstanceAllocatedMemoryUsage: 15.679 MB- InstanceDeallocatedMemoryUsage: 14.438 MB- InstanceNum: 1- InstancePeakMemoryUsage: 8.500 MB- JITCounter: 0- JITTotalCostTime: 0ns- QueryMemoryLimit: -1.000 BPipeline (id=1):- isGroupExecution: false- ActiveTime: 595.473us- BlockByInputEmpty: 2- BlockByOutputFull: 0- BlockByPrecondition: 0- DegreeOfParallelism: 1- DriverPrepareTime: 61.877us- DriverTotalTime: 4.997ms- OverheadTime: 0ns- PeakDriverQueueSize: 0- PendingTime: 4.358ms- InputEmptyTime: 4.360ms- FirstInputEmptyTime: 80.913us- FollowupInputEmptyTime: 4.280ms- OutputFullTime: 0ns- PendingFinishTime: 0ns- PreconditionBlockTime: 0ns- ScheduleCount: 3- ScheduleTime: 43.383us- TotalDegreeOfParallelism: 1- YieldByLocalWait: 0- YieldByPreempt: 0- YieldByTimeLimit: 0RESULT_SINK (plan_node_id=-1):CommonMetrics:- IsFinalSink- CloseTime: 20.519us- OperatorAllocatedMemoryUsage: 6.883 KB- OperatorDeallocatedMemoryUsage: 7.578 KB- OperatorPeakMemoryUsage: 0.000 B- OperatorTotalTime: 60.605us- PrepareTime: 8.947us- PullChunkNum: 0- PullRowNum: 0- PullTotalTime: 0ns- PushChunkNum: 1- PushRowNum: 1- PushTotalTime: 39.926us- SetFinishedTime: 40ns- SetFinishingTime: 120nsUniqueMetrics:result sink:- AppendChunkTime: 14.727us- ResultRendTime: 24.487us- TupleConvertTime: 6.703us- NumSentRows: 1CHUNK_ACCUMULATE (plan_node_id=-1):CommonMetrics:- IsSubordinate- CloseTime: 100ns- OperatorTotalTime: 1.643us- PrepareTime: 6.552us- PullChunkNum: 1- PullRowNum: 1- PullTotalTime: 221ns- PushChunkNum: 1- PushRowNum: 1- PushTotalTime: 1.262us- SetFinishedTime: 30ns- SetFinishingTime: 30nsUniqueMetrics:CHUNK_ACCUMULATE (plan_node_id=0):CommonMetrics:- IsSubordinate- CloseTime: 260ns- OperatorTotalTime: 2.535us- PrepareTime: 13.475us- PullChunkNum: 1- PullRowNum: 1- PullTotalTime: 181ns- PushChunkNum: 1- PushRowNum: 1- PushTotalTime: 1.894us- SetFinishedTime: 110ns- SetFinishingTime: 90nsUniqueMetrics:OLAP_SCAN (plan_node_id=0):CommonMetrics:- CloseTime: 503.420us- JoinRuntimeFilterEvaluate: 0- JoinRuntimeFilterHashTime: 0ns- JoinRuntimeFilterInputRows: 0- JoinRuntimeFilterOutputRows: 0- JoinRuntimeFilterTime: 0ns- OperatorAllocatedMemoryUsage: 15.419 MB- OperatorDeallocatedMemoryUsage: 13.469 MB- OperatorPeakMemoryUsage: 8.247 MB- OperatorTotalTime: 801.854us- PrepareTime: 14.758us- PullChunkNum: 1- PullRowNum: 1- PullTotalTime: 297.772us- PushChunkNum: 0- PushRowNum: 0- PushTotalTime: 0ns- RuntimeBloomFilterNum: 0- RuntimeInFilterNum: 0- SetFinishedTime: 101ns- SetFinishingTime: 561nsUniqueMetrics:- MorselQueueType: fixed_morsel_queue- Predicates: 1: id = 8469586, 2: date_created = '2018-10-01 00:13:02'- Rollup: ac_account- SharedScan: False- Table: ac_account- AccessPathHits: 0- AccessPathUnhits: 0- BytesRead: 689.000 B- CachedPagesNum: 0- ChunkBufferCapacity: 64- CompressedBytesRead: 332.227 KB- DefaultChunkBufferCapacity: 64- IOTaskExecTime: 4.493ms- CreateSegmentIter: 59.722us- GetDelVec: 1.392us- GetDeltaColumnGroup: 3.567us- GetRowsets: 380ns- IOTime: 192.835us- LateMaterialize: 3.237ms- ReadPKIndex: 0ns- SegmentInit: 519.510us- BitmapIndexFilter: 0ns- BitmapIndexFilterRows: 0- BitmapIndexIteratorInit: 13.225us- BloomFilterFilter: 261ns- BloomFilterFilterRows: 0- ColumnIteratorInit: 90.231us- GinFilter: 0ns- GinFilterRows: 0- RemainingRowsAfterShortKeyFilter: 1- SegmentRuntimeZoneMapFilterRows: 0- SegmentZoneMapFilterRows: 12- ShortKeyFilter: 221.909us- ShortKeyFilterRows: 33.069K (33069)- ShortKeyRangeNumber: 0- ZoneMapIndexFilterRows: 0- ZoneMapIndexFiter: 10.420us- SegmentRead: 10.108us- BlockFetch: 11.472us- BlockFetchCount: 1- BlockSeek: 203.304us- BlockSeekCount: 1- ChunkCopy: 30ns- DecompressT: 1.055ms- DelVecFilterRows: 0- PredFilter: 810ns- PredFilterRows: 0- RowsetsReadCount: 3- SegmentsReadCount: 2- TotalColumnsDataPageCount: 168- IOTaskWaitTime: 12.934us- MorselsCount: 1- PeakChunkBufferMemoryUsage: 892.337 KB- PeakChunkBufferSize: 2- PeakIOTasks: 1- PeakScanTaskQueueSize: 0- PrepareChunkSourceTime: 272.224us- PushdownAccessPaths: 0- PushdownPredicates: 2- RawRowsRead: 1- ReadPagesNum: 55- RowsRead: 1- ScanTime: 4.506ms- SubmitTaskCount: 1- SubmitTaskTime: 3.136us- TabletCount: 1- UncompressedBytesRead: 497.217 KBPipeline (id=0):- isGroupExecution: false- ActiveTime: 74.642us- BlockByInputEmpty: 0- BlockByOutputFull: 0- BlockByPrecondition: 0- DegreeOfParallelism: 1- DriverPrepareTime: 36.199us- DriverTotalTime: 94.930us- OverheadTime: 252ns- PeakDriverQueueSize: 0- PendingTime: 0ns- InputEmptyTime: 0ns- FirstInputEmptyTime: 0ns- FollowupInputEmptyTime: 0ns- OutputFullTime: 0ns- PendingFinishTime: 0ns- PreconditionBlockTime: 0ns- ScheduleCount: 1- ScheduleTime: 20.288us- TotalDegreeOfParallelism: 1- YieldByLocalWait: 0- YieldByPreempt: 0- YieldByTimeLimit: 0NOOP_SINK (plan_node_id=0):CommonMetrics:- IsSubordinate- CloseTime: 341ns- OperatorTotalTime: 440ns- PrepareTime: 6.772us- PullChunkNum: 0- PullRowNum: 0- PullTotalTime: 0ns- PushChunkNum: 0- PushRowNum: 0- PushTotalTime: 0ns- SetFinishedTime: 30ns- SetFinishingTime: 69nsUniqueMetrics:OLAP_SCAN_PREPARE (plan_node_id=0):CommonMetrics:- IsSubordinate- CloseTime: 3.225us- OperatorTotalTime: 73.950us- PrepareTime: 13.447us- PullChunkNum: 0- PullRowNum: 0- PullTotalTime: 70.584us- PushChunkNum: 0- PushRowNum: 0- PushTotalTime: 0ns- RuntimeBloomFilterNum: 0- RuntimeInFilterNum: 0- SetFinishedTime: 40ns- SetFinishingTime: 101nsUniqueMetrics:- CaptureTabletRowsetsTime: 3.626us