OceanBase 的 TRACE EVENT 是如何采集和实现的

[2022-07-08 11:26:20.535074] TRACE [TRACE]obmp_base.cpp:948 [59127][2532][YB420A0A34F5-0005E247B18CF116] [lt=16] [dc=0] [slow query](TRACE=begin_ts=1657250749896387 2022-07-08 03:25:49.896387|[process_begin] u=0 in_queue_time:11, receive_ts:1657250749896375, enqueue_ts:1657250749896376|[start_sql] u=0 addr:{ip:"10.xx.xx.xxx", port:3xxxx}|[query_begin] u=1 trace_id:YB420A0A34F5-0005E247B18CF116|[before_processor_run] u=4 |[session] u=2 sid:3223166492, tenant_id:1013|[parse_begin] u=16 stmt:"select * from ac01 where aac002 = '510xxxxxxxxxxxxxxx';", stmt_len:55|[cache_get_plan_begin] u=4 |[calc_partition_location_begin] u=64 |[tl_calc_by_range_end] u=10 |[tl_calc_part_id_end] u=0 |[get_location_cache_begin] u=0 |[get_location_cache_end] u=182 |[calc_partition_location_end] u=1 |[pc_choose_plan] u=46 |[check_priv] u=25 |[cache_get_plan_end] u=0 |[plan_id] u=1 plan_id:9320739|[exec_begin] u=2 arg1:false, end_trans_cb:false|[post_packet] u=46 ret:0, pcode:1808, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[do_open_plan_begin] u=557 plan_id:9320739|[sql_start_stmt_begin] u=1 |[sql_start_stmt_end] u=0 |[exec_plan_begin] u=1 |[exec_plan_end] u=14 |[sql_start_participant_begin] u=0 |[sql_start_participant_end] u=1 |[do_open_plan_end] u=1 |[post_packet] u=533 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:28xx}|[post_packet] u=109 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[post_packet] u=93 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[post_packet] u=90 ret:0, pcode:1311, addr:{ip:"10.xxx.xx.xxx", port:2xxx}|[post_packet] u=88 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[post_packet] u=93 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[post_packet] u=85 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[post_packet] u=88 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[post_packet] u=87 ret:0, pcode:1311, addr:{ip:"10.xx.xx.xxx", port:2xxx}|[sqc_finish] u=387 dfo_id:0, sqc_id:0|[sqc_finish] u=129 dfo_id:0, sqc_id:4|[sqc_finish] u=134 dfo_id:0, sqc_id:3|[sqc_finish] u=3 dfo_id:0, sqc_id:2|[sqc_finish] u=135 dfo_id:0, sqc_id:6|[sqc_finish] u=45 dfo_id:0, sqc_id:5|[sqc_finish] u=61 dfo_id:0, sqc_id:8|[sqc_finish] u=447 dfo_id:0, sqc_id:7|[sqc_finish] u=30634787 dfo_id:0, sqc_id:1|[close_plan_begin] u=8 |[end_participant_begin] u=100 |[end_participant_end] u=0 |[start_end_stmt] u=0 |[end_stmt] u=0 |[close_plan_end] u=0 |[affected_rows] u=1 affected_rows:0|[store_found_rows] u=0 found_rows:0, return_rows:1|[auto_end_plan_begin] u=1 |[auto_end_plan_end] u=2 |[result_set_close] u=0 ret:0, arg1:0, arg2:0, arg3:-4008, async:false|[exec_end] u=16 |[query_end] u=100 |[process_end] u=17 run_ts:1657250749896392|total_timeu=30638618)