例如下instance,Active time 5.733us,但是VScanner的InitConnectorTime耗时11s,并不能直观的发现query的性能瓶颈在哪里
VNewJdbcScanNode(
imp_db
.v_imp_base_target
) (id=1189):(Active: 5.733us, % non-child: 0.00%)
...
VScanner:
-InitConnectorTime: 11s79ms
下边是Fragment2完整的query profile
Fragment 2:
Instance 1d9c963d29b44aa3-8833e73c53f357bb (host=TNetworkAddress(hostname:192.168.30.136, port:9060)):
VDataStreamSender (dst_id=1199, dst_fragments=[{"1d9c963d29b44aa3-8833e73c53f357bc", "1d9c963d29b44aa3-8833e73c53f357bd", "1d9c963d29b44aa3-8833e73c53f357bf"}]):(Active: 220.747us, % non-child: 0.00%)
- BlocksSent: 5
- BrpcSendTime: 0ns
- BrpcSendTime.Wait: 0ns
- BytesSent: 11.72 KB
- CompressTime: 47.966us
- IgnoreRows: 0
- LocalBytesSent: 17.17 KB
- LocalSendTime: 36.182us
- LocalSentRows: 214
- MemoryUsage:
- PeakMemoryUsage: 19.02 KB
- OverallThroughput: 51.86849117279053 MB/sec
- RpcAvgTime: 4.921us
- RpcCount: 4
- RpcMaxTime: 19.685us
- RpcMinTime: 19.685us
- RpcSumTime: 19.685us
- SerializeBatchTime: 65.197us
- SplitBlockDistributeByChannelTime: 0ns
- SplitBlockHashComputeTime: 0ns
- UncompressedRowBatchSize: 51.70 KB
VNewJdbcScanNode(`imp_db`.`v_imp_base_target`) (id=1189):(Active: 5.733us, % non-child: 0.00%)
- RuntimeFilters: :
- UseSpecificThreadToken: False
- AcquireRuntimeFilterTime: 317ns
- AllocateResourceTime: 31.686ms
- GetNextTime: 6.119us
- MaxScannerThreadNum: 1
- MemoryUsage:
- PeakMemoryUsage: 0.00
- NumScanners: 1
- OpenTime: 0ns
- ProjectionTime: 0ns
- RowsReturned: 214
- RowsReturnedRate: 37.327751M /sec
- ScanByteRead: 140.00 KB
- ScanRowsRead: 214
- ScannerWorkerWaitTime: 17.869us
- TotalReadThroughput: 0
VScanner:
- JdbcDriverClass: com.mysql.jdbc.Driver
- JdbcDriverUrl: mysql-connector-java-8.0.30.jar
- JdbcUrl: jdbc:mysql://192.168.30.145:3306/imp_db?yearIsDateType=false&tinyInt1isBit=false&useUnicode=true&rewriteBatchedStatements=true&characterEncoding=utf-8
- QuerySql: SELECT `room_id`, `room_name`, `item_code`, `item_name`, `target_code` FROM `imp_db`.`v_imp_base_target` WHERE (`room_id` = 755386394620198912) AND (`item_code` IN ('401', '402', '403', '404', '211', '212', '201', '202', '221', '222'))
- PerScannerRunningTime: [56.064ms, ]
- PerScannerRowsRead: [214, ]
- PerScannerWaitTime: [17.869us, ]
- CheckTypeTime: 54.81us
- ConnectorCloseTime: 0ns
- ExecteReadTime: 57.159ms
- GetDataTime: 55.987ms
- CallJniNextTime: 0ns
- ConvertBatchTime: 0ns
- InitConnectorTime: 11s79ms
- LoadJarTime: 5.137ms
- MemoryUsage:
- FreeBlocks: 128.00 KB
- QueuedBlocks: 0.00
- NewlyCreateFreeBlocksNum: 2
- ScannerBatchWaitTime: 0ns
- ScannerConvertBlockTime: 0ns
- ScannerCpuTime: 617.904ms
- ScannerCtxSchedCount: 3
- ScannerCtxSchedTime: 6.247us
- ScannerFilterTime: 65.469us
- ScannerGetBlockTime: 55.997ms
- ScannerPrefilterTime: 0ns
- ScannerSchedCount: 1
PipelineContext:(Active: 11s424ms, % non-child: 0.00%)
- PrepareTime: 240.524us
- StartTime: 1.898us
Pipeline (pipeline id=0):
PipelineTask (index=0):(Active: 66.222ms, % non-child: 0.00%)
- Sink: ExchangeSinkOperator(dst_id=1199)
- OperatorIds(source2root): [ScanOperator(node_id=1189)]
- CoreChangeTimes: 0
- ExecuteTime: 31.937ms
- CloseTime: 2.550ms
- FinalizeTime: 137ns
- GetBlockTime: 8.837us
- OpenTime: 31.706ms
- PrepareTime: 15.421us
- SinkTime: 193.607us
- GetBlockCounter: 2
- NumBlockedBySinkTimes: 0
- NumBlockedBySrcTimes: 1
- NumBlockedTimes: 2
- NumScheduleTimes: 4
- NumYieldTimes: 0
- Task1BeginExecuteTime: 11s420ms
- Task2EosTime: 11s420ms
- Task3SrcPendingFinishOverTime: 11s420ms
- Task4DstPendingFinishOverTime: 11s421ms
- Task5TotalTime: 11s424ms
- Task6ClosePipelineTime: 11s424ms
- TaskCpuTime: 738.985us
- WaitBfTime: 0ns
- WaitSinkTime: 0ns
- WaitSourceTime: 11s388ms
- WaitWorkerTime: 346.2us