Effective way to track INSERT process

TomYork1986

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.

mosheg

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)

TomYork1986

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:

mosheg

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;