Effective way to track INSERT process
Hello,
I try to find the effective way to track INSERT process. Sometimes INSERT statements can take too long to execute. It'd be great to have a possibility to track them.
I understand that the EE operators counters are what I need, but there is no detailed information about the underlying EE processes. Therefore, it's difficult to understand which counters should be used.
0
Answers
The following script example shows the step differences between two INSERT statements.
DROP TABLE my_table_xyz CASCADE; CREATE TABLE my_table_xyz ( time_id timestamp NOT NULL DEFAULT CURRENT_TIME(0)::timestamp - randomint(730)/9, myuuid varchar(36) ) PARTITION BY (date(my_table_xyz.time_id)); PROFILE INSERT /* +LABEL(test_insert_1) */ INTO my_table_xyz (myuuid) VALUES ('12345F8D-12C3-41F2-B175-E36E91B67890'); COMMIT; \echo 'Generating 10k rows for INSERT..' \set GEN_ROWS 10000 PROFILE INSERT /* +LABEL(test_insert_100) */ INTO my_table_xyz (myuuid) with myrows as (select UUID_GENERATE() as myuuid from ( select 1 from ( select now() as se union all select now() + :GEN_ROWS - 1 as se) a timeseries ts as '1 day' over (order by se)) b) select myuuid from myrows; COMMIT; SELECT request_label, transaction_id, statement_id, request_duration_ms FROM query_requests WHERE request_label ilike 'test_insert_%' AND SUCCESS ORDER BY start_timestamp DESC LIMIT 2; request_label | transaction_id | statement_id | request_duration_ms -----------------+-------------------+--------------+--------------------- test_insert_100 | 45035996273730393 | 1 | 70 test_insert_1 | 45035996273730385 | 1 | 13 (2 rows) \set trxid 45035996273730393 \set stmtid 1 \echo 'test_insert_100' SELECT execution_step, sum(completion_time - time) as elapsed FROM v_internal.dc_query_executions WHERE transaction_id=:trxid AND statement_id=:stmtid GROUP BY 1 ORDER BY 2 DESC; test_insert_100 execution_step | elapsed -------------------------------+----------------- ExecutePlan | 00:00:00.06311 BeforePlan | 00:00:00.003658 PreparePlan | 00:00:00.002045 BeforePlan:AnalyzeRewrite | 00:00:00.001745 Plan | 00:00:00.001704 CompilePlan | 00:00:00.001172 CompilePlan:EEpreexecute | 00:00:00.001114 PreparePlan:EEcompile | 00:00:00.000849 PreparePlan:TunePlanResources | 00:00:00.000843 PreparePlan:LocalPlan | 00:00:00.000201 LoadVirtualTableRows | 00:00:00.000062 CompilePlan:ReserveResources | 00:00:00.000023 PreparePlan:TakeTableLocks | 00:00:00.000003 (13 rows) \set trxid 45035996273730385 \set stmtid 1 \echo 'test_insert_1' SELECT execution_step, sum(completion_time - time) as elapsed FROM v_internal.dc_query_executions WHERE transaction_id=:trxid AND statement_id=:stmtid GROUP BY 1 ORDER BY 2 DESC; test_insert_1 execution_step | elapsed -------------------------------+----------------- BeforePlan | 00:00:00.035631 ExecutePlan | 00:00:00.003215 Plan | 00:00:00.002682 PreparePlan | 00:00:00.001723 BeforePlan:AnalyzeRewrite | 00:00:00.001241 CompilePlan | 00:00:00.00092 CompilePlan:EEpreexecute | 00:00:00.000865 PreparePlan:EEcompile | 00:00:00.000451 PreparePlan:TunePlanResources | 00:00:00.00032 PreparePlan:LocalPlan | 00:00:00.000191 BeforePlan:Parser | 00:00:00.000056 CompilePlan:ReserveResources | 00:00:00.000025 PreparePlan:TakeTableLocks | 00:00:00.000003 (13 rows)Thanks for the answer, but that's not exactly what I'm trying to find. I want to get an output like this:
+++++
Rows to proceed:
Rows proceeded:
select output_rows
from query_consumption
where LABEL='The_INSERT_Label';
-- OR --
with my_insert as (
select transaction_id,statement_id
from query_requests
where REQUEST_LABEL = 'The_Insert_Label'
-- OR add: and is_executing
)
select
eep.node_name, eep.operator_name, eep.counter_value
from execution_engine_profiles eep, my_insert mi
where
eep.transaction_id = mi.transaction_id
and eep.statement_id = mi.statement_id
and counter_name='rows produced'
and operator_name='NewEENode'
order by 1;