Trace开启方式
修改配置文件或登录到数据库set global 参数名=参数值方式进行设置。
gbase_sql_trace=1 # 默认是0，表示关闭，设置为1即可开启。
gbase_sql_trace_level=3 #trace等级越高越详细。默认为3，绝大部分情况足够，极个别情况可设置为更大值。如7或者15
SQL语句
示例语句为TPC-H SQL21（10 Scale），测试环境CPU 4core，打开并行
selects_name,count(*) as numwait
from
supplier,lineitem l1,orders,nation
where
s_suppkey = l1.l_suppkey
and o_orderkey = l1.l_orderkey
and o_orderstatus = ‘F’
and l1.l_receiptdate > l1.l_commitdate
and exists (select*from lineitem l2 where l2.l_orderkey = l1.l_orderkey and l2.l_suppkey <> l1.l_suppkey)
and not exists (select* from lineitem l3 where l3.l_orderkey = l1.l_orderkey and l3.l_suppkey <> l1.l_suppkey
and l3.l_receiptdate > l3.l_commitdate)
and s_nationkey = n_nationkey and n_name = ‘SAUDI ARABIA’
group by s_name
order by numwait desc, s_name
limit 100;
trace信息
注：为了方便阅读，这里不列出资源监控部分，下一节专门说明。本文档最后一节附有完整的SQL trace（level=3的输出）
2023-05-17 16:08:36.324 Start Query Execution
2023-05-17 16:08:36.326 BEGIN Smart Scan — 智能索引过滤开始
2023-05-17 16:08:36.328 T0: total 2 DC, found 2 DC to scan(with 0 FULL DC). –- T0表：共2个DC，全部命中，需要扫描（无Full状态）
2023-05-17 16:08:36.328 T1: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:08:36.328 T2: total 229 DC, found 229 DC to scan(with 0 FULL DC).
2023-05-17 16:08:36.328 T3: total 1 DC, found 1 DC to scan(with 0 FULL DC).
2023-05-17 16:08:36.328 BEGIN Scan — 表扫描过滤开始
2023-05-17 16:08:36.328 using parallel scan — 第一个过滤条件开始，使用并行scan
2023-05-17 16:08:36.339 merge row num: 1 — 第一个过滤条件结束，结果为 1 row
2023-05-17 16:08:36.339 using parallel scan
2023-05-17 16:08:37.592 merge row num: 7309184
2023-05-17 16:08:37.592 using parallel scan
2023-05-17 16:08:45.483 merge row num: 37929348
2023-05-17 16:08:45.484 using parallel scan — 这个过滤条件是exists子查询
2023-05-17 16:08:45.496 do not support parallel scan , run normal scan — 相关子查询不适用普通的并行scan
2023-05-17 16:08:45.498 using serially scan
2023-05-17 16:08:45.509 | BEGIN Smart Scan — 子查询内部的智能索引过滤开始(一个’|’代表一层子查询，嵌套累加)
2023-05-17 16:08:45.509 | T0: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:08:45.509 | T1: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:08:45.509 | BEGIN Scan
2023-05-17 16:08:45.509 | T0: total 916 DC, found 916 DC after scan(with 916 FULL DC).
2023-05-17 16:08:45.510 | T1: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:08:45.510 | BEGIN Join — exists相关子查询优化为semi-join, join开始
2023-05-17 16:08:45.524 | divide to 4 blocks(using round-robin): 9486804, 9491138, 9489208, 9462198. –- 并行join数据分块(下面针对线程(0)进行说明)
2023-05-17 16:08:52.992 | (0)created hash on 7372800/9486804 rows already. –- 由于hj_buffer不足以装下hashtab，需要多趟hash
2023-05-17 16:08:53.255 | (1)created hash on 7372800/9491138 rows already.
2023-05-17 16:08:54.128 | (3)created hash on 7372800/9462198 rows already.
2023-05-17 16:08:54.187 | (2)created hash on 7372800/9489208 rows already.
2023-05-17 16:09:15.648 | (1)scanned 12124160 rows, and produced 29490678 rows already.
2023-05-17 16:09:16.028 | (0)scanned 12124160 rows, and produced 29495308 rows already. –- 线程0扫描了12124160条数据，共匹配上29495308条结果
2023-05-17 16:09:16.753 | (1)created hash on all 9491138 rows already.
2023-05-17 16:09:17.115 | (0)created hash on all 9486804 rows already. — 第二趟hash，在剩余的数据上建hashtab(9486804 – 7372800)
2023-05-17 16:09:21.793 | (1)scanned 3866624 rows, and produced 37965426 rows already.
2023-05-17 16:09:21.793 | (1)skipped 86.68% DCs by smart index.
2023-05-17 16:09:21.794 | (1)inner join(T0 – T1), using [semi]hash join, produced 9151948 rows.
2023-05-17 16:09:22.202 | (0)scanned 3866624 rows, and produced 37947533 rows already.
2023-05-17 16:09:22.202 | (0)skipped 86.68% DCs by smart index. — 智能索引直接过滤掉86.68%的DC，join时不需要全部扫描
2023-05-17 16:09:22.203 | (0)inner join(T0 – T1), using [semi]hash join, produced 9147665 rows. — 线程0最终共得到9147665条结果（去重之后）
2023-05-17 16:09:23.060 | (3)scanned 12058624 rows, and produced 29474728 rows already.
2023-05-17 16:09:24.038 | (3)created hash on all 9462198 rows already.
2023-05-17 16:09:24.687 | (2)scanned 12713984 rows, and produced 29482666 rows already.
2023-05-17 16:09:25.873 | (2)created hash on all 9489208 rows already.
2023-05-17 16:09:28.993 | (3)scanned 3756164 rows, and produced 37838709 rows already.
2023-05-17 16:09:28.993 | (3)skipped 86.79% DCs by smart index.
2023-05-17 16:09:28.993 | (3)inner join(T0 – T1), using [semi]hash join, produced 9124258 rows.
2023-05-17 16:09:32.365 | (2)scanned 3801088 rows, and produced 37939475 rows already.
2023-05-17 16:09:32.366 | (2)skipped 86.24% DCs by smart index.
2023-05-17 16:09:32.366 | (2)inner join(T0 – T1), using [semi]hash join, produced 9150117 rows.
2023-05-17 16:09:32.374 | merge row num: 36573988 — exists相关子查询结束，最终结果36573988条
2023-05-17 16:09:36.093 using parallel scan — 开始not exists相关子查询，与exists相关子查询类似，不再重复
2023-05-17 16:09:36.103 do not support parallel scan , run normal scan
2023-05-17 16:09:36.104 using serially scan
2023-05-17 16:09:36.112 | BEGIN Smart Scan
2023-05-17 16:09:36.113 | T0: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:09:36.113 | T1: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:09:36.113 | BEGIN Scan
2023-05-17 16:09:36.113 | using parallel scan
2023-05-17 16:09:41.290 | merge row num: 37929348
2023-05-17 16:09:41.291 | T0: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:09:41.291 | T1: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:09:41.291 | BEGIN Join
2023-05-17 16:09:41.349 | divide to 4 blocks(using round-robin): 9147665, 9151948, 9150117, 9124258.
2023-05-17 16:09:47.946 | (0)created hash on 7372800/9147665 rows already.
2023-05-17 16:09:48.056 | (1)created hash on 7372800/9151948 rows already.
2023-05-17 16:09:49.250 | (2)created hash on 7372800/9150117 rows already.
2023-05-17 16:09:49.428 | (3)created hash on 7372800/9124258 rows already.
2023-05-17 16:10:04.565 | (0)scanned 7829735 rows, and produced 19340793 rows already.
2023-05-17 16:10:05.399 | (0)created hash on all 9147665 rows already.
2023-05-17 16:10:05.427 | (1)scanned 8123447 rows, and produced 19342658 rows already.
2023-05-17 16:10:06.255 | (1)created hash on all 9151948 rows already.
2023-05-17 16:10:08.554 | (0)scanned 2320546 rows, and produced 23993387 rows already.
2023-05-17 16:10:08.554 | (0)skipped 86.62% DCs by smart index.
2023-05-17 16:10:08.556 | (0)inner join(T0 – T1), using [semi]hash join, produced 8641651 rows.
2023-05-17 16:10:09.345 | (1)scanned 1947652 rows, and produced 24007961 rows already.
2023-05-17 16:10:09.345 | (1)skipped 86.73% DCs by smart index.
2023-05-17 16:10:09.347 | (1)inner join(T0 – T1), using [semi]hash join, produced 8648760 rows.
2023-05-17 16:10:10.935 | (2)scanned 8163555 rows, and produced 19333658 rows already.
2023-05-17 16:10:11.742 | (2)created hash on all 9150117 rows already.
2023-05-17 16:10:11.941 | (3)scanned 8123595 rows, and produced 19328057 rows already.
2023-05-17 16:10:12.888 | (3)created hash on all 9124258 rows already.
2023-05-17 16:10:15.003 | (2)scanned 2237629 rows, and produced 23990497 rows already.
2023-05-17 16:10:15.003 | (2)skipped 86.29% DCs by smart index.
2023-05-17 16:10:15.005 | (2)inner join(T0 – T1), using [semi]hash join, produced 8645279 rows.
2023-05-17 16:10:16.883 | (3)scanned 1919161 rows, and produced 23924421 rows already.
2023-05-17 16:10:16.883 | (3)skipped 86.73% DCs by smart index.
2023-05-17 16:10:16.886 | (3)inner join(T0 – T1), using [semi]hash join, produced 8621374 rows.
2023-05-17 16:10:16.896 | merge row num: 34557064 — not exists相关子查询结束，最终结果34557064行
2023-05-17 16:10:22.821 T0: total 2 DC, found 2 DC after scan(with 2 FULL DC). — 表扫描最终结果，T0表所有DC数据全部命中
2023-05-17 16:10:22.821 T1: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:10:22.821 T2: total 229 DC, found 229 DC after scan(with 0 FULL DC).
2023-05-17 16:10:22.821 T3: total 1 DC, found 1 DC after scan(with 0 FULL DC).
2023-05-17 16:10:22.821 BEGIN Join — 开始join（主查询部分的）
2023-05-17 16:10:22.821 divide to 2 blocks(using round-robin): 65536, 34464.
2023-05-17 16:10:22.822 (1)created hash on all 1 rows already.
2023-05-17 16:10:22.822 (0)created hash on all 1 rows already.
2023-05-17 16:10:22.830 (1)scanned 34464 rows, and produced 1371 rows already.
2023-05-17 16:10:22.831 (1)inner join(T0 – T3), using hash join, produced 1371 rows.
2023-05-17 16:10:22.835 (0)scanned 65536 rows, and produced 2639 rows already.
2023-05-17 16:10:22.835 (0)inner join(T0 – T3), using hash join, produced 2639 rows.
2023-05-17 16:10:22.835 merge row num: 4010 — T0与T3的join结束，结果4010行
2023-05-17 16:10:22.842 divide to 4 blocks(using round-robin): 506014, 503188, 504838, 502884.
2023-05-17 16:10:22.846 (1)created hash on all 4010 rows already.
2023-05-17 16:10:22.846 (3)created hash on all 4010 rows already.
2023-05-17 16:10:22.846 (2)created hash on all 4010 rows already.
2023-05-17 16:10:22.850 (0)created hash on all 4010 rows already.
2023-05-17 16:10:23.049 (3)scanned 502884 rows, and produced 20257 rows already.
2023-05-17 16:10:23.051 (1)scanned 503188 rows, and produced 20303 rows already.
2023-05-17 16:10:23.065 (3)inner join(T0 – T1), using hash join, produced 20257 rows.
2023-05-17 16:10:23.066 (1)inner join(T0 – T1), using hash join, produced 20303 rows.
2023-05-17 16:10:23.101 (2)scanned 504838 rows, and produced 19986 rows already.
2023-05-17 16:10:23.117 (2)inner join(T0 – T1), using hash join, produced 19986 rows.
2023-05-17 16:10:23.117 (0)scanned 506014 rows, and produced 20499 rows already.
2023-05-17 16:10:23.138 (0)inner join(T0 – T1), using hash join, produced 20499 rows.
2023-05-17 16:10:23.145 merge row num: 81045 — T0与T1的join结束，结果81045行
2023-05-17 16:10:23.149 divide to 4 blocks(using round-robin): 1851538, 1820776, 1819130, 1817740.
2023-05-17 16:10:23.230 (0)created hash on all 81045 rows already.
2023-05-17 16:10:23.230 (2)created hash on all 81045 rows already.
2023-05-17 16:10:23.239 (3)created hash on all 81045 rows already.
2023-05-17 16:10:23.239 (1)created hash on all 81045 rows already.
2023-05-17 16:10:24.428 (0)scanned 1851538 rows, and produced 10127 rows already.
2023-05-17 16:10:24.432 (0)inner join(T1 – T2), using hash join, produced 10127 rows.
2023-05-17 16:10:24.433 (2)scanned 1819130 rows, and produced 9694 rows already.
2023-05-17 16:10:24.437 (2)inner join(T1 – T2), using hash join, produced 9694 rows.
2023-05-17 16:10:24.590 (1)scanned 1820776 rows, and produced 9760 rows already.
2023-05-17 16:10:24.594 (1)inner join(T1 – T2), using hash join, produced 9760 rows.
2023-05-17 16:10:24.616 (3)scanned 1817740 rows, and produced 9867 rows already.
2023-05-17 16:10:24.621 (3)inner join(T1 – T2), using hash join, produced 9867 rows.
2023-05-17 16:10:24.623 merge row num: 39448 — T1与T2的join结束，结果39448行
2023-05-17 16:10:24.623 BEGIN Parallel Aggregation(39448 rows) –– 开始分组聚集操作
2023-05-17 16:10:24.623 start sampling — 采样评估，以确定数据切分方法
2023-05-17 16:10:24.639 sample data: 2 packs, 4096 rows. NDV: 2504, 61%. — NDV比例较大（超过10%），hash划分
2023-05-17 16:10:24.654 (0)split by hash already(39448 rows). — 数据分块，采用hash划分
2023-05-17 16:10:24.654 divide to 4 blocks(using hash[parallel]): 9997, 9603, 10171, 9677.
2023-05-17 16:10:24.654 (1)BEGIN Aggregation(9603 rows)
2023-05-17 16:10:24.654 (3)BEGIN Aggregation(9677 rows)
2023-05-17 16:10:24.654 (0)BEGIN Aggregation(9997 rows)
2023-05-17 16:10:24.658 (2)BEGIN Aggregation(10171 rows)
2023-05-17 16:10:24.668 (3)produced total 980 groups.
2023-05-17 16:10:24.668 (0)produced total 2012 groups.
2023-05-17 16:10:24.669 (1)produced total 2987 groups.
2023-05-17 16:10:24.671 (2)produced total 4009 groups.
2023-05-17 16:10:24.671 produced total 4009 groups. — 并行分组聚集结束，共得到4009个分组
2023-05-17 16:10:24.679 BEGIN Parallel Sort(4009 rows) –– 开始并行排序
2023-05-17 16:10:24.679 divide to 1 blocks: 4009.
2023-05-17 16:10:24.679 (0)BEGIN Sort(4009 rows)
2023-05-17 16:10:24.679 (0)limit sorter initialized, total_bytes: 66, key_bytes: 29. –- Order By Limit，并行线程内部使用Limit Sorter，行宽66bytes，排序列29bytes
2023-05-17 16:10:24.690 BEGIN Merge.
2023-05-17 16:10:24.690 Send 100 rows already
2023-05-17 16:10:24.690 parallel sort done. –- 并行排序结束
2023-05-17 16:10:24.693 ResultSender: send 100 rows. –– 发送结果100行
2023-05-17 16:10:24.693 output result done.
2023-05-17 16:10:24.696 SUMMARY –– 执行计划总结
2023-05-17 16:10:24.696 elapsed time: 00:01:48.372 — sql执行时间
2023-05-17 16:10:24.696 data loaded from storage: 1.42G, 3.834s, 4130 DC. — 总共从磁盘读了1.42G(共4130个DC)的数据，用时3.834s
2023-05-17 16:10:24.696 data decompressed: 1.54G, 6.588s. — 总共解压了1.54G数据(不开压缩也会有值)，用时6.588s
2023-05-17 16:10:24.696 temp space IO stats: — 查询过程中临时表空间使用情况
2023-05-17 16:10:24.697 CB write(1MB, 2time, 0sec), read(2MB, 4time, 0sec) — 物化中间结果
2023-05-17 16:10:24.697 SRT write(0MB, 0time, 0sec), read(0MB, 0time, 0sec) — 排序中间结果
2023-05-17 16:10:24.697 GDC write(0MB, 0time, 0sec), read(0MB, 0time, 0sec) — groupby distinct中间结果
2023-05-17 16:10:24.697 MAT write(0MB, 12time, 0sec), read(5MB, 88time, 0sec) — join中间结果
2023-05-17 16:10:24.697 ======================================================
资源监控部分介绍
[M:1.45G, 27M,D: 633K] [DC: 19006, 3899]
[M:1.45G, 41M,D: 633K] [DC: 19500, 3901]
[M:1.45G, 41M,D: 633K] [DC: 19500, 3901]
[M:1.50G, 54M,D: 633K] [DC: 19500, 4110]
[M:1.50G, 48M,D: 633K] [DC: 19500, 4110]
[M:1.50G, 48M,D: 633K] [DC: 19500, 4110]
[M:1.50G, 41M,D: 633K] [DC: 19500, 4111]
[内存：数据堆，large堆，磁盘：临时表空间] [访问DC数：内存命中，磁盘访问]
(1). 数据堆：data heap的使用状况，全局状态
(2). Large堆： 算子buffer的使用情况， 全局状态
(3). 临时表空间： session级，语句执行过程中占用的临时磁盘空间
(4). 内存中访问DC总数 ：session级 可以看出查询中处理的数据量 语句执行过程中，从内存中访问的DC总数
(5). 磁盘中访问DC总数 ： session级 可以看到在什么步聚引起的IO 语句执行过程中，从磁盘中访问的DC总数
附完整的trace信息
select s_name, count(*) as numwait from supplier, lineitem l1, orders, nation where s_suppkey = l1.l_suppkey and o_orderkey = l1.l_orderkey and o_orderstatus = ‘F’ and l1.l_receiptdate > l1.l_commitdate and exists ( select * from lineitem l2 where l2.l_orderkey = l1.l_orderkey and l2.l_suppkey <> l1.l_suppkey ) and not exists ( select * from lineitem l3 where l3.l_orderkey = l1.l_orderkey and l3.l_suppkey <> l1.l_suppkey and l3.l_receiptdate > l3.l_commitdate ) and s_nationkey = n_nationkey and n_name = ‘SAUDI ARABIA’ group by s_name order by numwait desc, s_name limit 100
2023-05-17 16:08:36.324 [M: 0B, 0B,D: 0B] [DC: 0, 0] Start Query Execution
2023-05-17 16:08:36.326 [M: 0B, 0B,D: 0B] [DC: 0, 0] BEGIN Smart Scan
2023-05-17 16:08:36.328 [M: 0B, 0B,D: 0B] [DC: 0, 0] T0: total 2 DC, found 2 DC to scan(with 0 FULL DC).
2023-05-17 16:08:36.328 [M: 0B, 0B,D: 0B] [DC: 0, 0] T1: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:08:36.328 [M: 0B, 0B,D: 0B] [DC: 0, 0] T2: total 229 DC, found 229 DC to scan(with 0 FULL DC).
2023-05-17 16:08:36.328 [M: 0B, 0B,D: 0B] [DC: 0, 0] T3: total 1 DC, found 1 DC to scan(with 0 FULL DC).
2023-05-17 16:08:36.328 [M: 0B, 0B,D: 0B] [DC: 0, 0] BEGIN Scan
2023-05-17 16:08:36.328 [M: 0B, 0B,D: 0B] [DC: 0, 0] using parallel scan
2023-05-17 16:08:36.339 [M: 435B, 0B,D: 0B] [DC: 0, 1] merge row num: 1
2023-05-17 16:08:36.339 [M: 435B, 0B,D: 0B] [DC: 0, 1] using parallel scan
2023-05-17 16:08:37.592 [M: 157M, 0B,D: 0B] [DC: 0, 230] merge row num: 7309184
2023-05-17 16:08:37.592 [M: 157M, 0B,D: 0B] [DC: 0, 230] using parallel scan
2023-05-17 16:08:45.483 [M:1.05G, 0B,D: 0B] [DC: 0, 2062] merge row num: 37929348
2023-05-17 16:08:45.484 [M:1.05G, 0B,D: 0B] [DC: 0, 2062] using parallel scan
2023-05-17 16:08:45.496 [M:1.05G, 0B,D: 0B] [DC: 0, 2062] do not support parallel scan , run normal scan
2023-05-17 16:08:45.498 [M:1.05G, 0B,D: 0B] [DC: 0, 2062] using serially scan
2023-05-17 16:08:45.509 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | BEGIN Smart Scan
2023-05-17 16:08:45.509 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | T0: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:08:45.509 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | T1: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:08:45.509 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | BEGIN Scan
2023-05-17 16:08:45.509 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | T0: total 916 DC, found 916 DC after scan(with 916 FULL DC).
2023-05-17 16:08:45.510 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | T1: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:08:45.510 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | BEGIN Join
2023-05-17 16:08:45.524 [M:1.05G, 0B,D: 0B] [DC: 0, 2064] | divide to 4 blocks(using round-robin): 9486804, 9491138, 9489208, 9462198.
2023-05-17 16:08:52.992 [M:1.18G, 500M,D: 0B] [DC: 1, 2754] | (0)created hash on 7372800/9486804 rows already.
2023-05-17 16:08:53.255 [M:1.18G, 500M,D: 0B] [DC: 8, 2765] | (1)created hash on 7372800/9491138 rows already.
2023-05-17 16:08:54.128 [M:1.19G, 500M,D: 0B] [DC: 38, 2801] | (3)created hash on 7372800/9462198 rows already.
2023-05-17 16:08:54.187 [M:1.19G, 500M,D: 0B] [DC: 40, 2803] | (2)created hash on 7372800/9489208 rows already.
2023-05-17 16:09:15.648 [M:1.35G, 500M,D: 0B] [DC: 1334, 3452] | (1)scanned 12124160 rows, and produced 29490678 rows already.
2023-05-17 16:09:16.028 [M:1.35G, 500M,D: 0B] [DC: 1346, 3473] | (0)scanned 12124160 rows, and produced 29495308 rows already.
2023-05-17 16:09:16.753 [M:1.36G, 500M,D: 0B] [DC: 1378, 3532] | (1)created hash on all 9491138 rows already.
2023-05-17 16:09:17.115 [M:1.37G, 500M,D: 0B] [DC: 1407, 3552] | (0)created hash on all 9486804 rows already.
2023-05-17 16:09:21.793 [M:1.40G, 500M,D: 0B] [DC: 1690, 3686] | (1)scanned 3866624 rows, and produced 37965426 rows already.
2023-05-17 16:09:21.793 [M:1.40G, 500M,D: 0B] [DC: 1690, 3686] | (1)skipped 86.68% DCs by smart index.
2023-05-17 16:09:21.794 [M:1.40G, 375M,D: 0B] [DC: 1690, 3686] | (1)inner join(T0 – T1), using [semi]hash join, produced 9151948 rows.
2023-05-17 16:09:22.202 [M:1.40G, 375M,D: 0B] [DC: 1713, 3691] | (0)scanned 3866624 rows, and produced 37947533 rows already.
2023-05-17 16:09:22.202 [M:1.40G, 375M,D: 0B] [DC: 1713, 3691] | (0)skipped 86.68% DCs by smart index.
2023-05-17 16:09:22.203 [M:1.40G, 250M,D: 0B] [DC: 1713, 3691] | (0)inner join(T0 – T1), using [semi]hash join, produced 9147665 rows.
2023-05-17 16:09:23.060 [M:1.40G, 250M,D: 0B] [DC: 1725, 3697] | (3)scanned 12058624 rows, and produced 29474728 rows already.
2023-05-17 16:09:24.038 [M:1.41G, 250M,D: 0B] [DC: 1732, 3749] | (3)created hash on all 9462198 rows already.
2023-05-17 16:09:24.687 [M:1.42G, 250M,D: 0B] [DC: 1755, 3762] | (2)scanned 12713984 rows, and produced 29482666 rows already.
2023-05-17 16:09:25.873 [M:1.43G, 250M,D: 0B] [DC: 1791, 3814] | (2)created hash on all 9489208 rows already.
2023-05-17 16:09:28.993 [M:1.44G, 250M,D: 0B] [DC: 1917, 3870] | (3)scanned 3756164 rows, and produced 37838709 rows already.
2023-05-17 16:09:28.993 [M:1.44G, 250M,D: 0B] [DC: 1917, 3870] | (3)skipped 86.79% DCs by smart index.
2023-05-17 16:09:28.993 [M:1.44G, 125M,D: 0B] [DC: 1917, 3870] | (3)inner join(T0 – T1), using [semi]hash join, produced 9124258 rows.
2023-05-17 16:09:32.365 [M:1.45G, 125M,D: 0B] [DC: 1977, 3894] | (2)scanned 3801088 rows, and produced 37939475 rows already.
2023-05-17 16:09:32.366 [M:1.45G, 125M,D: 0B] [DC: 1977, 3894] | (2)skipped 86.24% DCs by smart index.
2023-05-17 16:09:32.366 [M:1.45G, 0B,D: 0B] [DC: 1977, 3894] | (2)inner join(T0 – T1), using [semi]hash join, produced 9150117 rows.
2023-05-17 16:09:32.374 [M:1.45G, 0B,D: 0B] [DC: 1977, 3894] | merge row num: 36573988
2023-05-17 16:09:36.093 [M:1.45G, 0B,D: 0B] [DC: 3807, 3894] using parallel scan
2023-05-17 16:09:36.103 [M:1.45G, 0B,D: 0B] [DC: 3807, 3894] do not support parallel scan , run normal scan
2023-05-17 16:09:36.104 [M:1.45G, 0B,D: 0B] [DC: 3807, 3894] using serially scan
2023-05-17 16:09:36.112 [M:1.45G, 0B,D: 0B] [DC: 3809, 3894] | BEGIN Smart Scan
2023-05-17 16:09:36.113 [M:1.45G, 0B,D: 0B] [DC: 3809, 3894] | T0: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:09:36.113 [M:1.45G, 0B,D: 0B] [DC: 3809, 3894] | T1: total 916 DC, found 916 DC to scan(with 0 FULL DC).
2023-05-17 16:09:36.113 [M:1.45G, 0B,D: 0B] [DC: 3809, 3894] | BEGIN Scan
2023-05-17 16:09:36.113 [M:1.45G, 0B,D: 0B] [DC: 3809, 3894] | using parallel scan
2023-05-17 16:09:41.290 [M:1.45G, 0B,D: 0B] [DC: 5641, 3894] | merge row num: 37929348
2023-05-17 16:09:41.291 [M:1.45G, 0B,D: 0B] [DC: 5641, 3894] | T0: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:09:41.291 [M:1.45G, 0B,D: 0B] [DC: 5641, 3894] | T1: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:09:41.291 [M:1.45G, 0B,D: 0B] [DC: 5641, 3894] | BEGIN Join
2023-05-17 16:09:41.349 [M:1.45G, 0B,D: 0B] [DC: 5641, 3894] | divide to 4 blocks(using round-robin): 9147665, 9151948, 9150117, 9124258.
2023-05-17 16:09:47.946 [M:1.45G, 500M,D: 0B] [DC: 6354, 3894] | (0)created hash on 7372800/9147665 rows already.
2023-05-17 16:09:48.056 [M:1.45G, 500M,D: 0B] [DC: 6363, 3894] | (1)created hash on 7372800/9151948 rows already.
2023-05-17 16:09:49.250 [M:1.45G, 500M,D: 0B] [DC: 6484, 3894] | (2)created hash on 7372800/9150117 rows already.
2023-05-17 16:09:49.428 [M:1.45G, 500M,D: 0B] [DC: 6506, 3894] | (3)created hash on 7372800/9124258 rows already.
2023-05-17 16:10:04.565 [M:1.45G, 500M,D: 0B] [DC: 8405, 3894] | (0)scanned 7829735 rows, and produced 19340793 rows already.
2023-05-17 16:10:05.399 [M:1.45G, 500M,D: 0B] [DC: 8500, 3894] | (0)created hash on all 9147665 rows already.
2023-05-17 16:10:05.427 [M:1.45G, 500M,D: 0B] [DC: 8504, 3894] | (1)scanned 8123447 rows, and produced 19342658 rows already.
2023-05-17 16:10:06.255 [M:1.45G, 500M,D: 0B] [DC: 8626, 3894] | (1)created hash on all 9151948 rows already.
2023-05-17 16:10:08.554 [M:1.45G, 500M,D: 0B] [DC: 8924, 3894] | (0)scanned 2320546 rows, and produced 23993387 rows already.
2023-05-17 16:10:08.554 [M:1.45G, 500M,D: 0B] [DC: 8924, 3894] | (0)skipped 86.62% DCs by smart index.
2023-05-17 16:10:08.556 [M:1.45G, 375M,D: 0B] [DC: 8924, 3894] | (0)inner join(T0 – T1), using [semi]hash join, produced 8641651 rows.
2023-05-17 16:10:09.345 [M:1.45G, 375M,D: 0B] [DC: 8985, 3894] | (1)scanned 1947652 rows, and produced 24007961 rows already.
2023-05-17 16:10:09.345 [M:1.45G, 375M,D: 0B] [DC: 8985, 3894] | (1)skipped 86.73% DCs by smart index.
2023-05-17 16:10:09.347 [M:1.45G, 250M,D: 0B] [DC: 8985, 3894] | (1)inner join(T0 – T1), using [semi]hash join, produced 8648760 rows.
2023-05-17 16:10:10.935 [M:1.45G, 250M,D: 0B] [DC: 9033, 3894] | (2)scanned 8163555 rows, and produced 19333658 rows already.
2023-05-17 16:10:11.742 [M:1.45G, 250M,D: 0B] [DC: 9089, 3894] | (2)created hash on all 9150117 rows already.
2023-05-17 16:10:11.941 [M:1.45G, 250M,D: 0B] [DC: 9108, 3894] | (3)scanned 8123595 rows, and produced 19328057 rows already.
2023-05-17 16:10:12.888 [M:1.45G, 250M,D: 0B] [DC: 9194, 3894] | (3)created hash on all 9124258 rows already.
2023-05-17 16:10:15.003 [M:1.45G, 250M,D: 0B] [DC: 9358, 3894] | (2)scanned 2237629 rows, and produced 23990497 rows already.
2023-05-17 16:10:15.003 [M:1.45G, 250M,D: 0B] [DC: 9358, 3894] | (2)skipped 86.29% DCs by smart index.
2023-05-17 16:10:15.005 [M:1.45G, 125M,D: 0B] [DC: 9358, 3894] | (2)inner join(T0 – T1), using [semi]hash join, produced 8645279 rows.
2023-05-17 16:10:16.883 [M:1.45G, 125M,D: 0B] [DC: 9419, 3894] | (3)scanned 1919161 rows, and produced 23924421 rows already.
2023-05-17 16:10:16.883 [M:1.45G, 125M,D: 0B] [DC: 9419, 3894] | (3)skipped 86.73% DCs by smart index.
2023-05-17 16:10:16.886 [M:1.45G, 0B,D: 0B] [DC: 9419, 3894] | (3)inner join(T0 – T1), using [semi]hash join, produced 8621374 rows.
2023-05-17 16:10:16.896 [M:1.45G, 0B,D: 0B] [DC: 9419, 3894] | merge row num: 34557064
2023-05-17 16:10:22.821 [M:1.45G, 0B,D: 0B] [DC: 11249, 3894] T0: total 2 DC, found 2 DC after scan(with 2 FULL DC).
2023-05-17 16:10:22.821 [M:1.45G, 0B,D: 0B] [DC: 11249, 3894] T1: total 916 DC, found 916 DC after scan(with 0 FULL DC).
2023-05-17 16:10:22.821 [M:1.45G, 0B,D: 0B] [DC: 11249, 3894] T2: total 229 DC, found 229 DC after scan(with 0 FULL DC).
2023-05-17 16:10:22.821 [M:1.45G, 0B,D: 0B] [DC: 11249, 3894] T3: total 1 DC, found 1 DC after scan(with 0 FULL DC).
2023-05-17 16:10:22.821 [M:1.45G, 0B,D: 0B] [DC: 11249, 3894] BEGIN Join
2023-05-17 16:10:22.821 [M:1.45G, 0B,D: 0B] [DC: 11249, 3894] divide to 2 blocks(using round-robin): 65536, 34464.
2023-05-17 16:10:22.822 [M:1.45G, 2K,D: 0B] [DC: 11250, 3895] (1)created hash on all 1 rows already.
2023-05-17 16:10:22.822 [M:1.45G, 2K,D: 0B] [DC: 11250, 3895] (0)created hash on all 1 rows already.
2023-05-17 16:10:22.830 [M:1.45G, 2K,D: 0B] [DC: 11250, 3897] (1)scanned 34464 rows, and produced 1371 rows already.
2023-05-17 16:10:22.831 [M:1.45G, 1K,D: 0B] [DC: 11250, 3897] (1)inner join(T0 – T3), using hash join, produced 1371 rows.
2023-05-17 16:10:22.835 [M:1.45G, 1K,D: 0B] [DC: 11250, 3897] (0)scanned 65536 rows, and produced 2639 rows already.
2023-05-17 16:10:22.835 [M:1.45G, 0B,D: 0B] [DC: 11250, 3897] (0)inner join(T0 – T3), using hash join, produced 2639 rows.
2023-05-17 16:10:22.835 [M:1.45G, 0B,D: 0B] [DC: 11250, 3897] merge row num: 4010
2023-05-17 16:10:22.842 [M:1.45G, 0B,D: 0B] [DC: 11250, 3897] divide to 4 blocks(using round-robin): 506014, 503188, 504838, 502884.
2023-05-17 16:10:22.846 [M:1.45G, 470K,D: 0B] [DC: 11255, 3899] (1)created hash on all 4010 rows already.
2023-05-17 16:10:22.846 [M:1.45G, 470K,D: 0B] [DC: 11256, 3899] (3)created hash on all 4010 rows already.
2023-05-17 16:10:22.846 [M:1.45G, 4M,D: 0B] [DC: 11257, 3899] (2)created hash on all 4010 rows already.
2023-05-17 16:10:22.850 [M:1.45G, 11M,D: 0B] [DC: 11270, 3899] (0)created hash on all 4010 rows already.
2023-05-17 16:10:23.049 [M:1.45G, 15M,D: 0B] [DC: 12058, 3899] (3)scanned 502884 rows, and produced 20257 rows already.
2023-05-17 16:10:23.051 [M:1.45G, 15M,D: 0B] [DC: 12063, 3899] (1)scanned 503188 rows, and produced 20303 rows already.
2023-05-17 16:10:23.065 [M:1.45G, 15M,D: 0B] [DC: 12087, 3899] (3)inner join(T0 – T1), using hash join, produced 20257 rows.
2023-05-17 16:10:23.066 [M:1.45G, 15M,D: 0B] [DC: 12089, 3899] (1)inner join(T0 – T1), using hash join, produced 20303 rows.
2023-05-17 16:10:23.101 [M:1.45G, 15M,D: 0B] [DC: 12159, 3899] (2)scanned 504838 rows, and produced 19986 rows already.
2023-05-17 16:10:23.117 [M:1.45G, 15M,D: 0B] [DC: 12172, 3899] (2)inner join(T0 – T1), using hash join, produced 19986 rows.
2023-05-17 16:10:23.117 [M:1.45G, 15M,D: 0B] [DC: 12172, 3899] (0)scanned 506014 rows, and produced 20499 rows already.
2023-05-17 16:10:23.138 [M:1.45G, 15M,D: 0B] [DC: 12172, 3899] (0)inner join(T0 – T1), using hash join, produced 20499 rows.
2023-05-17 16:10:23.145 [M:1.45G, 0B,D: 633K] [DC: 12172, 3899] merge row num: 81045
2023-05-17 16:10:23.149 [M:1.45G, 0B,D: 633K] [DC: 12172, 3899] divide to 4 blocks(using round-robin): 1851538, 1820776, 1819130, 1817740.
2023-05-17 16:10:23.230 [M:1.45G, 27M,D: 633K] [DC: 19002, 3899] (0)created hash on all 81045 rows already.
2023-05-17 16:10:23.230 [M:1.45G, 27M,D: 633K] [DC: 19006, 3899] (2)created hash on all 81045 rows already.
2023-05-17 16:10:23.239 [M:1.45G, 41M,D: 633K] [DC: 19500, 3901] (3)created hash on all 81045 rows already.
2023-05-17 16:10:23.239 [M:1.45G, 41M,D: 633K] [DC: 19500, 3901] (1)created hash on all 81045 rows already.
2023-05-17 16:10:24.428 [M:1.50G, 54M,D: 633K] [DC: 19500, 4110] (0)scanned 1851538 rows, and produced 10127 rows already.
2023-05-17 16:10:24.432 [M:1.50G, 48M,D: 633K] [DC: 19500, 4110] (0)inner join(T1 – T2), using hash join, produced 10127 rows.
2023-05-17 16:10:24.433 [M:1.50G, 48M,D: 633K] [DC: 19500, 4110] (2)scanned 1819130 rows, and produced 9694 rows already.
2023-05-17 16:10:24.437 [M:1.50G, 41M,D: 633K] [DC: 19500, 4111] (2)inner join(T1 – T2), using hash join, produced 9694 rows.
2023-05-17 16:10:24.590 [M:1.50G, 41M,D: 633K] [DC: 19500, 4127] (1)scanned 1820776 rows, and produced 9760 rows already.
2023-05-17 16:10:24.594 [M:1.50G, 34M,D: 633K] [DC: 19500, 4127] (1)inner join(T1 – T2), using hash join, produced 9760 rows.
2023-05-17 16:10:24.616 [M:1.50G, 34M,D: 633K] [DC: 19500, 4128] (3)scanned 1817740 rows, and produced 9867 rows already.
2023-05-17 16:10:24.621 [M:1.50G, 27M,D: 633K] [DC: 19500, 4128] (3)inner join(T1 – T2), using hash join, produced 9867 rows.
2023-05-17 16:10:24.623 [M:1.50G, 0B,D: 154K] [DC: 19500, 4128] merge row num: 39448
2023-05-17 16:10:24.623 [M:1.50G, 7M,D: 154K] [DC: 19500, 4128] BEGIN Parallel Aggregation(39448 rows)
2023-05-17 16:10:24.623 [M:1.50G, 7M,D: 154K] [DC: 19500, 4128] start sampling
2023-05-17 16:10:24.639 [M:1.51G, 7M,D: 154K] [DC: 19500, 4130] sample data: 2 packs, 4096 rows. NDV: 2504, 61%.
2023-05-17 16:10:24.654 [M:1.51G, 28M,D: 154K] [DC: 19502, 4130] (0)split by hash already(39448 rows).
2023-05-17 16:10:24.654 [M:1.51G, 28M,D: 154K] [DC: 19502, 4130] divide to 4 blocks(using hash[parallel]): 9997, 9603, 10171, 9677.
2023-05-17 16:10:24.654 [M:1.51G, 28M,D: 154K] [DC: 19502, 4130] (1)BEGIN Aggregation(9603 rows)
2023-05-17 16:10:24.654 [M:1.51G, 28M,D: 154K] [DC: 19502, 4130] (3)BEGIN Aggregation(9677 rows)
2023-05-17 16:10:24.654 [M:1.51G, 30M,D: 154K] [DC: 19502, 4130] (0)BEGIN Aggregation(9997 rows)
2023-05-17 16:10:24.658 [M:1.51G, 34M,D: 154K] [DC: 19503, 4130] (2)BEGIN Aggregation(10171 rows)
2023-05-17 16:10:24.668 [M:1.51G, 38M,D: 154K] [DC: 19510, 4130] (3)produced total 980 groups.
2023-05-17 16:10:24.668 [M:1.51G, 28M,D: 154K] [DC: 19510, 4130] (0)produced total 2012 groups.
2023-05-17 16:10:24.669 [M:1.51G, 19M,D: 154K] [DC: 19510, 4130] (1)produced total 2987 groups.
2023-05-17 16:10:24.671 [M:1.51G, 10M,D: 154K] [DC: 19510, 4130] (2)produced total 4009 groups.
2023-05-17 16:10:24.671 [M:1.51G, 1M,D: 154K] [DC: 19510, 4130] produced total 4009 groups.
2023-05-17 16:10:24.678 [M:1.51G, 7M,D: 1M] [DC: 19510, 4130] limit sorter initialized, total_bytes: 66, key_bytes: 29.
2023-05-17 16:10:24.679 [M:1.51G, 7M,D: 1M] [DC: 19510, 4130] BEGIN Parallel Sort(4009 rows)
2023-05-17 16:10:24.679 [M:1.51G, 7M,D: 1M] [DC: 19510, 4130] divide to 1 blocks: 4009.
2023-05-17 16:10:24.679 [M:1.51G, 7M,D: 1M] [DC: 19510, 4130] (0)BEGIN Sort(4009 rows)
2023-05-17 16:10:24.679 [M:1.51G, 7M,D: 1M] [DC: 19510, 4130] (0)limit sorter initialized, total_bytes: 66, key_bytes: 29.
2023-05-17 16:10:24.690 [M:1.51G, 9M,D: 1M] [DC: 19510, 4130] BEGIN Merge.
2023-05-17 16:10:24.690 [M:1.51G, 9M,D: 1M] [DC: 19510, 4130] Send 100 rows already
2023-05-17 16:10:24.690 [M:1.51G, 9M,D: 1M] [DC: 19510, 4130] parallel sort done.
2023-05-17 16:10:24.693 [M:1.51G, 10K,D: 0B] [DC: 19510, 4130] ResultSender: send 100 rows.
2023-05-17 16:10:24.693 [M:1.51G, 10K,D: 0B] [DC: 19510, 4130] output result done.
2023-05-17 16:10:24.696 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] SUMMARY
2023-05-17 16:10:24.696 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] elapsed time: 00:01:48.372
2023-05-17 16:10:24.696 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] data loaded from storage: 1.42G, 3.834s, 4130 DC.
2023-05-17 16:10:24.696 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] data decompressed: 1.54G, 6.588s.
2023-05-17 16:10:24.696 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] temp space IO stats:
2023-05-17 16:10:24.697 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] CB write(1MB, 2time, 0sec), read(2MB, 4time, 0sec)
2023-05-17 16:10:24.697 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] SRT write(0MB, 0time, 0sec), read(0MB, 0time, 0sec)
2023-05-17 16:10:24.697 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] GDC write(0MB, 0time, 0sec), read(0MB, 0time, 0sec)
2023-05-17 16:10:24.697 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] MAT write(0MB, 12time, 0sec), read(5MB, 88time, 0sec)
2023-05-17 16:10:24.697 [M:1.51G, 0B,D: 0B] [DC: 19510, 4130] ======================================================
原创文章，作者：kirin，如若转载，请注明出处：https://blog.ytso.com/tech/bigdata/317787.html