From e656f65d7c0c4758bc7bfb31bc49914c13890a8e Mon Sep 17 00:00:00 2001 From: yihaoDeng Date: Mon, 9 Sep 2024 21:28:42 +0800 Subject: [PATCH] opt transport --- log | 205 +++++++++++++++++++++++++ qid | 216 +++++++++++++++++++++++++++ source/libs/transport/src/transCli.c | 17 ++- source/libs/transport/src/transSvr.c | 3 + sql0 | 140 +++++++++++++++++ sql1 | 141 +++++++++++++++++ 6 files changed, 715 insertions(+), 7 deletions(-) create mode 100644 log create mode 100644 qid create mode 100644 sql0 create mode 100644 sql1 diff --git a/log b/log new file mode 100644 index 0000000000..de7cd0bfa7 --- /dev/null +++ b/log @@ -0,0 +1,205 @@ +10060:09/09 19:07:23.425713 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +10062:09/09 19:07:23.425770 00161875 C RPC DND-S conn 0x7f73780418e0 heartbeat received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:184, cost:161us, seqNum:9, qid:15, gtid:0xadc8d77787a1000d:0x70b71d6778700015 +10063:09/09 19:07:23.425776 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d77787a1000d:0x70b71d6778700015 +10098:09/09 19:07:23.426118 00161914 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d77787a1000d:0x70b71d6778700015 +10105:09/09 19:07:23.426263 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +10106:09/09 19:07:23.426291 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +10107:09/09 19:07:23.426299 00161875 C RPC DND-S conn 0x7f73780418e0 heartbeat-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:855, seqNum:9, qid:15, gtid:0xadc8d77787a1000d:0x70b71d6778700015 +10108:09/09 19:07:23.426303 00161875 C RPC conn 0x7f73780418e0 ref count:2 +10109:09/09 19:07:23.426358 00161875 C RPC DND-S conn 0x7f73780418e0 send data +10110:09/09 19:07:23.426383 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:9, qid:15, gtid:0xadc8d77787a1000d:0x70b71d6778700015 +10112:09/09 19:07:23.426393 00161875 C RPC conn 0x7f73780418e0 ref count:1 +10285:09/09 19:07:24.604388 00161881 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0x0:0x70b71d6775200005 +10291:09/09 19:07:24.604484 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +10292:09/09 19:07:24.604492 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +10293:09/09 19:07:24.604497 00161875 C RPC DND-S conn 0x7f73780418e0 query-heartbeat-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:116, seqNum:1, qid:4, gtid:0x0:0x70b71d6775200005 +10294:09/09 19:07:24.604502 00161875 C RPC conn 0x7f73780418e0 ref count:2 +10295:09/09 19:07:24.604552 00161875 C RPC DND-S conn 0x7f73780418e0 send data +10296:09/09 19:07:24.604575 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:1, qid:4, gtid:0x0:0x70b71d6775200005 +10298:09/09 19:07:24.604585 00161875 C RPC conn 0x7f73780418e0 ref count:1 +10463:09/09 19:07:24.866345 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +10465:09/09 19:07:24.866385 00161875 C RPC DND-S conn 0x7f73780418e0 vnode-batch-meta received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:90, cost:107us, seqNum:10, qid:0, gtid:0xadc8d7778d40000e:0x70b71d6778d00017 +10466:09/09 19:07:24.866389 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d7778d40000e:0x70b71d6778d00017 +10542:09/09 19:07:24.867015 00162315 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d7778d40000e:0x70b71d6778d00017 +10549:09/09 19:07:24.867083 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +10550:09/09 19:07:24.867088 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +10551:09/09 19:07:24.867093 00161875 C RPC DND-S conn 0x7f73780418e0 vnode-batch-meta is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:329, seqNum:10, qid:0, gtid:0xadc8d7778d40000e:0x70b71d6778d00017 +10552:09/09 19:07:24.867097 00161875 C RPC conn 0x7f73780418e0 ref count:2 +10553:09/09 19:07:24.867137 00161875 C RPC DND-S conn 0x7f73780418e0 send data +10554:09/09 19:07:24.867144 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:10, qid:0, gtid:0xadc8d7778d40000e:0x70b71d6778d00017 +10556:09/09 19:07:24.867153 00161875 C RPC conn 0x7f73780418e0 ref count:1 +10601:09/09 19:07:24.869034 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +10603:09/09 19:07:24.869064 00161875 C RPC DND-S conn 0x7f73780418e0 query-heartbeat received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:41, cost:93us, seqNum:11, qid:16, gtid:0x0:0x70b71d6778d00019 +10604:09/09 19:07:24.869067 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0x0:0x70b71d6778d00019 +10626:09/09 19:07:24.869574 00162315 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback +10635:09/09 19:07:24.869602 00162315 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0x0:0x70b71d6778d00019 +10643:09/09 19:07:24.869659 00161875 C RPC DND-S conn 0x7f73780418e0 register brokenlink callback +10644:09/09 19:07:24.869661 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback, qid:16 +10645:09/09 19:07:24.869664 00161875 C RPC conn 0x7f73780418e0 register brokenlink callback succ +10648:09/09 19:07:24.869670 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +10649:09/09 19:07:24.869672 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +10650:09/09 19:07:24.869674 00161875 C RPC DND-S conn 0x7f73780418e0 query-heartbeat-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:116, seqNum:11, qid:16, gtid:0x0:0x70b71d6778d00019 +10651:09/09 19:07:24.869676 00161875 C RPC conn 0x7f73780418e0 ref count:2 +10652:09/09 19:07:24.869698 00161875 C RPC DND-S conn 0x7f73780418e0 send data +10653:09/09 19:07:24.869701 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:11, qid:16, gtid:0x0:0x70b71d6778d00019 +10655:09/09 19:07:24.869705 00161875 C RPC conn 0x7f73780418e0 ref count:1 +10656:09/09 19:07:24.869711 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +10658:09/09 19:07:24.869727 00161875 C RPC DND-S conn 0x7f73780418e0 query received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:1312, cost:373us, seqNum:12, qid:18, gtid:0xadc8d7778d40000e:0x70b71d6778d0001b +10659:09/09 19:07:24.869729 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d7778d40000e:0x70b71d6778d0001b +10668:09/09 19:07:24.869752 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback +10677:09/09 19:07:24.869921 00161875 C RPC DND-S conn 0x7f73780418e0 register brokenlink callback +10678:09/09 19:07:24.869925 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback, qid:18 +10679:09/09 19:07:24.869929 00161875 C RPC conn 0x7f73780418e0 register brokenlink callback succ +10858:09/09 19:07:24.872444 00162312 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d7778d40000e:0x70b71d6778d0001b +10867:09/09 19:07:24.872486 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +10869:09/09 19:07:24.872493 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +10870:09/09 19:07:24.872496 00161875 C RPC DND-S conn 0x7f73780418e0 query-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:130, seqNum:12, qid:18, gtid:0xadc8d7778d40000e:0x70b71d6778d0001b +10871:09/09 19:07:24.872498 00161875 C RPC conn 0x7f73780418e0 ref count:2 +10872:09/09 19:07:24.872518 00161875 C RPC DND-S conn 0x7f73780418e0 send data +10873:09/09 19:07:24.872521 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:12, qid:18, gtid:0xadc8d7778d40000e:0x70b71d6778d0001b +10875:09/09 19:07:24.872525 00161875 C RPC conn 0x7f73780418e0 ref count:1 +10952:09/09 19:07:24.873453 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +10954:09/09 19:07:24.873476 00161875 C RPC DND-S conn 0x7f73780418e0 merge-query received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:595, cost:107us, seqNum:13, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001d +10955:09/09 19:07:24.873479 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d7778d40000e:0x70b71d6778d0001d +10964:09/09 19:07:24.873500 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback +10972:09/09 19:07:24.873553 00161875 C RPC DND-S conn 0x7f73780418e0 register brokenlink callback +10977:09/09 19:07:24.873556 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback, qid:20 +10981:09/09 19:07:24.873672 00161875 C RPC conn 0x7f73780418e0 register brokenlink callback succ +11153:09/09 19:07:24.874866 00163053 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d7778d40000e:0x70b71d6778d0001d +11159:09/09 19:07:24.874914 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +11160:09/09 19:07:24.874926 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +11162:09/09 19:07:24.874930 00161875 C RPC DND-S conn 0x7f73780418e0 merge-query-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:111, seqNum:13, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001d +11166:09/09 19:07:24.874933 00161875 C RPC conn 0x7f73780418e0 ref count:2 +11167:09/09 19:07:24.875549 00161875 C RPC DND-S conn 0x7f73780418e0 send data +11168:09/09 19:07:24.875602 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:13, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001d +11170:09/09 19:07:24.875646 00161875 C RPC conn 0x7f73780418e0 ref count:1 +11171:09/09 19:07:24.876014 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +11173:09/09 19:07:24.876039 00161875 C RPC DND-S conn 0x7f73780418e0 merge-fetch received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:44, cost:62us, seqNum:14, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001e +11174:09/09 19:07:24.876042 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d7778d40000e:0x70b71d6778d0001e +11200:09/09 19:07:24.876181 00162337 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d7778d40000e:0x70b71d6778d0001e +11209:09/09 19:07:24.876215 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +11210:09/09 19:07:24.876217 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +11211:09/09 19:07:24.876219 00161875 C RPC DND-S conn 0x7f73780418e0 merge-fetch-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:1110, seqNum:14, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001e +11212:09/09 19:07:24.876221 00161875 C RPC conn 0x7f73780418e0 ref count:2 +11213:09/09 19:07:24.876246 00161875 C RPC DND-S conn 0x7f73780418e0 send data +11214:09/09 19:07:24.876249 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:14, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001e +11216:09/09 19:07:24.876253 00161875 C RPC conn 0x7f73780418e0 ref count:1 +11217:09/09 19:07:24.876706 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +11219:09/09 19:07:24.876732 00161875 C RPC DND-S conn 0x7f73780418e0 drop-task received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:48, cost:54us, seqNum:15, qid:18, gtid:0xadc8d7778d40000e:0x70b71d6778d0001f +11220:09/09 19:07:24.876734 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d7778d40000e:0x70b71d6778d0001f +11235:09/09 19:07:24.876834 00162315 C RPC DND-S conn 0x7f73780418e0 start to send task-release, qid:18 +11255:09/09 19:07:24.877107 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +11257:09/09 19:07:24.877134 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +11259:09/09 19:07:24.877149 00161875 C RPC DND-S conn 0x7f73780418e0 task-release is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:91, seqNum:0, qid:18, gtid:0xadc8d7778d40000e:0x70b71d6778d0001b +11260:09/09 19:07:24.877169 00161875 C RPC conn 0x7f73780418e0 ref count:2 +11263:09/09 19:07:24.877193 00161875 C RPC DND-S conn 0x7f73780418e0 send data +11264:09/09 19:07:24.877294 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:0, qid:18, gtid:0xadc8d7778d40000e:0x70b71d6778d0001b +11266:09/09 19:07:24.877323 00161875 C RPC conn 0x7f73780418e0 ref count:1 +11270:09/09 19:07:24.877340 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +11275:09/09 19:07:24.877458 00161875 C RPC DND-S conn 0x7f73780418e0 drop-task received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:48, cost:717us, seqNum:16, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d00021 +11276:09/09 19:07:24.877461 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d7778d40000e:0x70b71d6778d00021 +11342:09/09 19:07:24.877977 00162337 C RPC DND-S conn 0x7f73780418e0 start to send task-release, qid:20 +11359:09/09 19:07:24.878137 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +11361:09/09 19:07:24.878182 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +11363:09/09 19:07:24.878186 00161875 C RPC DND-S conn 0x7f73780418e0 task-release is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:91, seqNum:0, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001d +11364:09/09 19:07:24.878189 00161875 C RPC conn 0x7f73780418e0 ref count:2 +11365:09/09 19:07:24.878208 00161875 C RPC DND-S conn 0x7f73780418e0 send data +11366:09/09 19:07:24.878220 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:0, qid:20, gtid:0xadc8d7778d40000e:0x70b71d6778d0001d +11368:09/09 19:07:24.878224 00161875 C RPC conn 0x7f73780418e0 ref count:1 +11944:09/09 19:07:26.247094 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +11947:09/09 19:07:26.247153 00161875 C RPC DND-S conn 0x7f73780418e0 query-heartbeat received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:41, cost:126us, seqNum:17, qid:22, gtid:0x0:0x70b71d6779200023 +11949:09/09 19:07:26.247163 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0x0:0x70b71d6779200023 +11981:09/09 19:07:26.247510 00162315 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback +11992:09/09 19:07:26.247599 00161875 C RPC DND-S conn 0x7f73780418e0 register brokenlink callback +11993:09/09 19:07:26.247602 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback, qid:22 +11994:09/09 19:07:26.247605 00161875 C RPC conn 0x7f73780418e0 register brokenlink callback succ +11995:09/09 19:07:26.247578 00162315 C RPC DND-S conn 0x7f73780418e0 start to send task-release, qid:16 +12007:09/09 19:07:26.247821 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12011:09/09 19:07:26.247956 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12013:09/09 19:07:26.247973 00161875 C RPC DND-S conn 0x7f73780418e0 task-release is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:91, seqNum:0, qid:16, gtid:0x0:0x70b71d6778d00019 +12020:09/09 19:07:26.248038 00162315 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0x0:0x70b71d6779200023 +12026:09/09 19:07:26.247975 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12031:09/09 19:07:26.248166 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12033:09/09 19:07:26.248206 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12034:09/09 19:07:26.248217 00161875 C RPC DND-S conn 0x7f73780418e0 query-heartbeat-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:116, seqNum:17, qid:22, gtid:0x0:0x70b71d6779200023 +12037:09/09 19:07:26.248248 00161875 C RPC conn 0x7f73780418e0 ref count:3 +12043:09/09 19:07:26.248296 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12044:09/09 19:07:26.248341 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:0, qid:16, gtid:0x0:0x70b71d6778d00019 +12049:09/09 19:07:26.248433 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12050:09/09 19:07:26.248441 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12054:09/09 19:07:26.248503 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:17, qid:22, gtid:0x0:0x70b71d6779200023 +12074:09/09 19:07:26.248787 00161875 C RPC conn 0x7f73780418e0 ref count:1 +12076:09/09 19:07:26.248887 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +12082:09/09 19:07:26.248920 00161875 C RPC DND-S conn 0x7f73780418e0 query received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:1312, cost:1830us, seqNum:18, qid:24, gtid:0xadc8d77792a60010:0x70b71d6779200025 +12090:09/09 19:07:26.249021 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d77792a60010:0x70b71d6779200025 +12109:09/09 19:07:26.249567 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback +12127:09/09 19:07:26.249617 00161875 C RPC DND-S conn 0x7f73780418e0 register brokenlink callback +12130:09/09 19:07:26.249623 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback, qid:24 +12139:09/09 19:07:26.249633 00161875 C RPC conn 0x7f73780418e0 register brokenlink callback succ +12302:09/09 19:07:26.251246 00162269 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d77792a60010:0x70b71d6779200025 +12317:09/09 19:07:26.251495 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12318:09/09 19:07:26.251597 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12319:09/09 19:07:26.251602 00161875 C RPC DND-S conn 0x7f73780418e0 query-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:130, seqNum:18, qid:24, gtid:0xadc8d77792a60010:0x70b71d6779200025 +12320:09/09 19:07:26.251604 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12321:09/09 19:07:26.251611 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12322:09/09 19:07:26.251613 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:18, qid:24, gtid:0xadc8d77792a60010:0x70b71d6779200025 +12324:09/09 19:07:26.251616 00161875 C RPC conn 0x7f73780418e0 ref count:1 +12327:09/09 19:07:26.290976 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +12329:09/09 19:07:26.291023 00161875 C RPC DND-S conn 0x7f73780418e0 merge-query received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:595, cost:96us, seqNum:19, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200027 +12330:09/09 19:07:26.291026 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d77792a60010:0x70b71d6779200027 +12339:09/09 19:07:26.291064 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback +12347:09/09 19:07:26.291142 00161875 C RPC DND-S conn 0x7f73780418e0 register brokenlink callback +12348:09/09 19:07:26.291145 00161875 C RPC DND-S conn 0x7f73780418e0 start to register brokenlink callback, qid:26 +12351:09/09 19:07:26.291148 00161875 C RPC conn 0x7f73780418e0 register brokenlink callback succ +12528:09/09 19:07:26.292905 00162273 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d77792a60010:0x70b71d6779200027 +12532:09/09 19:07:26.292977 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12536:09/09 19:07:26.292980 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12538:09/09 19:07:26.293019 00161875 C RPC DND-S conn 0x7f73780418e0 merge-query-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:111, seqNum:19, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200027 +12541:09/09 19:07:26.293025 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12542:09/09 19:07:26.293054 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12543:09/09 19:07:26.293068 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:19, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200027 +12545:09/09 19:07:26.293073 00161875 C RPC conn 0x7f73780418e0 ref count:1 +12546:09/09 19:07:26.293505 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +12548:09/09 19:07:26.293524 00161875 C RPC DND-S conn 0x7f73780418e0 merge-fetch received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:44, cost:65us, seqNum:20, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200028 +12549:09/09 19:07:26.293526 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d77792a60010:0x70b71d6779200028 +12575:09/09 19:07:26.293624 00162337 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0xadc8d77792a60010:0x70b71d6779200028 +12579:09/09 19:07:26.293691 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12581:09/09 19:07:26.293694 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12582:09/09 19:07:26.293711 00161875 C RPC DND-S conn 0x7f73780418e0 merge-fetch-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:1110, seqNum:20, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200028 +12583:09/09 19:07:26.293733 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12588:09/09 19:07:26.293847 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12589:09/09 19:07:26.293861 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:20, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200028 +12591:09/09 19:07:26.293866 00161875 C RPC conn 0x7f73780418e0 ref count:1 +12602:09/09 19:07:26.294162 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +12609:09/09 19:07:26.294319 00161875 C RPC DND-S conn 0x7f73780418e0 drop-task received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:48, cost:204us, seqNum:21, qid:26, gtid:0xadc8d77792a60010:0x70b71d677920002a +12610:09/09 19:07:26.294508 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d77792a60010:0x70b71d677920002a +12663:09/09 19:07:26.295131 00162337 C RPC DND-S conn 0x7f73780418e0 start to send task-release, qid:26 +12680:09/09 19:07:26.295340 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12682:09/09 19:07:26.295381 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12684:09/09 19:07:26.295419 00161875 C RPC DND-S conn 0x7f73780418e0 task-release is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:91, seqNum:0, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200027 +12685:09/09 19:07:26.295431 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12686:09/09 19:07:26.295510 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12687:09/09 19:07:26.295527 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:0, qid:26, gtid:0xadc8d77792a60010:0x70b71d6779200027 +12689:09/09 19:07:26.295532 00161875 C RPC conn 0x7f73780418e0 ref count:1 +12690:09/09 19:07:26.295540 00161875 C RPC DND-S conn 0x7f73780418e0 not reset read buf +12692:09/09 19:07:26.295557 00161875 C RPC DND-S conn 0x7f73780418e0 drop-task received from 127.0.0.1:59940, local info:127.0.0.1:6100, len:48, cost:1397us, seqNum:22, qid:24, gtid:0xadc8d77792a60010:0x70b71d677920002b +12693:09/09 19:07:26.295559 00161875 C RPC DND-S handle 0x7f737802b760 conn:0x7f73780418e0 translated to app, refId:8, gtid:0xadc8d77792a60010:0x70b71d677920002b +12708:09/09 19:07:26.295660 00162315 C RPC DND-S conn 0x7f73780418e0 start to send task-release, qid:24 +12713:09/09 19:07:26.295705 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12716:09/09 19:07:26.295713 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12718:09/09 19:07:26.295749 00161875 C RPC DND-S conn 0x7f73780418e0 task-release is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:91, seqNum:0, qid:24, gtid:0xadc8d77792a60010:0x70b71d6779200025 +12719:09/09 19:07:26.295752 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12721:09/09 19:07:26.295774 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12722:09/09 19:07:26.295795 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:0, qid:24, gtid:0xadc8d77792a60010:0x70b71d6779200025 +12724:09/09 19:07:26.295800 00161875 C RPC conn 0x7f73780418e0 ref count:1 +12939:09/09 19:07:27.279390 00161881 C RPC conn 0x7f73780418e0 start to send resp (1/2), gtid:0x0:0x70b71d6779200023 +12943:09/09 19:07:27.279480 00161875 C RPC DND-S conn 0x7f73780418e0 start to send resp (2/2) +12944:09/09 19:07:27.279486 00161875 C RPC DND-S conn 0x7f73780418e0 has 1 msg to send +12945:09/09 19:07:27.279491 00161875 C RPC DND-S conn 0x7f73780418e0 query-heartbeat-rsp is sent to 127.0.0.1:59940, local info:127.0.0.1:6100, len:116, seqNum:17, qid:22, gtid:0x0:0x70b71d6779200023 +12946:09/09 19:07:27.279494 00161875 C RPC conn 0x7f73780418e0 ref count:2 +12947:09/09 19:07:27.279530 00161875 C RPC DND-S conn 0x7f73780418e0 send data +12948:09/09 19:07:27.279560 00161875 C RPC DND-S conn 0x7f73780418e0 msg already send out, seqNum:17, qid:22, gtid:0x0:0x70b71d6779200023 +12950:09/09 19:07:27.279585 00161875 C RPC conn 0x7f73780418e0 ref count:1 +13094:09/09 19:07:27.747059 00161875 C RPC DND-S conn 0x7f73780418e0 read error:EOF +13095:09/09 19:07:27.747080 00161875 C RPC conn 0x7f73780418e0 to be destroyed +13098:09/09 19:07:27.747108 00161875 C RPC DND-S conn 0x7f73780418e0 destroy diff --git a/qid b/qid new file mode 100644 index 0000000000..d8a8431ea0 --- /dev/null +++ b/qid @@ -0,0 +1,216 @@ +11802:09/09 19:41:59.586660 00211996 C RPC DND-S conn 0x7fa218014af0 query received from 127.0.0.1:37174, local info:127.0.0.1:6100, len:1312, cost:589us, seqNum:16, qid:22, gtid:0x2e20039735a00008:0x26f31d6973500026 +11803:09/09 19:41:59.586682 00211996 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 prerocessQuery start, handle:0x7fa218021f60, SQL:select * from test.sp; +11804:09/09 19:41:59.586684 00211994 C RPC DND-S conn 0x7fa210002100 query received from 127.0.0.1:37180, local info:127.0.0.1:6100, len:1312, cost:642us, seqNum:15, qid:21, gtid:0x2e20039735a00008:0x26f31d6973500025 +11806:09/09 19:41:59.586698 00211994 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 prerocessQuery start, handle:0x7fa210010ec0, SQL:select * from test.sp; +11807:09/09 19:41:59.586700 00211996 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 task status added, newStatus:INIT +11808:09/09 19:41:59.586713 00211996 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 prerocessQuery end, handle:0x7fa218021f60, code:0 +11810:09/09 19:41:59.586728 00211994 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task status added, newStatus:INIT +11811:09/09 19:41:59.586734 00211994 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 prerocessQuery end, handle:0x7fa210010ec0, code:0 +11818:09/09 19:41:59.586785 00212137 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 processQuery start, node:0x7fa24d7e8f50, type:query, compress:0, handle:0x7fa210010ec0, SQL:select * from test.sp; +11819:09/09 19:41:59.586795 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 start to handle event at phase PRE_QUERY +11820:09/09 19:41:59.586802 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task status updated from INIT to EXECUTING +11821:09/09 19:41:59.586805 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 end to handle event at phase PRE_QUERY, code:success +11822:09/09 19:41:59.586816 00212138 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 processQuery start, node:0x7fa24cfe7f50, type:query, compress:0, handle:0x7fa218021f60, SQL:select * from test.sp; +11823:09/09 19:41:59.586831 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 start to handle event at phase PRE_QUERY +11824:09/09 19:41:59.586837 00212137 C QRY start to create task, TID:0xa QID:0x2e20039735a00008, vgId:2 +11825:09/09 19:41:59.586840 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 task status updated from INIT to EXECUTING +11826:09/09 19:41:59.586845 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 end to handle event at phase PRE_QUERY, code:success +11827:09/09 19:41:59.586878 00212137 C QRY extract queried table list completed, 1 tables, elapsed time:0.00 ms TID:0xa QID:0x2e20039735a00008 +11828:09/09 19:41:59.586887 00212137 C QRY generate group id map completed, elapsed time:0.01 ms TID:0xa QID:0x2e20039735a00008 +11829:09/09 19:41:59.586891 00212138 C QRY start to create task, TID:0xb QID:0x2e20039735a00008, vgId:3 +11830:09/09 19:41:59.586919 00212137 C QRY subplan task create completed, TID:0xa QID:0x2e20039735a00008 +11831:09/09 19:41:59.586925 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 start to execTask, loopIdx:0 +11832:09/09 19:41:59.586928 00212137 C QRY TID:0xa QID:0x2e20039735a00008 execTask is launched +11833:09/09 19:41:59.586943 00212138 C QRY extract queried table list completed, 0 tables, elapsed time:0.00 ms TID:0xb QID:0x2e20039735a00008 +11834:09/09 19:41:59.586950 00212137 C TSD 0x7fa16001f930 create 1 tables scan-info, size:0.38 Kb, elapsed time:0.00 ms, TID:0xa QID:0x2e20039735a00008 +11835:09/09 19:41:59.586955 00212137 C TSD 0x7fa16001f930 total numOfTable:1, window:1410522119587 - 9223372036854775807, verRange:0 - 46 in this query TID:0xa QID:0x2e20039735a00008 +11836:09/09 19:41:59.586967 00212137 C TSD init fileset iterator, total files:1 TID:0xa QID:0x2e20039735a00008 +11837:09/09 19:41:59.586951 00212138 C QRY no table qualified for query, TID:0xb QID:0x2e20039735a00008lx +11838:09/09 19:41:59.586972 00212137 C TSD 0x7fa16001f930 file found fid:1997 for qrange:1410522119587-9223372036854775807, TID:0xa QID:0x2e20039735a00008 +11839:09/09 19:41:59.586979 00212137 C TSD load block of 1 tables completed, blocks:0 in 0 tables, stt-files:1, block-info-size:0.00 Kb, elapsed time:0.00 ms TID:0xa QID:0x2e20039735a00008 +11840:09/09 19:41:59.586983 00212137 C TSD reader: 0x7fa16001f930 resumed uid 0, numOfTable:1, in this query TID:0xa QID:0x2e20039735a00008 +11841:09/09 19:41:59.586986 00212137 C TSD seq load data blocks from stt files TID:0xa QID:0x2e20039735a00008 +11842:09/09 19:41:59.586989 00212137 C TSD init stt block reader, window:1410522119587-9223372036854775807, uid:8502546947039559767, TID:0xa QID:0x2e20039735a00008 +11843:09/09 19:41:59.587009 00212138 C QRY subplan task create completed, TID:0xb QID:0x2e20039735a00008 +11844:09/09 19:41:59.587018 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 start to execTask, loopIdx:0 +11845:09/09 19:41:59.587022 00212138 C QRY TID:0xb QID:0x2e20039735a00008 execTask is launched +11846:09/09 19:41:59.587040 00212137 C TSD TID:0xa QID:0x2e20039735a00008 load 1 statis blocks into buf, elapsed time:0.01ms +11847:09/09 19:41:59.587045 00212137 C TSD load the stt file blk info completed, elapsed time:0.02ms, TID:0xa QID:0x2e20039735a00008 +11848:09/09 19:41:59.587050 00212138 C TSD 0x7fa16401f900 create 0 tables scan-info, size:0.00 Kb, elapsed time:0.00 ms, TID:0xb QID:0x2e20039735a00008 +11849:09/09 19:41:59.587056 00212138 C TSD 0x7fa16401f900 total numOfTable:0, window:1410522119588 - 9223372036854775807, verRange:0 - 4 in this query TID:0xb QID:0x2e20039735a00008 +11850:09/09 19:41:59.587061 00212138 C TSD reader: 0x7fa16401f900 resumed uid 0, numOfTable:0, in this query TID:0xb QID:0x2e20039735a00008 +11851:09/09 19:41:59.587063 00212137 C TSD read stt block, total load:1, trigger by uid:8502546947039559767, stt-fileVer:1, last block index:0, entry:0, rows:42, uidRange:8502546947039559767-8502546947039559767 tsRange:1725878896277-1725878917534 0x7fa1600223d0, elapsed time:0.01 ms, TID:0xa QID:0x2e20039735a00008 +11853:09/09 19:41:59.587067 00212137 C TSD last block index list:0, -1, rowIndex:-1 TID:0xa QID:0x2e20039735a00008 +11854:09/09 19:41:59.587107 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11856:09/09 19:41:59.587118 00212138 C QRY TID:0xb QID:0x2e20039735a00008 task suspended, 0 rows in 0 blocks returned, total:0 rows, in sinkNode:0, elapsed:0.00 ms +11857:09/09 19:41:59.587124 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 qExecTask end with empty res, useconds:0 +11858:09/09 19:41:59.587131 00212137 C TSD 0x7fa16001f930 uid:8502546947039559767, no data in mem, TID:0xa QID:0x2e20039735a00008 +11859:09/09 19:41:59.587136 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 start to handle event at phase POST_QUERY +11860:09/09 19:41:59.587139 00212137 C TSD 0x7fa16001f930 uid:8502546947039559767, no data in imem, TID:0xa QID:0x2e20039735a00008 +11861:09/09 19:41:59.587166 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 task status updated from EXECUTING to PARTIAL_SUCCEED +11862:09/09 19:41:59.587172 00212137 C TSD init stt block reader completed, elapsed time:183us TID:0xa QID:0x2e20039735a00008 +11863:09/09 19:41:59.587178 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11864:09/09 19:41:59.587179 00212138 C RPC conn 0x7fa218014af0 start to send resp (1/2), gtid:0x2e20039735a00008:0x26f31d6973500026 +11865:09/09 19:41:59.587198 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11866:09/09 19:41:59.587203 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11867:09/09 19:41:59.587206 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11868:09/09 19:41:59.587207 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 query msg rsped, handle:0x7fa218021f60, code:0 - success +11869:09/09 19:41:59.587215 00212138 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 end to handle event at phase POST_QUERY, code:0 - success +11870:09/09 19:41:59.587220 00212138 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 processQuery end, node:0x7fa24cfe7f50, code:0 +11871:09/09 19:41:59.587223 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11872:09/09 19:41:59.587228 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11873:09/09 19:41:59.587232 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11876:09/09 19:41:59.587308 00211996 C RPC DND-S conn 0x7fa218014af0 query-rsp is sent to 127.0.0.1:37174, local info:127.0.0.1:6100, len:130, seqNum:16, qid:22, gtid:0x2e20039735a00008:0x26f31d6973500026 +11878:09/09 19:41:59.587326 00211996 C RPC DND-S conn 0x7fa218014af0 msg already send out, seqNum:16, qid:22, gtid:0x2e20039735a00008:0x26f31d6973500026 +11879:09/09 19:41:59.587252 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11880:09/09 19:41:59.587507 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11881:09/09 19:41:59.587545 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11882:09/09 19:41:59.587554 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11883:09/09 19:41:59.587580 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11884:09/09 19:41:59.587608 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11885:09/09 19:41:59.587635 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11886:09/09 19:41:59.587663 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11887:09/09 19:41:59.587690 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11888:09/09 19:41:59.587719 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11889:09/09 19:41:59.587745 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11890:09/09 19:41:59.587781 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11891:09/09 19:41:59.587828 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11892:09/09 19:41:59.587856 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11893:09/09 19:41:59.587883 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11894:09/09 19:41:59.587910 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11895:09/09 19:41:59.587937 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11896:09/09 19:41:59.587964 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11897:09/09 19:41:59.587990 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11898:09/09 19:41:59.588034 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11899:09/09 19:41:59.588061 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11900:09/09 19:41:59.588087 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11901:09/09 19:41:59.588114 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11902:09/09 19:41:59.588139 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11903:09/09 19:41:59.588168 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11904:09/09 19:41:59.588176 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11905:09/09 19:41:59.588202 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11906:09/09 19:41:59.588228 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11907:09/09 19:41:59.588254 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11908:09/09 19:41:59.588298 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11909:09/09 19:41:59.588325 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11910:09/09 19:41:59.588351 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11911:09/09 19:41:59.588377 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11912:09/09 19:41:59.588385 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11913:09/09 19:41:59.588409 00212137 C TSD no more last block qualified, uid:8502546947039559767, stt-file block:0, TID:0xa QID:0x2e20039735a00008 +11914:09/09 19:41:59.588415 00212137 C TSD ERROR failed to exec stt-file nextIter, lino:0, code:success, TID:0xa QID:0x2e20039735a00008 +11915:09/09 19:41:59.588444 00212137 C TSD 0x7fa16001f930 uid:8502546947039559767, composed data block created, brange:1725878896277-1725878917534 rows:42, elapsed time:1.27 ms TID:0xa QID:0x2e20039735a00008 +11916:09/09 19:41:59.588470 00212137 C QRY retrieve table meta from cache:1, hit:0 miss:1, TID:0xa QID:0x2e20039735a00008 +11917:09/09 19:41:59.588498 00212137 C TSD seq load data blocks from stt files TID:0xa QID:0x2e20039735a00008 +11918:09/09 19:41:59.588503 00212137 C TSD seq load data blocks from cache, TID:0xa QID:0x2e20039735a00008 +11921:09/09 19:41:59.588518 00212137 C QRY TID:0xa QID:0x2e20039735a00008 task suspended, 42 rows in 1 blocks returned, total:42 rows, in sinkNode:0, elapsed:1.59 ms +11922:09/09 19:41:59.588535 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 data put into sink, rows:42, continueExecTask:1 +11923:09/09 19:41:59.588539 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 qExecTask done, useconds:1587 +11924:09/09 19:41:59.588542 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 start to handle event at phase POST_QUERY +11925:09/09 19:41:59.588549 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task status updated from EXECUTING to PARTIAL_SUCCEED +11926:09/09 19:41:59.588558 00212137 C RPC conn 0x7fa210002100 start to send resp (1/2), gtid:0x2e20039735a00008:0x26f31d6973500025 +11927:09/09 19:41:59.588587 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 query msg rsped, handle:0x7fa210010ec0, code:0 - success +11928:09/09 19:41:59.588594 00212137 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 end to handle event at phase POST_QUERY, code:0 - success +11930:09/09 19:41:59.588600 00212137 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 processQuery end, node:0x7fa24d7e8f50, code:0 +11932:09/09 19:41:59.588608 00211994 C RPC DND-S conn 0x7fa210002100 query-rsp is sent to 127.0.0.1:37180, local info:127.0.0.1:6100, len:130, seqNum:15, qid:21, gtid:0x2e20039735a00008:0x26f31d6973500025 +11934:09/09 19:41:59.588616 00211994 C RPC DND-S conn 0x7fa210002100 msg already send out, seqNum:15, qid:21, gtid:0x2e20039735a00008:0x26f31d6973500025 +11935:09/09 19:41:59.631192 00211994 C RPC DND-S conn 0x7fa210002100 merge-query received from 127.0.0.1:37180, local info:127.0.0.1:6100, len:595, cost:80us, seqNum:16, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500027 +11936:09/09 19:41:59.631228 00211994 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 prerocessQuery start, handle:0x7fa210010ec0, SQL:select * from test.sp; +11938:09/09 19:41:59.631255 00211994 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task status added, newStatus:INIT +11939:09/09 19:41:59.631260 00211994 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 prerocessQuery end, handle:0x7fa210010ec0, code:0 +11943:09/09 19:41:59.631349 00212139 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 processQuery start, node:0x7fa24c7e6f50, type:merge-query, compress:0, handle:0x7fa210010ec0, SQL:select * from test.sp; +11944:09/09 19:41:59.631367 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 start to handle event at phase PRE_QUERY +11945:09/09 19:41:59.631378 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task status updated from INIT to EXECUTING +11946:09/09 19:41:59.631382 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 end to handle event at phase PRE_QUERY, code:success +11947:09/09 19:41:59.631410 00212139 C QRY start to create task, TID:0x9 QID:0x2e20039735a00008, vgId:2 +11948:09/09 19:41:59.631435 00212139 C QRY subplan task create completed, TID:0x9 QID:0x2e20039735a00008 +11949:09/09 19:41:59.631439 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 start to execTask, loopIdx:0 +11950:09/09 19:41:59.631443 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 execTask is launched +11951:09/09 19:41:59.631450 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 build fetch msg and send to vgId:3, ep:localhost, taskId:0xb, execId:0, 0x7fa158002f60, 0/2 +11955:09/09 19:41:59.631501 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 build fetch msg and send to vgId:2, ep:localhost, taskId:0xa, execId:0, 0x7fa158002f60, 1/2 +11960:09/09 19:41:59.631527 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 send all fetch requests to 2 sources completed, elapsed:0.08ms +11961:09/09 19:41:59.631554 00212139 C QRY prepare wait for ready, 0x7fa158002f60, TID:0x9 QID:0x2e20039735a00008 +11974:09/09 19:41:59.631693 00212158 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 processFetch start, node:0x7fa288001640, handle:0x7fa210021de0 +11975:09/09 19:41:59.631702 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 start to handle event at phase PRE_FETCH +11976:09/09 19:41:59.631709 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 end to handle event at phase PRE_FETCH, code:success +11977:09/09 19:41:59.631714 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 no more data in sink and query end, fetched blocks 0 rows 0 +11978:09/09 19:41:59.631721 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 task status updated from PARTIAL_SUCCEED to SUCCEED +11979:09/09 19:41:59.631725 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 start to handle event at phase POST_FETCH +11980:09/09 19:41:59.631728 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 end to handle event at phase POST_FETCH, code:0 - success +11982:09/09 19:41:59.631756 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 fetch rsp send, msgType:fetch-rsp, handle:0x7fa210021de0, code:0 - success, dataLen:0 +11983:09/09 19:41:59.631761 00212158 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 processFetch end, node:0x7fa288001640, code:0 +11990:09/09 19:41:59.631932 00211999 C QRY TID:0x9 QID:0x2e20039735a00008 fetch rsp received, index:0, blocks:0, rows:0, 0x7fa158002f60 +11993:09/09 19:41:59.631972 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 vgId:3, taskId:0xb execId:0 index:0 completed, rowsOfSource:0, totalRows:0, try next 1/2 +11994:09/09 19:41:59.631993 00212139 C QRY prepare wait for ready, 0x7fa158002f60, TID:0x9 QID:0x2e20039735a00008 +11995:09/09 19:41:59.632005 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 processFetch start, node:0x7fa290001630, handle:0x7fa210021de0 +11996:09/09 19:41:59.632013 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 start to handle event at phase PRE_FETCH +11997:09/09 19:41:59.632018 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 end to handle event at phase PRE_FETCH, code:success +11999:09/09 19:41:59.632025 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 there are data in sink, dataLength:746 +12000:09/09 19:41:59.632029 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task all data fetched and done, fetched blocks 1 rows 42 +12001:09/09 19:41:59.632033 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task status updated from PARTIAL_SUCCEED to SUCCEED +12002:09/09 19:41:59.632036 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 start to handle event at phase POST_FETCH +12003:09/09 19:41:59.632038 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 end to handle event at phase POST_FETCH, code:0 - success +12005:09/09 19:41:59.632063 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 fetch rsp send, msgType:fetch-rsp, handle:0x7fa210021de0, code:0 - success, dataLen:754 +12006:09/09 19:41:59.632068 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 processFetch end, node:0x7fa290001630, code:0 +12013:09/09 19:41:59.632150 00211999 C QRY TID:0x9 QID:0x2e20039735a00008 fetch rsp received, index:1, blocks:1, rows:42, 0x7fa158002f60 +12015:09/09 19:41:59.632191 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 fetch msg rsp from vgId:2, taskId:0xa execId:0 index:1 completed, blocks:1, numOfRows:42, rowsOfSource:42, totalRows:42, total:0.74 Kb, try next 2/2 +12016:09/09 19:41:59.632206 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 all 2 sources are exhausted, total rows: 42, 0.74 Kb, elapsed:0.69 ms +12017:09/09 19:41:59.632212 00212139 C QRY TID:0x9 QID:0x2e20039735a00008 task suspended, 42 rows in 1 blocks returned, total:42 rows, in sinkNode:0, elapsed:0.77 ms +12018:09/09 19:41:59.632219 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 data put into sink, rows:42, continueExecTask:1 +12019:09/09 19:41:59.632222 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 qExecTask done, useconds:766 +12020:09/09 19:41:59.632226 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 start to handle event at phase POST_QUERY +12021:09/09 19:41:59.632238 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task status updated from EXECUTING to PARTIAL_SUCCEED +12022:09/09 19:41:59.632246 00212139 C RPC conn 0x7fa210002100 start to send resp (1/2), gtid:0x2e20039735a00008:0x26f31d6973500027 +12023:09/09 19:41:59.632271 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 query msg rsped, handle:0x7fa210010ec0, code:0 - success +12024:09/09 19:41:59.632277 00212139 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 end to handle event at phase POST_QUERY, code:0 - success +12025:09/09 19:41:59.632282 00212139 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 processQuery end, node:0x7fa24c7e6f50, code:0 +12028:09/09 19:41:59.632295 00211994 C RPC DND-S conn 0x7fa210002100 merge-query-rsp is sent to 127.0.0.1:37180, local info:127.0.0.1:6100, len:111, seqNum:16, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500027 +12030:09/09 19:41:59.632333 00211994 C RPC DND-S conn 0x7fa210002100 msg already send out, seqNum:16, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500027 +12031:09/09 19:41:59.632825 00211994 C RPC DND-S conn 0x7fa210002100 merge-fetch received from 127.0.0.1:37180, local info:127.0.0.1:6100, len:44, cost:54us, seqNum:17, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500028 +12032:09/09 19:41:59.632870 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 processFetch start, node:0x7fa290001630, handle:0x7fa210010ec0 +12033:09/09 19:41:59.632878 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 start to handle event at phase PRE_FETCH +12034:09/09 19:41:59.632882 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 end to handle event at phase PRE_FETCH, code:success +12036:09/09 19:41:59.632887 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 there are data in sink, dataLength:746 +12037:09/09 19:41:59.632890 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task all data fetched and done, fetched blocks 1 rows 42 +12038:09/09 19:41:59.632894 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task status updated from PARTIAL_SUCCEED to SUCCEED +12039:09/09 19:41:59.632896 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 start to handle event at phase POST_FETCH +12040:09/09 19:41:59.632899 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 end to handle event at phase POST_FETCH, code:0 - success +12041:09/09 19:41:59.632902 00212159 C RPC conn 0x7fa210002100 start to send resp (1/2), gtid:0x2e20039735a00008:0x26f31d6973500028 +12042:09/09 19:41:59.632921 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 fetch rsp send, msgType:merge-fetch-rsp, handle:0x7fa210010ec0, code:0 - success, dataLen:754 +12043:09/09 19:41:59.632925 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 processFetch end, node:0x7fa290001630, code:0 +12046:09/09 19:41:59.632944 00211994 C RPC DND-S conn 0x7fa210002100 merge-fetch-rsp is sent to 127.0.0.1:37180, local info:127.0.0.1:6100, len:1110, seqNum:17, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500028 +12048:09/09 19:41:59.632984 00211994 C RPC DND-S conn 0x7fa210002100 msg already send out, seqNum:17, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500028 +12049:09/09 19:41:59.633734 00211994 C RPC DND-S conn 0x7fa210002100 drop-task received from 127.0.0.1:37180, local info:127.0.0.1:6100, len:48, cost:49us, seqNum:18, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500029 +12050:09/09 19:41:59.633780 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 processDrop start, node:0x7fa290001630, handle:0x7fa210010ec0 +12051:09/09 19:41:59.633805 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task status dropped +12053:09/09 19:41:59.633842 00211996 C RPC DND-S conn 0x7fa218014af0 drop-task received from 127.0.0.1:37174, local info:127.0.0.1:6100, len:48, cost:43us, seqNum:17, qid:22, gtid:0x2e20039735a00008:0x26f31d697350002b +12054:09/09 19:41:59.633842 00212159 C QRY TID:0x9 QID:0x2e20039735a00008 execTask completed, numOfRows:42 +12055:09/09 19:41:59.633853 00212159 C QRY TID:0x9 QID:0x2e20039735a00008 :cost summary: idle in queue:0.03 ms, elapsed time:0.77 ms +12057:09/09 19:41:59.633878 00212158 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 processDrop start, node:0x7fa288001640, handle:0x7fa218021f60 +12058:09/09 19:41:59.633892 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 task status dropped +12059:09/09 19:41:59.633859 00212159 C QRY TID:0x9 QID:0x2e20039735a00008 execTask is freed +12063:09/09 19:41:59.633914 00211994 C RPC DND-S conn 0x7fa210002100 task-release is sent to 127.0.0.1:37180, local info:127.0.0.1:6100, len:91, seqNum:0, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500027 +12065:09/09 19:41:59.633926 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task ctx dropped +12066:09/09 19:41:59.633928 00212159 C QRY QID:0x2e20039735a00008,TID:0x9,EID:0 task is dropped +12067:09/09 19:41:59.633926 00212158 C QRY TID:0xb QID:0x2e20039735a00008 execTask completed, numOfRows:0 +12068:09/09 19:41:59.633932 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0x9,EID:0 processDrop end, node:0x7fa290001630, code:0 +12069:09/09 19:41:59.633935 00212158 C QRY TID:0xb QID:0x2e20039735a00008 :cost summary: idle:0.12 ms, elapsed time:0.00 ms, extract tableList:0.00 ms, createGroupIdMap:0.00 ms, total blocks:0, load block SMA:0, load data block:0, total rows:0, check rows:0 +12070:09/09 19:41:59.633942 00212158 C QRY TID:0xb QID:0x2e20039735a00008 execTask is freed +12073:09/09 19:41:59.633961 00211996 C RPC DND-S conn 0x7fa218014af0 task-release is sent to 127.0.0.1:37174, local info:127.0.0.1:6100, len:91, seqNum:0, qid:22, gtid:0x2e20039735a00008:0x26f31d6973500026 +12074:09/09 19:41:59.633961 00212158 C TSD 0x7fa16401f900 :io-cost summary: head-file:0, head-file time:0.00 ms, SMA:0 SMA-time:0.00 ms, fileBlocks:0, fileBlocks-load-time:0.00 ms, build in-memory-block-time:0.00 ms, sttBlocks:0, sttBlocks-time:0.00 ms, sttStatisBlock:0, stt-statis-Block-time:0.00 ms, composed-blocks:0, composed-blocks-time:0.00ms, STableBlockScanInfo size:0.00 Kb, createTime:0.00 ms,createSkylineIterTime:0.00 ms, initSttBlockReader:0.00ms, TID:0xb QID:0x2e20039735a00008 +12076:09/09 19:41:59.633976 00211994 C RPC DND-S conn 0x7fa210002100 msg already send out, seqNum:0, qid:23, gtid:0x2e20039735a00008:0x26f31d6973500027 +12079:09/09 19:41:59.633989 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 task ctx dropped +12080:09/09 19:41:59.633991 00212158 C QRY QID:0x2e20039735a00008,TID:0xb,EID:0 task is dropped +12081:09/09 19:41:59.633991 00211994 C RPC DND-S conn 0x7fa210002100 drop-task received from 127.0.0.1:37180, local info:127.0.0.1:6100, len:48, cost:257us, seqNum:19, qid:21, gtid:0x2e20039735a00008:0x26f31d697350002a +12083:09/09 19:41:59.633995 00212158 C QRY QW:0x7fa2882818e0 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xb,EID:0 processDrop end, node:0x7fa288001640, code:0 +12084:09/09 19:41:59.634004 00211996 C RPC DND-S conn 0x7fa218014af0 msg already send out, seqNum:0, qid:22, gtid:0x2e20039735a00008:0x26f31d6973500026 +12085:09/09 19:41:59.634046 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 processDrop start, node:0x7fa290001630, handle:0x7fa210010ec0 +12086:09/09 19:41:59.634059 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task status dropped +12088:09/09 19:41:59.634091 00212159 C QRY TID:0xa QID:0x2e20039735a00008 execTask completed, numOfRows:42 +12089:09/09 19:41:59.634097 00212159 C QRY TID:0xa QID:0x2e20039735a00008 :cost summary: idle:0.09 ms, elapsed time:1.59 ms, extract tableList:0.00 ms, createGroupIdMap:0.01 ms, total blocks:1, load block SMA:0, load data block:1, total rows:42, check rows:42 +12090:09/09 19:41:59.634105 00212159 C QRY TID:0xa QID:0x2e20039735a00008 execTask is freed +12093:09/09 19:41:59.634123 00211994 C RPC DND-S conn 0x7fa210002100 task-release is sent to 127.0.0.1:37180, local info:127.0.0.1:6100, len:91, seqNum:0, qid:21, gtid:0x2e20039735a00008:0x26f31d6973500025 +12094:09/09 19:41:59.634143 00212159 C TSD 0x7fa16001f930 :io-cost summary: head-file:0, head-file time:0.00 ms, SMA:0 SMA-time:0.00 ms, fileBlocks:1, fileBlocks-load-time:0.00 ms, build in-memory-block-time:0.00 ms, sttBlocks:1, sttBlocks-time:0.01 ms, sttStatisBlock:1, stt-statis-Block-time:0.01 ms, composed-blocks:1, composed-blocks-time:1.27ms, STableBlockScanInfo size:0.38 Kb, createTime:0.00 ms,createSkylineIterTime:0.00 ms, initSttBlockReader:0.18ms, TID:0xa QID:0x2e20039735a00008 +12096:09/09 19:41:59.634157 00211994 C RPC DND-S conn 0x7fa210002100 msg already send out, seqNum:0, qid:21, gtid:0x2e20039735a00008:0x26f31d6973500025 +12099:09/09 19:41:59.634179 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task ctx dropped +12100:09/09 19:41:59.634181 00212159 C QRY QID:0x2e20039735a00008,TID:0xa,EID:0 task is dropped +12101:09/09 19:41:59.634184 00212159 C QRY QW:0x7fa2901c0b60 SID:0x3034663031623866,QID:0x2e20039735a00008,TID:0xa,EID:0 processDrop end, node:0x7fa290001630, code:0 diff --git a/source/libs/transport/src/transCli.c b/source/libs/transport/src/transCli.c index 3c74fbd168..25ac74d9c0 100644 --- a/source/libs/transport/src/transCli.c +++ b/source/libs/transport/src/transCli.c @@ -1160,6 +1160,9 @@ static void cliRecvCb(uv_stream_t* handle, ssize_t nread, const uv_buf_t* buf) { if (handle->data == NULL) { return; } + int32_t fd; + uv_fileno((uv_handle_t*)handle, &fd); + setsockopt(fd, IPPROTO_TCP, TCP_QUICKACK, (int[]){1}, sizeof(int)); SCliConn* conn = handle->data; SConnBuffer* pBuf = &conn->readBuf; @@ -3630,13 +3633,13 @@ static SCliConn* getConnFromHeapCache(SHashObj* pConnHeapCache, char* key) { return NULL; } code = transHeapGet(pHeap, &pConn); - if (pConn && taosHashGetSize(pConn->pQTable) > 0) { - tDebug("get conn %p from heap cache for key:%s, status:%d, refCnt:%d", pConn, key, pConn->inHeap, pConn->reqRefCnt); - return NULL; - } /*else { - // tDebug("failed to get conn from heap cache for key:%s", key); - // return NULL; - }*/ + // if (pConn && taosHashGetSize(pConn->pQTable) > 0) { + // tDebug("get conn %p from heap cache for key:%s, status:%d, refCnt:%d", pConn, key, pConn->inHeap, + // pConn->reqRefCnt); return NULL; + // } /*else { + // // tDebug("failed to get conn from heap cache for key:%s", key); + // // return NULL; + // }*/ if (code != 0) { tDebug("failed to get conn from heap cache for key:%s", key); diff --git a/source/libs/transport/src/transSvr.c b/source/libs/transport/src/transSvr.c index 2b05ad1a65..53e9c0f9b1 100644 --- a/source/libs/transport/src/transSvr.c +++ b/source/libs/transport/src/transSvr.c @@ -566,6 +566,9 @@ void uvOnRecvCb(uv_stream_t* cli, ssize_t nread, const uv_buf_t* buf) { return; } STrans* pInst = conn->pInst; + int32_t fd = 0; + uv_fileno((uv_handle_t*)cli, &fd); + setsockopt(fd, IPPROTO_TCP, TCP_QUICKACK, (int[]){1}, sizeof(int)); SConnBuffer* pBuf = &conn->readBuf; if (nread > 0) { diff --git a/sql0 b/sql0 new file mode 100644 index 0000000000..02a6f5d7fb --- /dev/null +++ b/sql0 @@ -0,0 +1,140 @@ +974:09/09 18:52:59.433846 00166866 C TSC 0x6 new Request from connObj:0x2, current:1, app current:1, total:5, reqId:0x987bae6a58a90008 975:09/09 18:52:59.433871 00166866 C TSC 0x6 SQL: select * from test.sp;, reqId:0x987bae6a58a90008 +977:09/09 18:52:59.433972 00166866 C QRY QID:0x987bae6a58a90008 the 0th task type [get db vgroup] initialized, dbFName:1.test +978:09/09 18:52:59.433978 00166866 C QRY QID:0x987bae6a58a90008 the 1th task type [bget table meta] initialized, dbNum:1, tbNum:1 +979:09/09 18:52:59.433982 00166866 C QRY QID:0x987bae6a58a90008 the 2th task type [bget table hash] initialized, dbNum:1, tbNum:1 +980:09/09 18:52:59.433986 00166866 C QRY QID:0x987bae6a58a90008 the 3th task type [get user] initialized, user:root +981:09/09 18:52:59.433991 00166866 C QRY QID:0x987bae6a58a90008, jobId: 0x5 initialized, task num 5, forceUpdate 0, elapsed time:0.03 ms +982:09/09 18:52:59.434002 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [0th] task +985:09/09 18:52:59.434031 00166866 C QRY QID:0x987bae6a58a90008 task 0 end with res success +986:09/09 18:52:59.434036 00166866 C QRY QID:0x987bae6a58a90008 task done: 1, total: 5 +987:09/09 18:52:59.434039 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [1th] task +990:09/09 18:52:59.434053 00166866 C QRY QID:0x987bae6a58a90008 task 1 end with res success +991:09/09 18:52:59.434056 00166866 C QRY QID:0x987bae6a58a90008 task done: 2, total: 5 +992:09/09 18:52:59.434059 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [2th] task +995:09/09 18:52:59.434072 00166866 C QRY QID:0x987bae6a58a90008 task 2 end with res success +996:09/09 18:52:59.434075 00166866 C QRY QID:0x987bae6a58a90008 task done: 3, total: 5 +997:09/09 18:52:59.434078 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [3th] task +1000:09/09 18:52:59.434090 00166866 C QRY QID:0x987bae6a58a90008 task 3 end with res success +1001:09/09 18:52:59.434104 00166866 C QRY QID:0x987bae6a58a90008 task done: 4, total: 5 +1002:09/09 18:52:59.434108 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [4th] task +1003:09/09 18:52:59.434114 00166866 C QRY QID:0x987bae6a58a90008 task 4 end with res success +1004:09/09 18:52:59.434170 00166842 C QRY QID:0x987bae6a58a90008 ctg start to call user cb with rsp success +1005:09/09 18:52:59.434187 00166842 C QRY 0x6 start to semantic analysis, reqId:0x987bae6a58a90008 +1006:09/09 18:52:59.434337 00166842 C TSC 0x987bae6a58a90008 vnode policy, use vnode list, num:2 +1008:09/09 18:52:59.434346 00166842 C QRY QID:0x987bae6a58a90008 set job levelIdx to 1 +1009:09/09 18:52:59.434352 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 task initialized, max times 6:6 +1010:09/09 18:52:59.434355 00166842 C QRY QID:0x987bae6a58a90008 level 0 initialized, taskNum:1 +1011:09/09 18:52:59.434358 00166842 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:-1 task initialized, max times 6:12 +1012:09/09 18:52:59.434360 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:-1 task initialized, max times 6:12 +1013:09/09 18:52:59.434361 00166842 C QRY QID:0x987bae6a58a90008 level 1 initialized, taskNum:2 +1014:09/09 18:52:59.434363 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 children info, the 0 child TID 0x7 +1015:09/09 18:52:59.434365 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 children info, the 1 child TID 0x8 +1016:09/09 18:52:59.434366 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 level:0, parentNum:0, childNum:2 +1017:09/09 18:52:59.434367 00166842 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:-1 parents info, the 0 parent TID 0x6 +1018:09/09 18:52:59.434368 00166842 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:-1 level:1, parentNum:1, childNum:0 +1019:09/09 18:52:59.434369 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:-1 parents info, the 0 parent TID 0x6 +1020:09/09 18:52:59.434371 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:-1 level:1, parentNum:1, childNum:0 +1021:09/09 18:52:59.434373 00166842 C QRY QID:0x987bae6a58a90008 job refId:0x5 created +1023:09/09 18:52:59.434377 00166842 C QRY QID:0x987bae6a58a90008 job start EXEC operation +1024:09/09 18:52:59.434381 00166842 C QRY QID:0x987bae6a58a90008 job status updated from NULL to INIT +1025:09/09 18:52:59.434382 00166842 C QRY QID:0x987bae6a58a90008 job status updated from INIT to EXECUTING +1026:09/09 18:52:59.434383 00166842 C QRY QID:0x987bae6a58a90008 sch job refId 0x5 started +1027:09/09 18:52:59.434385 00166842 C QRY QID:0x987bae6a58a90008 job no need flow ctrl, totalTableNum:0 +1028:09/09 18:52:59.434410 00166842 C QRY QID:0x987bae6a58a90008 job exec done, job status:EXECUTING, jobId:0x5 +1029:09/09 18:52:59.434414 00166842 C QRY QID:0x987bae6a58a90008 job end EXEC operation with code success +1031:09/09 18:52:59.434417 00166842 C QRY QID:0x987bae6a58a90008 ctg end to call user cb +1032:09/09 18:52:59.434424 00166842 C QRY QID:0x987bae6a58a90008, ctg job 0x5 freed +1035:09/09 18:52:59.434456 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to launch REMOTE task, execId 0, retry 1 +1036:09/09 18:52:59.434458 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to launch REMOTE task, execId 0, retry 1 +1037:09/09 18:52:59.434484 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 task added to execTask list, numOfTasks:1 +1038:09/09 18:52:59.434485 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 task added to execTask list, numOfTasks:2 +1039:09/09 18:52:59.434503 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 use execNode in plan as candidate addr, numOfEps:1 +1040:09/09 18:52:59.434515 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 use execNode in plan as candidate addr, numOfEps:1 +1050:09/09 18:52:59.434576 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 target candidateIdx 0, epInUse 0/1 +1052:09/09 18:52:59.434588 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to send query msg to node[3,localhost,6100], pTrans:0x2, pHandle:0x11 +1054:09/09 18:52:59.434593 00166842 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f65a4003330, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1055:09/09 18:52:59.434595 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 req msg sent, type:769, query +1056:09/09 18:52:59.434597 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 task execNode added, execId:0, handle:0x11 +1059:09/09 18:52:59.434605 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 target candidateIdx 0, epInUse 0/1 +1062:09/09 18:52:59.434666 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to send query msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x12 +1065:09/09 18:52:59.434672 00166843 C RPC TSC send request at thread:00166860, dst:localhost:6100, app:0x7f65a8006120, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1066:09/09 18:52:59.434696 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 req msg sent, type:769, query +1068:09/09 18:52:59.434700 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 task execNode added, execId:0, handle:0x12 +1077:09/09 18:52:59.434797 00166862 C RPC TSC conn 0x7f65bc000c40 query is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:14, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1089:09/09 18:52:59.434934 00166860 C RPC TSC conn 0x7f65d4000c40 query is sent to 127.0.0.1:6100, local info:127.0.0.1:57868, seq:9, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1107:09/09 18:52:59.480608 00166862 C RPC TSC conn 0x7f65bc000c40 query-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57880, len:130, seq:14, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1108:09/09 18:52:59.480658 00166860 C RPC TSC conn 0x7f65d4000c40 query-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57868, len:130, seq:9, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1111:09/09 18:52:59.480728 00166847 C TSC processMsgFromServer handle 0x11, message: query-rsp, size:39, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a580001d +1114:09/09 18:52:59.480779 00166847 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 handle updated to 0x11 for execId 0 +1115:09/09 18:52:59.480795 00166847 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 taskOnSuccess, status:EXECUTING +1116:09/09 18:52:59.480809 00166847 C QRY PLAN: QID:0x987bae6a58a90008 set subplan execution node, groupId:2 +1119:09/09 18:52:59.480832 00166847 C TSC processMsgFromServer handle 0x12, message: query-rsp, size:39, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a580001e +1122:09/09 18:52:59.480854 00166847 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 handle updated to 0x12 for execId 0 +1123:09/09 18:52:59.480863 00166847 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 taskOnSuccess, status:EXECUTING +1124:09/09 18:52:59.480868 00166847 C QRY PLAN: QID:0x987bae6a58a90008 set subplan execution node, groupId:2 +1125:09/09 18:52:59.480872 00166847 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 all 2 children task done, start to launch parent task 0x6 +1129:09/09 18:52:59.480921 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to launch REMOTE task, execId 0, retry 1 +1130:09/09 18:52:59.480927 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 task added to execTask list, numOfTasks:3 +1131:09/09 18:52:59.480959 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 target candidateIdx 0, epInUse 0/1 +1133:09/09 18:52:59.480982 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to send merge-query msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x13 +1135:09/09 18:52:59.480998 00166847 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f6598006b80, gtid:0x987bae6a58a90008:0x31de1d66a580001f +1136:09/09 18:52:59.481028 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 req msg sent, type:771, merge-query +1137:09/09 18:52:59.481035 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 task execNode added, execId:0, handle:0x13 +1143:09/09 18:52:59.481077 00166862 C RPC TSC conn 0x7f65bc000c40 merge-query is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:15, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a580001f +1145:09/09 18:52:59.481938 00166862 C RPC TSC conn 0x7f65bc000c40 merge-query-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57880, len:111, seq:15, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a580001f +1147:09/09 18:52:59.481995 00166850 C TSC processMsgFromServer handle 0x13, message: merge-query-rsp, size:20, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a580001f +1150:09/09 18:52:59.482031 00166850 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 handle updated to 0x13 for execId 0 +1151:09/09 18:52:59.482042 00166850 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 taskOnSuccess, status:EXECUTING +1152:09/09 18:52:59.482049 00166850 C QRY QID:0x987bae6a58a90008 job status updated from EXECUTING to PARTIAL_SUCCEED +1153:09/09 18:52:59.482055 00166850 C QRY QID:0x987bae6a58a90008 execRes dumped, code: success +1154:09/09 18:52:59.482058 00166850 C QRY QID:0x987bae6a58a90008 sch start to invoke exec cb, code: success +1155:09/09 18:52:59.482062 00166850 C TSC 0x6 enter scheduler exec cb, code:success, reqId:0x987bae6a58a90008 +1162:09/09 18:52:59.482157 00166850 C QRY QID:0x987bae6a58a90008 sch end from exec cb, code: success +1168:09/09 18:52:59.482384 00166866 C QRY QID:0x987bae6a58a90008 job start FETCH operation +1169:09/09 18:52:59.482390 00166866 C QRY QID:0x987bae6a58a90008 job status updated from PARTIAL_SUCCEED to FETCHING +1170:09/09 18:52:59.482403 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to send merge-fetch msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x13 +1172:09/09 18:52:59.482426 00166866 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f65943151d0, gtid:0x987bae6a58a90008:0x31de1d66a5800020 +1173:09/09 18:52:59.482452 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 req msg sent, type:779, merge-fetch +1174:09/09 18:52:59.482460 00166866 C QRY QID:0x987bae6a58a90008 job end FETCH operation with code success +1178:09/09 18:52:59.482489 00166862 C RPC TSC conn 0x7f65bc000c40 merge-fetch is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:16, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a5800020 +1180:09/09 18:52:59.482714 00166862 C RPC TSC conn 0x7f65bc000c40 merge-fetch-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57880, len:1110, seq:16, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a5800020 +1182:09/09 18:52:59.482782 00166852 C TSC processMsgFromServer handle 0x13, message: merge-fetch-rsp, size:1019, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a5800020 +1185:09/09 18:52:59.482829 00166852 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 handle updated to 0x13 for execId 0 +1186:09/09 18:52:59.482835 00166852 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 got fetch rsp, rows:42, complete:1 +1187:09/09 18:52:59.482839 00166852 C QRY QID:0x987bae6a58a90008 job status updated from FETCHING to SUCCEED +1188:09/09 18:52:59.482842 00166852 C QRY QID:0x987bae6a58a90008 fetch done, totalRows:42 +1189:09/09 18:52:59.482845 00166852 C QRY QID:0x987bae6a58a90008 sch start to invoke fetch cb, code: success +1190:09/09 18:52:59.482848 00166852 C TSC 0x6 enter scheduler fetch cb, code:0 - success, reqId:0x987bae6a58a90008 +1191:09/09 18:52:59.482858 00166852 C TSC 0x6 fetch results, numOfRows:42 total Rows:42, complete:1, reqId:0x987bae6a58a90008 +1192:09/09 18:52:59.483360 00166852 C QRY QID:0x987bae6a58a90008 sch end from fetch cb, code: success +1196:09/09 18:52:59.483396 00166866 C TSC 0x987bae6a58a90008 taos_free_result start to free query +1198:09/09 18:52:59.483414 00166866 C QRY QID:0x987bae6a58a90008 start to free job 0x5, code:Query killed +1199:09/09 18:52:59.483419 00166866 C QRY QID:0x987bae6a58a90008 job status updated from SUCCEED to DROPPING +1200:09/09 18:52:59.483423 00166866 C QRY QID:0x987bae6a58a90008 job errCode updated to Query killed +1201:09/09 18:52:59.483426 00166866 C QRY QID:0x987bae6a58a90008 job failed with error Query killed +1202:09/09 18:52:59.483428 00166866 C QRY QID:0x987bae6a58a90008 job not in any operation, no need to post job res, status:DROPPING +1203:09/09 18:52:59.483432 00166866 C QRY QID:0x987bae6a58a90008 job removed from jobRef list, refId:0x5 +1205:09/09 18:52:59.483437 00166866 C QRY QID:0x987bae6a58a90008 begin to free sch job, refId:0x5, pointer:0x7f65a400d4a0 +1206:09/09 18:52:59.483449 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to send drop-task msg to node[3,localhost,6100], pTrans:0x2, pHandle:0x11 +1208:09/09 18:52:59.483462 00166866 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f6594302920, gtid:0x987bae6a58a90008:0x31de1d66a5800021 +1209:09/09 18:52:59.483487 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 req msg sent, type:783, drop-task +1210:09/09 18:52:59.483494 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to drop task's 0th execNode +1211:09/09 18:52:59.483498 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 task has been dropped on 1 exec nodes +1212:09/09 18:52:59.483505 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to send drop-task msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x13 +1214:09/09 18:52:59.483515 00166866 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f65943031b0, gtid:0x987bae6a58a90008:0x31de1d66a5800022 +1215:09/09 18:52:59.483519 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 req msg sent, type:783, drop-task +1216:09/09 18:52:59.483521 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to drop task's 0th execNode +1217:09/09 18:52:59.483524 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 task has been dropped on 1 exec nodes +1218:09/09 18:52:59.483528 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to send drop-task msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x12 +1220:09/09 18:52:59.483535 00166866 C RPC TSC send request at thread:00166860, dst:localhost:6100, app:0x7f659430e900, gtid:0x987bae6a58a90008:0x31de1d66a5800023 +1221:09/09 18:52:59.483560 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 req msg sent, type:783, drop-task +1222:09/09 18:52:59.483566 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to drop task's 0th execNode +1223:09/09 18:52:59.483570 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 task has been dropped on 1 exec nodes +1226:09/09 18:52:59.483597 00166860 C RPC TSC conn 0x7f65d4000c40 drop-task is sent to 127.0.0.1:6100, local info:127.0.0.1:57868, seq:10, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a5800023 +1228:09/09 18:52:59.483610 00166866 C QRY QID:0x987bae6a58a90008 sch job freed, refId:0x5, pointer:0x7f65a400d4a0 +1230:09/09 18:52:59.483622 00166866 C TSC 0x6 free Request from connObj: 0x2, reqId:0x987bae6a58a90008 elapsed:49.78 ms, current:0, app current:0 +1234:09/09 18:52:59.483739 00166862 C RPC TSC conn 0x7f65bc000c40 drop-task is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:17, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a5800021 +1236:09/09 18:52:59.483813 00166860 C RPC TSC conn 0x7f65d4000c40 receive release req, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1242:09/09 18:52:59.483854 00166862 C RPC TSC conn 0x7f65bc000c40 drop-task is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:18, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a5800022 +1246:09/09 18:52:59.484011 00166862 C RPC TSC conn 0x7f65bc000c40 receive release req, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1250:09/09 18:52:59.484124 00166862 C RPC TSC conn 0x7f65bc000c40 receive release req, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a580001f diff --git a/sql1 b/sql1 new file mode 100644 index 0000000000..6924fc9a2a --- /dev/null +++ b/sql1 @@ -0,0 +1,141 @@ +974:09/09 18:52:59.433846 00166866 C TSC 0x6 new Request from connObj:0x2, current:1, app current:1, total:5, reqId:0x987bae6a58a90008 +975:09/09 18:52:59.433871 00166866 C TSC 0x6 SQL: select * from test.sp;, reqId:0x987bae6a58a90008 +977:09/09 18:52:59.433972 00166866 C QRY QID:0x987bae6a58a90008 the 0th task type [get db vgroup] initialized, dbFName:1.test +978:09/09 18:52:59.433978 00166866 C QRY QID:0x987bae6a58a90008 the 1th task type [bget table meta] initialized, dbNum:1, tbNum:1 +979:09/09 18:52:59.433982 00166866 C QRY QID:0x987bae6a58a90008 the 2th task type [bget table hash] initialized, dbNum:1, tbNum:1 +980:09/09 18:52:59.433986 00166866 C QRY QID:0x987bae6a58a90008 the 3th task type [get user] initialized, user:root +981:09/09 18:52:59.433991 00166866 C QRY QID:0x987bae6a58a90008, jobId: 0x5 initialized, task num 5, forceUpdate 0, elapsed time:0.03 ms +982:09/09 18:52:59.434002 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [0th] task +985:09/09 18:52:59.434031 00166866 C QRY QID:0x987bae6a58a90008 task 0 end with res success +986:09/09 18:52:59.434036 00166866 C QRY QID:0x987bae6a58a90008 task done: 1, total: 5 +987:09/09 18:52:59.434039 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [1th] task +990:09/09 18:52:59.434053 00166866 C QRY QID:0x987bae6a58a90008 task 1 end with res success +991:09/09 18:52:59.434056 00166866 C QRY QID:0x987bae6a58a90008 task done: 2, total: 5 +992:09/09 18:52:59.434059 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [2th] task +995:09/09 18:52:59.434072 00166866 C QRY QID:0x987bae6a58a90008 task 2 end with res success +996:09/09 18:52:59.434075 00166866 C QRY QID:0x987bae6a58a90008 task done: 3, total: 5 +997:09/09 18:52:59.434078 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [3th] task +1000:09/09 18:52:59.434090 00166866 C QRY QID:0x987bae6a58a90008 task 3 end with res success +1001:09/09 18:52:59.434104 00166866 C QRY QID:0x987bae6a58a90008 task done: 4, total: 5 +1002:09/09 18:52:59.434108 00166866 C QRY QID:0x987bae6a58a90008 ctg launch [4th] task +1003:09/09 18:52:59.434114 00166866 C QRY QID:0x987bae6a58a90008 task 4 end with res success +1004:09/09 18:52:59.434170 00166842 C QRY QID:0x987bae6a58a90008 ctg start to call user cb with rsp success +1005:09/09 18:52:59.434187 00166842 C QRY 0x6 start to semantic analysis, reqId:0x987bae6a58a90008 +1006:09/09 18:52:59.434337 00166842 C TSC 0x987bae6a58a90008 vnode policy, use vnode list, num:2 +1008:09/09 18:52:59.434346 00166842 C QRY QID:0x987bae6a58a90008 set job levelIdx to 1 +1009:09/09 18:52:59.434352 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 task initialized, max times 6:6 +1010:09/09 18:52:59.434355 00166842 C QRY QID:0x987bae6a58a90008 level 0 initialized, taskNum:1 +1011:09/09 18:52:59.434358 00166842 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:-1 task initialized, max times 6:12 +1012:09/09 18:52:59.434360 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:-1 task initialized, max times 6:12 +1013:09/09 18:52:59.434361 00166842 C QRY QID:0x987bae6a58a90008 level 1 initialized, taskNum:2 +1014:09/09 18:52:59.434363 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 children info, the 0 child TID 0x7 +1015:09/09 18:52:59.434365 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 children info, the 1 child TID 0x8 +1016:09/09 18:52:59.434366 00166842 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:-1 level:0, parentNum:0, childNum:2 +1017:09/09 18:52:59.434367 00166842 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:-1 parents info, the 0 parent TID 0x6 +1018:09/09 18:52:59.434368 00166842 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:-1 level:1, parentNum:1, childNum:0 +1019:09/09 18:52:59.434369 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:-1 parents info, the 0 parent TID 0x6 +1020:09/09 18:52:59.434371 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:-1 level:1, parentNum:1, childNum:0 +1021:09/09 18:52:59.434373 00166842 C QRY QID:0x987bae6a58a90008 job refId:0x5 created +1023:09/09 18:52:59.434377 00166842 C QRY QID:0x987bae6a58a90008 job start EXEC operation +1024:09/09 18:52:59.434381 00166842 C QRY QID:0x987bae6a58a90008 job status updated from NULL to INIT +1025:09/09 18:52:59.434382 00166842 C QRY QID:0x987bae6a58a90008 job status updated from INIT to EXECUTING +1026:09/09 18:52:59.434383 00166842 C QRY QID:0x987bae6a58a90008 sch job refId 0x5 started +1027:09/09 18:52:59.434385 00166842 C QRY QID:0x987bae6a58a90008 job no need flow ctrl, totalTableNum:0 +1028:09/09 18:52:59.434410 00166842 C QRY QID:0x987bae6a58a90008 job exec done, job status:EXECUTING, jobId:0x5 +1029:09/09 18:52:59.434414 00166842 C QRY QID:0x987bae6a58a90008 job end EXEC operation with code success +1031:09/09 18:52:59.434417 00166842 C QRY QID:0x987bae6a58a90008 ctg end to call user cb +1032:09/09 18:52:59.434424 00166842 C QRY QID:0x987bae6a58a90008, ctg job 0x5 freed +1035:09/09 18:52:59.434456 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to launch REMOTE task, execId 0, retry 1 +1036:09/09 18:52:59.434458 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to launch REMOTE task, execId 0, retry 1 +1037:09/09 18:52:59.434484 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 task added to execTask list, numOfTasks:1 +1038:09/09 18:52:59.434485 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 task added to execTask list, numOfTasks:2 +1039:09/09 18:52:59.434503 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 use execNode in plan as candidate addr, numOfEps:1 +1040:09/09 18:52:59.434515 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 use execNode in plan as candidate addr, numOfEps:1 +1050:09/09 18:52:59.434576 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 target candidateIdx 0, epInUse 0/1 +1052:09/09 18:52:59.434588 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to send query msg to node[3,localhost,6100], pTrans:0x2, pHandle:0x11 +1054:09/09 18:52:59.434593 00166842 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f65a4003330, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1055:09/09 18:52:59.434595 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 req msg sent, type:769, query +1056:09/09 18:52:59.434597 00166842 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 task execNode added, execId:0, handle:0x11 +1059:09/09 18:52:59.434605 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 target candidateIdx 0, epInUse 0/1 +1062:09/09 18:52:59.434666 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to send query msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x12 +1065:09/09 18:52:59.434672 00166843 C RPC TSC send request at thread:00166860, dst:localhost:6100, app:0x7f65a8006120, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1066:09/09 18:52:59.434696 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 req msg sent, type:769, query +1068:09/09 18:52:59.434700 00166843 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 task execNode added, execId:0, handle:0x12 +1077:09/09 18:52:59.434797 00166862 C RPC TSC conn 0x7f65bc000c40 query is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:14, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1089:09/09 18:52:59.434934 00166860 C RPC TSC conn 0x7f65d4000c40 query is sent to 127.0.0.1:6100, local info:127.0.0.1:57868, seq:9, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1107:09/09 18:52:59.480608 00166862 C RPC TSC conn 0x7f65bc000c40 query-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57880, len:130, seq:14, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1108:09/09 18:52:59.480658 00166860 C RPC TSC conn 0x7f65d4000c40 query-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57868, len:130, seq:9, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1111:09/09 18:52:59.480728 00166847 C TSC processMsgFromServer handle 0x11, message: query-rsp, size:39, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a580001d +1114:09/09 18:52:59.480779 00166847 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 handle updated to 0x11 for execId 0 +1115:09/09 18:52:59.480795 00166847 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 taskOnSuccess, status:EXECUTING +1116:09/09 18:52:59.480809 00166847 C QRY PLAN: QID:0x987bae6a58a90008 set subplan execution node, groupId:2 +1119:09/09 18:52:59.480832 00166847 C TSC processMsgFromServer handle 0x12, message: query-rsp, size:39, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a580001e +1122:09/09 18:52:59.480854 00166847 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 handle updated to 0x12 for execId 0 +1123:09/09 18:52:59.480863 00166847 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 taskOnSuccess, status:EXECUTING +1124:09/09 18:52:59.480868 00166847 C QRY PLAN: QID:0x987bae6a58a90008 set subplan execution node, groupId:2 +1125:09/09 18:52:59.480872 00166847 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 all 2 children task done, start to launch parent task 0x6 +1129:09/09 18:52:59.480921 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to launch REMOTE task, execId 0, retry 1 +1130:09/09 18:52:59.480927 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 task added to execTask list, numOfTasks:3 +1131:09/09 18:52:59.480959 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 target candidateIdx 0, epInUse 0/1 +1133:09/09 18:52:59.480982 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to send merge-query msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x13 +1135:09/09 18:52:59.480998 00166847 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f6598006b80, gtid:0x987bae6a58a90008:0x31de1d66a580001f +1136:09/09 18:52:59.481028 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 req msg sent, type:771, merge-query +1137:09/09 18:52:59.481035 00166847 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 task execNode added, execId:0, handle:0x13 +1143:09/09 18:52:59.481077 00166862 C RPC TSC conn 0x7f65bc000c40 merge-query is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:15, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a580001f +1145:09/09 18:52:59.481938 00166862 C RPC TSC conn 0x7f65bc000c40 merge-query-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57880, len:111, seq:15, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a580001f +1147:09/09 18:52:59.481995 00166850 C TSC processMsgFromServer handle 0x13, message: merge-query-rsp, size:20, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a580001f +1150:09/09 18:52:59.482031 00166850 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 handle updated to 0x13 for execId 0 +1151:09/09 18:52:59.482042 00166850 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 taskOnSuccess, status:EXECUTING +1152:09/09 18:52:59.482049 00166850 C QRY QID:0x987bae6a58a90008 job status updated from EXECUTING to PARTIAL_SUCCEED +1153:09/09 18:52:59.482055 00166850 C QRY QID:0x987bae6a58a90008 execRes dumped, code: success +1154:09/09 18:52:59.482058 00166850 C QRY QID:0x987bae6a58a90008 sch start to invoke exec cb, code: success +1155:09/09 18:52:59.482062 00166850 C TSC 0x6 enter scheduler exec cb, code:success, reqId:0x987bae6a58a90008 +1162:09/09 18:52:59.482157 00166850 C QRY QID:0x987bae6a58a90008 sch end from exec cb, code: success +1168:09/09 18:52:59.482384 00166866 C QRY QID:0x987bae6a58a90008 job start FETCH operation +1169:09/09 18:52:59.482390 00166866 C QRY QID:0x987bae6a58a90008 job status updated from PARTIAL_SUCCEED to FETCHING +1170:09/09 18:52:59.482403 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to send merge-fetch msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x13 +1172:09/09 18:52:59.482426 00166866 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f65943151d0, gtid:0x987bae6a58a90008:0x31de1d66a5800020 +1173:09/09 18:52:59.482452 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 req msg sent, type:779, merge-fetch +1174:09/09 18:52:59.482460 00166866 C QRY QID:0x987bae6a58a90008 job end FETCH operation with code success +1178:09/09 18:52:59.482489 00166862 C RPC TSC conn 0x7f65bc000c40 merge-fetch is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:16, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a5800020 +1180:09/09 18:52:59.482714 00166862 C RPC TSC conn 0x7f65bc000c40 merge-fetch-rsp received from 127.0.0.1:6100, local info:127.0.0.1:57880, len:1110, seq:16, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a5800020 +1182:09/09 18:52:59.482782 00166852 C TSC processMsgFromServer handle 0x13, message: merge-fetch-rsp, size:1019, code: success, gtid: 0x987bae6a58a90008:0x31de1d66a5800020 +1185:09/09 18:52:59.482829 00166852 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 handle updated to 0x13 for execId 0 +1186:09/09 18:52:59.482835 00166852 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 got fetch rsp, rows:42, complete:1 +1187:09/09 18:52:59.482839 00166852 C QRY QID:0x987bae6a58a90008 job status updated from FETCHING to SUCCEED +1188:09/09 18:52:59.482842 00166852 C QRY QID:0x987bae6a58a90008 fetch done, totalRows:42 +1189:09/09 18:52:59.482845 00166852 C QRY QID:0x987bae6a58a90008 sch start to invoke fetch cb, code: success +1190:09/09 18:52:59.482848 00166852 C TSC 0x6 enter scheduler fetch cb, code:0 - success, reqId:0x987bae6a58a90008 +1191:09/09 18:52:59.482858 00166852 C TSC 0x6 fetch results, numOfRows:42 total Rows:42, complete:1, reqId:0x987bae6a58a90008 +1192:09/09 18:52:59.483360 00166852 C QRY QID:0x987bae6a58a90008 sch end from fetch cb, code: success +1196:09/09 18:52:59.483396 00166866 C TSC 0x987bae6a58a90008 taos_free_result start to free query +1198:09/09 18:52:59.483414 00166866 C QRY QID:0x987bae6a58a90008 start to free job 0x5, code:Query killed +1199:09/09 18:52:59.483419 00166866 C QRY QID:0x987bae6a58a90008 job status updated from SUCCEED to DROPPING +1200:09/09 18:52:59.483423 00166866 C QRY QID:0x987bae6a58a90008 job errCode updated to Query killed +1201:09/09 18:52:59.483426 00166866 C QRY QID:0x987bae6a58a90008 job failed with error Query killed +1202:09/09 18:52:59.483428 00166866 C QRY QID:0x987bae6a58a90008 job not in any operation, no need to post job res, status:DROPPING +1203:09/09 18:52:59.483432 00166866 C QRY QID:0x987bae6a58a90008 job removed from jobRef list, refId:0x5 +1205:09/09 18:52:59.483437 00166866 C QRY QID:0x987bae6a58a90008 begin to free sch job, refId:0x5, pointer:0x7f65a400d4a0 +1206:09/09 18:52:59.483449 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to send drop-task msg to node[3,localhost,6100], pTrans:0x2, pHandle:0x11 +1208:09/09 18:52:59.483462 00166866 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f6594302920, gtid:0x987bae6a58a90008:0x31de1d66a5800021 +1209:09/09 18:52:59.483487 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 req msg sent, type:783, drop-task +1210:09/09 18:52:59.483494 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 start to drop task's 0th execNode +1211:09/09 18:52:59.483498 00166866 C QRY QID:0x987bae6a58a90008,TID:0x8,EID:0 task has been dropped on 1 exec nodes +1212:09/09 18:52:59.483505 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to send drop-task msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x13 +1214:09/09 18:52:59.483515 00166866 C RPC TSC send request at thread:00166862, dst:localhost:6100, app:0x7f65943031b0, gtid:0x987bae6a58a90008:0x31de1d66a5800022 +1215:09/09 18:52:59.483519 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 req msg sent, type:783, drop-task +1216:09/09 18:52:59.483521 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 start to drop task's 0th execNode +1217:09/09 18:52:59.483524 00166866 C QRY QID:0x987bae6a58a90008,TID:0x6,EID:0 task has been dropped on 1 exec nodes +1218:09/09 18:52:59.483528 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to send drop-task msg to node[2,localhost,6100], pTrans:0x2, pHandle:0x12 +1220:09/09 18:52:59.483535 00166866 C RPC TSC send request at thread:00166860, dst:localhost:6100, app:0x7f659430e900, gtid:0x987bae6a58a90008:0x31de1d66a5800023 +1221:09/09 18:52:59.483560 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 req msg sent, type:783, drop-task +1222:09/09 18:52:59.483566 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 start to drop task's 0th execNode +1223:09/09 18:52:59.483570 00166866 C QRY QID:0x987bae6a58a90008,TID:0x7,EID:0 task has been dropped on 1 exec nodes +1226:09/09 18:52:59.483597 00166860 C RPC TSC conn 0x7f65d4000c40 drop-task is sent to 127.0.0.1:6100, local info:127.0.0.1:57868, seq:10, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a5800023 +1228:09/09 18:52:59.483610 00166866 C QRY QID:0x987bae6a58a90008 sch job freed, refId:0x5, pointer:0x7f65a400d4a0 +1230:09/09 18:52:59.483622 00166866 C TSC 0x6 free Request from connObj: 0x2, reqId:0x987bae6a58a90008 elapsed:49.78 ms, current:0, app current:0 +1234:09/09 18:52:59.483739 00166862 C RPC TSC conn 0x7f65bc000c40 drop-task is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:17, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a5800021 +1236:09/09 18:52:59.483813 00166860 C RPC TSC conn 0x7f65d4000c40 receive release req, qid:18, gtid:0x987bae6a58a90008:0x31de1d66a580001e +1242:09/09 18:52:59.483854 00166862 C RPC TSC conn 0x7f65bc000c40 drop-task is sent to 127.0.0.1:6100, local info:127.0.0.1:57880, seq:18, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a5800022 +1246:09/09 18:52:59.484011 00166862 C RPC TSC conn 0x7f65bc000c40 receive release req, qid:17, gtid:0x987bae6a58a90008:0x31de1d66a580001d +1250:09/09 18:52:59.484124 00166862 C RPC TSC conn 0x7f65bc000c40 receive release req, qid:19, gtid:0x987bae6a58a90008:0x31de1d66a580001f