Check firebird.log [no messages found for interval when this test was running]
Jump to: output_first_mismatch    outcomes_full_history    elapsed_time_chart
Show cross-report outcomes.

Annotation type Annotation details
2 @message
assert   
    START_SESSION 1
    START_SESSION 2
  + Statement failed, SQLSTATE = 42S02
  + Dynamic SQL Error
  + -SQL error code = -204
  + -Table unknown
  + -"PLG$PROF_SESSIONS"
  + -At line 5, column 10
  + Statement failed, SQLSTATE = 42S02
  + Dynamic SQL Error
  + -SQL error code = -204
  + -Table unknown
  + -"PLG$PROF_PSQL_STATS_VIEW"
  + -At line 14, column 10
  + Statement failed, SQLSTATE = 42S02
  + Dynamic SQL Error
  + -SQL error code = -204
  + -Table unknown
  + -"PLG$PROF_RECORD_SOURCE_STATS_VIEW"
  + -At line 31, column 10
  + Statement failed, SQLSTATE = 42S02
  + Dynamic SQL Error
  + -SQL error code = -204
  + -Table unknown
  + -"PLG$PROF_REQUESTS"
  + -At line 11, column 12
  + Statement failed, SQLSTATE = 42S02
  + Dynamic SQL Error
  + -SQL error code = -204
  + -Table unknown
  + -"PLG$PROF_PSQL_STATS"
  + -At line 13, column 12
  + Statement failed, SQLSTATE = 42S02
  + Dynamic SQL Error
  + -SQL error code = -204
  + -Table unknown
  + -"PLG$PROF_RECORD_SOURCE_STATS"
  + -At line 17, column 12
  - MSG --- [ 1: plg$prof_sessions ] ---
  - PROFILE_ID 1
  - ATTACHMENT_ID
  - USER_NAME SYSDBA
  - DESCRIPTION profile session 1
  - START_TIMESTAMP
  - FINISH_TIMESTAMP
  - MSG --- [ 1: plg$prof_sessions ] ---
  - PROFILE_ID 2
  - ATTACHMENT_ID
  - USER_NAME SYSDBA
  - DESCRIPTION profile session 2
  - START_TIMESTAMP
  - FINISH_TIMESTAMP
  - Records affected: 2
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE BLOCK
  - SQL_TEXT
  - execute block
  - as
  - begin
  - execute procedure ins;
  - delete from tab;
  - end
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 1
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE BLOCK
  - SQL_TEXT
  - execute block
  - as
  - begin
  - execute procedure ins;
  - delete from tab;
  - end
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 1
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE PROCEDURE
  - SQL_TEXT
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 1
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE PROCEDURE
  - SQL_TEXT
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 1001
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE PROCEDURE
  - SQL_TEXT
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 1000
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE PROCEDURE
  - SQL_TEXT
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 500
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE PROCEDURE
  - SQL_TEXT
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 1000
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - MSG --- [ 2: plg$prof_psql_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_TYPE FUNCTION
  - SQL_TEXT
  - LINE_NUM
  - COLUMN_NUM
  - COUNTER 500
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - AVG_ELAPSED_TIME
  - Records affected: 8
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select rdb$profiler.start_session('profile session 1') from rdb$database
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 2
  - PARENT_RECORD_SOURCE_ID 1
  - ACCESS_PATH 84:1
  - -> Table "RDB$DATABASE" Full Scan
  - OPEN_COUNTER 0
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select rdb$profiler.start_session('profile session 1') from rdb$database
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 1
  - PARENT_RECORD_SOURCE_ID <null>
  - ACCESS_PATH 84:0
  - Select Expression
  - OPEN_COUNTER 0
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - execute block
  - as
  - begin
  - execute procedure ins;
  - delete from tab;
  - end
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 2
  - PARENT_RECORD_SOURCE_ID 1
  - ACCESS_PATH 84:3
  - -> Table "TAB" Full Scan
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 1
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - execute block
  - as
  - begin
  - execute procedure ins;
  - delete from tab;
  - end
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 1
  - PARENT_RECORD_SOURCE_ID <null>
  - ACCESS_PATH 84:2
  - Select Expression (line 5, column 9)
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select rdb$profiler.start_session('profile session 2') from rdb$database
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 2
  - PARENT_RECORD_SOURCE_ID 1
  - ACCESS_PATH 84:5
  - -> Table "RDB$DATABASE" Full Scan
  - OPEN_COUNTER 0
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select rdb$profiler.start_session('profile session 2') from rdb$database
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 1
  - PARENT_RECORD_SOURCE_ID <null>
  - ACCESS_PATH 84:4
  - Select Expression
  - OPEN_COUNTER 0
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select mod(id, 5),
  - sum(val)
  - from tab
  - where id <= 50
  - group by mod(id, 5)
  - order by sum(val)
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 2
  - PARENT_RECORD_SOURCE_ID 1
  - ACCESS_PATH 84:7
  - -> Sort (record length: 44, key length: 12)
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select mod(id, 5),
  - sum(val)
  - from tab
  - where id <= 50
  - group by mod(id, 5)
  - order by sum(val)
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 3
  - PARENT_RECORD_SOURCE_ID 2
  - ACCESS_PATH 84:8
  - -> Aggregate
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select mod(id, 5),
  - sum(val)
  - from tab
  - where id <= 50
  - group by mod(id, 5)
  - order by sum(val)
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 4
  - PARENT_RECORD_SOURCE_ID 3
  - ACCESS_PATH 84:9
  - -> Sort (record length: 44, key length: 8)
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select mod(id, 5),
  - sum(val)
  - from tab
  - where id <= 50
  - group by mod(id, 5)
  - order by sum(val)
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 5
  - PARENT_RECORD_SOURCE_ID 4
  - ACCESS_PATH 84:a
  - -> Filter
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select mod(id, 5),
  - sum(val)
  - from tab
  - where id <= 50
  - group by mod(id, 5)
  - order by sum(val)
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 6
  - PARENT_RECORD_SOURCE_ID 5
  - ACCESS_PATH 84:b
  - -> Table "TAB" Full Scan
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
  - PROFILE_ID 2
  - STATEMENT_ID
  - STATEMENT_TYPE BLOCK
  - PACKAGE_NAME <null>
  - ROUTINE_NAME <null>
  - PARENT_STATEMENT_ID
  - PARENT_STATEMENT_TYPE <null>
  - PARENT_ROUTINE_NAME <null>
  - SQL_TEXT
  - select mod(id, 5),
  - sum(val)
  - from tab
  - where id <= 50
  - group by mod(id, 5)
  - order by sum(val)
  - CURSOR_ID 1
  - CURSOR_NAME <null>
  - CURSOR_LINE_NUM
  - CURSOR_COLUMN_NUM
  - RECORD_SOURCE_ID 1
  - PARENT_RECORD_SOURCE_ID <null>
  - ACCESS_PATH 84:6
  - Select Expression
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - OPEN_AVG_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - FETCH_AVG_ELAPSED_TIME
  - OPEN_FETCH_TOTAL_ELAPSED_TIME
  - Records affected: 12
  - MSG --- [ 4: plg$prof_requests ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - STATEMENT_ID
  - CALLER_REQUEST_ID
  - START_TIMESTAMP
  - FINISH_TIMESTAMP
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 4: plg$prof_requests ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - STATEMENT_ID
  - CALLER_REQUEST_ID
  - START_TIMESTAMP
  - FINISH_TIMESTAMP
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 4: plg$prof_requests ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - STATEMENT_ID
  - CALLER_REQUEST_ID
  - START_TIMESTAMP
  - FINISH_TIMESTAMP
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 4: plg$prof_requests ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - STATEMENT_ID
  - CALLER_REQUEST_ID
  - START_TIMESTAMP
  - FINISH_TIMESTAMP
  - TOTAL_ELAPSED_TIME
  - Records affected: 4
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 1
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 1
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 1
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 1001
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 1000
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 500
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 1000
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
  - PROFILE_ID 1
  - REQUEST_ID
  - LINE_NUM
  - COLUMN_NUM
  - STATEMENT_ID
  - COUNTER 500
  - MIN_ELAPSED_TIME
  - MAX_ELAPSED_TIME
  - TOTAL_ELAPSED_TIME
  - Records affected: 8
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 1
  - STATEMENT_ID
  - OPEN_COUNTER 0
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 2
  - STATEMENT_ID
  - OPEN_COUNTER 0
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 1
  - STATEMENT_ID
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 2
  - STATEMENT_ID
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 3
  - STATEMENT_ID
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 4
  - STATEMENT_ID
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 5
  - STATEMENT_ID
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - MSG --- [ 6: plg$prof_record_source_stats ] ---
  - PROFILE_ID 2
  - REQUEST_ID
  - CURSOR_ID 1
  - RECORD_SOURCE_ID 6
  - STATEMENT_ID
  - OPEN_COUNTER 1
  - OPEN_MIN_ELAPSED_TIME
  - OPEN_MAX_ELAPSED_TIME
  - OPEN_TOTAL_ELAPSED_TIME
  - FETCH_COUNTER
  - FETCH_MIN_ELAPSED_TIME
  - FETCH_MAX_ELAPSED_TIME
  - FETCH_TOTAL_ELAPSED_TIME
  - Records affected: 8

LOG DETAILS:

2025-06-30 05:40:03.687
2025-06-30 05:40:03.697 act = <firebird.qa.plugin.Action object at [hex]>
2025-06-30 05:40:03.706
2025-06-30 05:40:03.719 @pytest.mark.version('>=5.0')
2025-06-30 05:40:03.730 def test_1(act: Action):
2025-06-30 05:40:03.739 act.expected_stdout = fb5x_expected_out if act.is_version('<6') else fb6x_expected_out
2025-06-30 05:40:03.746 act.execute(combine_output = True)
2025-06-30 05:40:03.753 >       assert act.clean_stdout == act.clean_expected_stdout
2025-06-30 05:40:03.760 E       assert
2025-06-30 05:40:03.771 E           START_SESSION 1
2025-06-30 05:40:03.779 E           START_SESSION 2
2025-06-30 05:40:03.787 E         + Statement failed, SQLSTATE = 42S02
2025-06-30 05:40:03.795 E         + Dynamic SQL Error
2025-06-30 05:40:03.803 E         + -SQL error code = -204
2025-06-30 05:40:03.811 E         + -Table unknown
2025-06-30 05:40:03.820 E         + -"PLG$PROF_SESSIONS"
2025-06-30 05:40:03.829 E         + -At line 5, column 10
2025-06-30 05:40:03.842 E         + Statement failed, SQLSTATE = 42S02
2025-06-30 05:40:03.853 E         + Dynamic SQL Error
2025-06-30 05:40:03.862 E         + -SQL error code = -204
2025-06-30 05:40:03.870 E         + -Table unknown
2025-06-30 05:40:03.879 E         + -"PLG$PROF_PSQL_STATS_VIEW"
2025-06-30 05:40:03.887 E         + -At line 14, column 10
2025-06-30 05:40:03.895 E         + Statement failed, SQLSTATE = 42S02
2025-06-30 05:40:03.904 E         + Dynamic SQL Error
2025-06-30 05:40:03.913 E         + -SQL error code = -204
2025-06-30 05:40:03.923 E         + -Table unknown
2025-06-30 05:40:03.937 E         + -"PLG$PROF_RECORD_SOURCE_STATS_VIEW"
2025-06-30 05:40:03.947 E         + -At line 31, column 10
2025-06-30 05:40:03.956 E         + Statement failed, SQLSTATE = 42S02
2025-06-30 05:40:03.964 E         + Dynamic SQL Error
2025-06-30 05:40:03.974 E         + -SQL error code = -204
2025-06-30 05:40:03.982 E         + -Table unknown
2025-06-30 05:40:03.990 E         + -"PLG$PROF_REQUESTS"
2025-06-30 05:40:03.996 E         + -At line 11, column 12
2025-06-30 05:40:04.002 E         + Statement failed, SQLSTATE = 42S02
2025-06-30 05:40:04.009 E         + Dynamic SQL Error
2025-06-30 05:40:04.018 E         + -SQL error code = -204
2025-06-30 05:40:04.028 E         + -Table unknown
2025-06-30 05:40:04.036 E         + -"PLG$PROF_PSQL_STATS"
2025-06-30 05:40:04.044 E         + -At line 13, column 12
2025-06-30 05:40:04.052 E         + Statement failed, SQLSTATE = 42S02
2025-06-30 05:40:04.059 E         + Dynamic SQL Error
2025-06-30 05:40:04.070 E         + -SQL error code = -204
2025-06-30 05:40:04.082 E         + -Table unknown
2025-06-30 05:40:04.091 E         + -"PLG$PROF_RECORD_SOURCE_STATS"
2025-06-30 05:40:04.098 E         + -At line 17, column 12
2025-06-30 05:40:04.103 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-06-30 05:40:04.109 E         - PROFILE_ID 1
2025-06-30 05:40:04.114 E         - ATTACHMENT_ID
2025-06-30 05:40:04.119 E         - USER_NAME SYSDBA
2025-06-30 05:40:04.127 E         - DESCRIPTION profile session 1
2025-06-30 05:40:04.132 E         - START_TIMESTAMP
2025-06-30 05:40:04.143 E         - FINISH_TIMESTAMP
2025-06-30 05:40:04.153 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-06-30 05:40:04.165 E         - PROFILE_ID 2
2025-06-30 05:40:04.175 E         - ATTACHMENT_ID
2025-06-30 05:40:04.182 E         - USER_NAME SYSDBA
2025-06-30 05:40:04.189 E         - DESCRIPTION profile session 2
2025-06-30 05:40:04.195 E         - START_TIMESTAMP
2025-06-30 05:40:04.200 E         - FINISH_TIMESTAMP
2025-06-30 05:40:04.206 E         - Records affected: 2
2025-06-30 05:40:04.211 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:04.218 E         - PROFILE_ID 1
2025-06-30 05:40:04.226 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:04.232 E         - SQL_TEXT
2025-06-30 05:40:04.238 E         - execute block
2025-06-30 05:40:04.252 E         - as
2025-06-30 05:40:04.266 E         - begin
2025-06-30 05:40:04.279 E         - execute procedure ins;
2025-06-30 05:40:04.290 E         - delete from tab;
2025-06-30 05:40:04.303 E         - end
2025-06-30 05:40:04.317 E         - LINE_NUM
2025-06-30 05:40:04.329 E         - COLUMN_NUM
2025-06-30 05:40:04.342 E         - COUNTER 1
2025-06-30 05:40:04.355 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:04.364 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:04.373 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:04.378 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:04.384 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:04.390 E         - PROFILE_ID 1
2025-06-30 05:40:04.396 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:04.402 E         - SQL_TEXT
2025-06-30 05:40:04.407 E         - execute block
2025-06-30 05:40:04.412 E         - as
2025-06-30 05:40:04.417 E         - begin
2025-06-30 05:40:04.423 E         - execute procedure ins;
2025-06-30 05:40:04.431 E         - delete from tab;
2025-06-30 05:40:04.444 E         - end
2025-06-30 05:40:04.451 E         - LINE_NUM
2025-06-30 05:40:04.458 E         - COLUMN_NUM
2025-06-30 05:40:04.469 E         - COUNTER 1
2025-06-30 05:40:04.482 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:04.493 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:04.504 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:04.517 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:04.530 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:04.541 E         - PROFILE_ID 1
2025-06-30 05:40:04.552 E         - STATEMENT_TYPE PROCEDURE
2025-06-30 05:40:04.565 E         - SQL_TEXT
2025-06-30 05:40:04.576 E         - LINE_NUM
2025-06-30 05:40:04.587 E         - COLUMN_NUM
2025-06-30 05:40:04.596 E         - COUNTER 1
2025-06-30 05:40:04.602 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:04.609 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:04.614 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:04.620 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:04.628 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:04.634 E         - PROFILE_ID 1
2025-06-30 05:40:04.640 E         - STATEMENT_TYPE PROCEDURE
2025-06-30 05:40:04.646 E         - SQL_TEXT
2025-06-30 05:40:04.653 E         - LINE_NUM
2025-06-30 05:40:04.660 E         - COLUMN_NUM
2025-06-30 05:40:04.674 E         - COUNTER 1001
2025-06-30 05:40:04.683 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:04.695 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:04.705 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:04.715 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:04.732 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:04.740 E         - PROFILE_ID 1
2025-06-30 05:40:04.747 E         - STATEMENT_TYPE PROCEDURE
2025-06-30 05:40:04.756 E         - SQL_TEXT
2025-06-30 05:40:04.767 E         - LINE_NUM
2025-06-30 05:40:04.775 E         - COLUMN_NUM
2025-06-30 05:40:04.782 E         - COUNTER 1000
2025-06-30 05:40:04.788 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:04.794 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:04.799 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:04.807 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:04.820 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:04.829 E         - PROFILE_ID 1
2025-06-30 05:40:04.837 E         - STATEMENT_TYPE PROCEDURE
2025-06-30 05:40:04.844 E         - SQL_TEXT
2025-06-30 05:40:04.851 E         - LINE_NUM
2025-06-30 05:40:04.865 E         - COLUMN_NUM
2025-06-30 05:40:04.877 E         - COUNTER 500
2025-06-30 05:40:04.885 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:04.892 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:04.899 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:04.912 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:04.923 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:04.932 E         - PROFILE_ID 1
2025-06-30 05:40:04.944 E         - STATEMENT_TYPE PROCEDURE
2025-06-30 05:40:04.953 E         - SQL_TEXT
2025-06-30 05:40:04.961 E         - LINE_NUM
2025-06-30 05:40:04.970 E         - COLUMN_NUM
2025-06-30 05:40:04.977 E         - COUNTER 1000
2025-06-30 05:40:04.984 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:04.990 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:04.996 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.006 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:05.020 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-30 05:40:05.033 E         - PROFILE_ID 1
2025-06-30 05:40:05.043 E         - STATEMENT_TYPE FUNCTION
2025-06-30 05:40:05.056 E         - SQL_TEXT
2025-06-30 05:40:05.066 E         - LINE_NUM
2025-06-30 05:40:05.074 E         - COLUMN_NUM
2025-06-30 05:40:05.081 E         - COUNTER 500
2025-06-30 05:40:05.088 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:05.095 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:05.101 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.106 E         - AVG_ELAPSED_TIME
2025-06-30 05:40:05.113 E         - Records affected: 8
2025-06-30 05:40:05.119 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:05.124 E         - PROFILE_ID 1
2025-06-30 05:40:05.130 E         - STATEMENT_ID
2025-06-30 05:40:05.137 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:05.143 E         - PACKAGE_NAME <null>
2025-06-30 05:40:05.150 E         - ROUTINE_NAME <null>
2025-06-30 05:40:05.155 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:05.161 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:05.169 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:05.179 E         - SQL_TEXT
2025-06-30 05:40:05.188 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-06-30 05:40:05.197 E         - CURSOR_ID 1
2025-06-30 05:40:05.205 E         - CURSOR_NAME <null>
2025-06-30 05:40:05.212 E         - CURSOR_LINE_NUM
2025-06-30 05:40:05.219 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:05.227 E         - RECORD_SOURCE_ID 2
2025-06-30 05:40:05.234 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-30 05:40:05.242 E         - ACCESS_PATH 84:1
2025-06-30 05:40:05.250 E         - -> Table "RDB$DATABASE" Full Scan
2025-06-30 05:40:05.261 E         - OPEN_COUNTER 0
2025-06-30 05:40:05.274 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:05.284 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:05.295 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.306 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:05.315 E         - FETCH_COUNTER
2025-06-30 05:40:05.325 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:05.336 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:05.348 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.361 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:05.372 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.382 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:05.394 E         - PROFILE_ID 1
2025-06-30 05:40:05.404 E         - STATEMENT_ID
2025-06-30 05:40:05.412 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:05.426 E         - PACKAGE_NAME <null>
2025-06-30 05:40:05.439 E         - ROUTINE_NAME <null>
2025-06-30 05:40:05.452 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:05.466 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:05.476 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:05.485 E         - SQL_TEXT
2025-06-30 05:40:05.492 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-06-30 05:40:05.499 E         - CURSOR_ID 1
2025-06-30 05:40:05.514 E         - CURSOR_NAME <null>
2025-06-30 05:40:05.526 E         - CURSOR_LINE_NUM
2025-06-30 05:40:05.538 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:05.549 E         - RECORD_SOURCE_ID 1
2025-06-30 05:40:05.560 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-30 05:40:05.573 E         - ACCESS_PATH 84:0
2025-06-30 05:40:05.584 E         - Select Expression
2025-06-30 05:40:05.593 E         - OPEN_COUNTER 0
2025-06-30 05:40:05.600 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:05.611 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:05.626 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.640 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:05.652 E         - FETCH_COUNTER
2025-06-30 05:40:05.664 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:05.674 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:05.684 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.696 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:05.708 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:05.721 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:05.732 E         - PROFILE_ID 1
2025-06-30 05:40:05.741 E         - STATEMENT_ID
2025-06-30 05:40:05.748 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:05.755 E         - PACKAGE_NAME <null>
2025-06-30 05:40:05.761 E         - ROUTINE_NAME <null>
2025-06-30 05:40:05.767 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:05.775 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:05.787 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:05.801 E         - SQL_TEXT
2025-06-30 05:40:05.813 E         - execute block
2025-06-30 05:40:05.824 E         - as
2025-06-30 05:40:05.833 E         - begin
2025-06-30 05:40:05.841 E         - execute procedure ins;
2025-06-30 05:40:05.848 E         - delete from tab;
2025-06-30 05:40:05.862 E         - end
2025-06-30 05:40:05.875 E         - CURSOR_ID 1
2025-06-30 05:40:05.887 E         - CURSOR_NAME <null>
2025-06-30 05:40:05.900 E         - CURSOR_LINE_NUM
2025-06-30 05:40:05.911 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:05.920 E         - RECORD_SOURCE_ID 2
2025-06-30 05:40:05.928 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-30 05:40:05.935 E         - ACCESS_PATH 84:3
2025-06-30 05:40:05.942 E         - -> Table "TAB" Full Scan
2025-06-30 05:40:05.952 E         - OPEN_COUNTER 1
2025-06-30 05:40:05.964 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:05.975 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:05.986 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.000 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:06.010 E         - FETCH_COUNTER
2025-06-30 05:40:06.019 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:06.027 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:06.041 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.054 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:06.064 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.073 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:06.081 E         - PROFILE_ID 1
2025-06-30 05:40:06.088 E         - STATEMENT_ID
2025-06-30 05:40:06.094 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:06.100 E         - PACKAGE_NAME <null>
2025-06-30 05:40:06.106 E         - ROUTINE_NAME <null>
2025-06-30 05:40:06.117 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:06.126 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:06.133 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:06.140 E         - SQL_TEXT
2025-06-30 05:40:06.151 E         - execute block
2025-06-30 05:40:06.161 E         - as
2025-06-30 05:40:06.169 E         - begin
2025-06-30 05:40:06.175 E         - execute procedure ins;
2025-06-30 05:40:06.181 E         - delete from tab;
2025-06-30 05:40:06.189 E         - end
2025-06-30 05:40:06.196 E         - CURSOR_ID 1
2025-06-30 05:40:06.203 E         - CURSOR_NAME <null>
2025-06-30 05:40:06.210 E         - CURSOR_LINE_NUM
2025-06-30 05:40:06.221 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:06.230 E         - RECORD_SOURCE_ID 1
2025-06-30 05:40:06.238 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-30 05:40:06.244 E         - ACCESS_PATH 84:2
2025-06-30 05:40:06.249 E         - Select Expression (line 5, column 9)
2025-06-30 05:40:06.256 E         - OPEN_COUNTER 1
2025-06-30 05:40:06.263 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:06.271 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:06.278 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.289 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:06.298 E         - FETCH_COUNTER
2025-06-30 05:40:06.305 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:06.312 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:06.316 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.330 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:06.339 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.350 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:06.360 E         - PROFILE_ID 2
2025-06-30 05:40:06.373 E         - STATEMENT_ID
2025-06-30 05:40:06.385 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:06.398 E         - PACKAGE_NAME <null>
2025-06-30 05:40:06.408 E         - ROUTINE_NAME <null>
2025-06-30 05:40:06.415 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:06.424 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:06.437 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:06.447 E         - SQL_TEXT
2025-06-30 05:40:06.460 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-06-30 05:40:06.467 E         - CURSOR_ID 1
2025-06-30 05:40:06.474 E         - CURSOR_NAME <null>
2025-06-30 05:40:06.484 E         - CURSOR_LINE_NUM
2025-06-30 05:40:06.494 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:06.500 E         - RECORD_SOURCE_ID 2
2025-06-30 05:40:06.507 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-30 05:40:06.513 E         - ACCESS_PATH 84:5
2025-06-30 05:40:06.519 E         - -> Table "RDB$DATABASE" Full Scan
2025-06-30 05:40:06.525 E         - OPEN_COUNTER 0
2025-06-30 05:40:06.531 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:06.538 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:06.550 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.562 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:06.572 E         - FETCH_COUNTER
2025-06-30 05:40:06.580 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:06.587 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:06.594 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.601 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:06.607 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.614 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:06.623 E         - PROFILE_ID 2
2025-06-30 05:40:06.632 E         - STATEMENT_ID
2025-06-30 05:40:06.640 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:06.646 E         - PACKAGE_NAME <null>
2025-06-30 05:40:06.653 E         - ROUTINE_NAME <null>
2025-06-30 05:40:06.659 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:06.667 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:06.675 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:06.684 E         - SQL_TEXT
2025-06-30 05:40:06.697 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-06-30 05:40:06.708 E         - CURSOR_ID 1
2025-06-30 05:40:06.717 E         - CURSOR_NAME <null>
2025-06-30 05:40:06.722 E         - CURSOR_LINE_NUM
2025-06-30 05:40:06.727 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:06.733 E         - RECORD_SOURCE_ID 1
2025-06-30 05:40:06.738 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-30 05:40:06.744 E         - ACCESS_PATH 84:4
2025-06-30 05:40:06.750 E         - Select Expression
2025-06-30 05:40:06.760 E         - OPEN_COUNTER 0
2025-06-30 05:40:06.773 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:06.783 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:06.792 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.800 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:06.806 E         - FETCH_COUNTER
2025-06-30 05:40:06.813 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:06.820 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:06.827 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.835 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:06.846 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:06.855 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:06.864 E         - PROFILE_ID 2
2025-06-30 05:40:06.871 E         - STATEMENT_ID
2025-06-30 05:40:06.883 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:06.894 E         - PACKAGE_NAME <null>
2025-06-30 05:40:06.903 E         - ROUTINE_NAME <null>
2025-06-30 05:40:06.911 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:06.918 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:06.930 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:06.940 E         - SQL_TEXT
2025-06-30 05:40:06.948 E         - select mod(id, 5),
2025-06-30 05:40:06.955 E         - sum(val)
2025-06-30 05:40:06.962 E         - from tab
2025-06-30 05:40:06.974 E         - where id <= 50
2025-06-30 05:40:06.985 E         - group by mod(id, 5)
2025-06-30 05:40:06.995 E         - order by sum(val)
2025-06-30 05:40:07.006 E         - CURSOR_ID 1
2025-06-30 05:40:07.019 E         - CURSOR_NAME <null>
2025-06-30 05:40:07.030 E         - CURSOR_LINE_NUM
2025-06-30 05:40:07.043 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:07.053 E         - RECORD_SOURCE_ID 2
2025-06-30 05:40:07.065 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-30 05:40:07.077 E         - ACCESS_PATH 84:7
2025-06-30 05:40:07.089 E         - -> Sort (record length: 44, key length: 12)
2025-06-30 05:40:07.099 E         - OPEN_COUNTER 1
2025-06-30 05:40:07.114 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:07.125 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:07.139 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.153 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:07.166 E         - FETCH_COUNTER
2025-06-30 05:40:07.180 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:07.191 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:07.200 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.208 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:07.214 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.228 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:07.241 E         - PROFILE_ID 2
2025-06-30 05:40:07.255 E         - STATEMENT_ID
2025-06-30 05:40:07.262 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:07.273 E         - PACKAGE_NAME <null>
2025-06-30 05:40:07.285 E         - ROUTINE_NAME <null>
2025-06-30 05:40:07.295 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:07.305 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:07.318 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:07.332 E         - SQL_TEXT
2025-06-30 05:40:07.345 E         - select mod(id, 5),
2025-06-30 05:40:07.357 E         - sum(val)
2025-06-30 05:40:07.363 E         - from tab
2025-06-30 05:40:07.370 E         - where id <= 50
2025-06-30 05:40:07.383 E         - group by mod(id, 5)
2025-06-30 05:40:07.393 E         - order by sum(val)
2025-06-30 05:40:07.406 E         - CURSOR_ID 1
2025-06-30 05:40:07.415 E         - CURSOR_NAME <null>
2025-06-30 05:40:07.423 E         - CURSOR_LINE_NUM
2025-06-30 05:40:07.431 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:07.437 E         - RECORD_SOURCE_ID 3
2025-06-30 05:40:07.443 E         - PARENT_RECORD_SOURCE_ID 2
2025-06-30 05:40:07.450 E         - ACCESS_PATH 84:8
2025-06-30 05:40:07.460 E         - -> Aggregate
2025-06-30 05:40:07.471 E         - OPEN_COUNTER 1
2025-06-30 05:40:07.480 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:07.488 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:07.499 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.508 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:07.517 E         - FETCH_COUNTER
2025-06-30 05:40:07.525 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:07.532 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:07.539 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.546 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:07.558 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.571 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:07.581 E         - PROFILE_ID 2
2025-06-30 05:40:07.593 E         - STATEMENT_ID
2025-06-30 05:40:07.605 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:07.617 E         - PACKAGE_NAME <null>
2025-06-30 05:40:07.627 E         - ROUTINE_NAME <null>
2025-06-30 05:40:07.638 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:07.651 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:07.658 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:07.672 E         - SQL_TEXT
2025-06-30 05:40:07.685 E         - select mod(id, 5),
2025-06-30 05:40:07.692 E         - sum(val)
2025-06-30 05:40:07.699 E         - from tab
2025-06-30 05:40:07.705 E         - where id <= 50
2025-06-30 05:40:07.711 E         - group by mod(id, 5)
2025-06-30 05:40:07.718 E         - order by sum(val)
2025-06-30 05:40:07.724 E         - CURSOR_ID 1
2025-06-30 05:40:07.729 E         - CURSOR_NAME <null>
2025-06-30 05:40:07.735 E         - CURSOR_LINE_NUM
2025-06-30 05:40:07.741 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:07.746 E         - RECORD_SOURCE_ID 4
2025-06-30 05:40:07.751 E         - PARENT_RECORD_SOURCE_ID 3
2025-06-30 05:40:07.759 E         - ACCESS_PATH 84:9
2025-06-30 05:40:07.771 E         - -> Sort (record length: 44, key length: 8)
2025-06-30 05:40:07.778 E         - OPEN_COUNTER 1
2025-06-30 05:40:07.787 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:07.799 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:07.810 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.817 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:07.826 E         - FETCH_COUNTER
2025-06-30 05:40:07.837 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:07.851 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:07.860 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.868 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:07.875 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:07.883 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:07.894 E         - PROFILE_ID 2
2025-06-30 05:40:07.902 E         - STATEMENT_ID
2025-06-30 05:40:07.911 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:07.919 E         - PACKAGE_NAME <null>
2025-06-30 05:40:07.927 E         - ROUTINE_NAME <null>
2025-06-30 05:40:07.938 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:07.951 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:07.961 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:07.967 E         - SQL_TEXT
2025-06-30 05:40:07.972 E         - select mod(id, 5),
2025-06-30 05:40:07.976 E         - sum(val)
2025-06-30 05:40:07.981 E         - from tab
2025-06-30 05:40:07.986 E         - where id <= 50
2025-06-30 05:40:07.990 E         - group by mod(id, 5)
2025-06-30 05:40:07.995 E         - order by sum(val)
2025-06-30 05:40:08.000 E         - CURSOR_ID 1
2025-06-30 05:40:08.006 E         - CURSOR_NAME <null>
2025-06-30 05:40:08.011 E         - CURSOR_LINE_NUM
2025-06-30 05:40:08.016 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:08.028 E         - RECORD_SOURCE_ID 5
2025-06-30 05:40:08.037 E         - PARENT_RECORD_SOURCE_ID 4
2025-06-30 05:40:08.045 E         - ACCESS_PATH 84:a
2025-06-30 05:40:08.055 E         - -> Filter
2025-06-30 05:40:08.069 E         - OPEN_COUNTER 1
2025-06-30 05:40:08.081 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:08.089 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:08.095 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.103 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:08.110 E         - FETCH_COUNTER
2025-06-30 05:40:08.120 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:08.128 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:08.138 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.147 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:08.155 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.161 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:08.166 E         - PROFILE_ID 2
2025-06-30 05:40:08.171 E         - STATEMENT_ID
2025-06-30 05:40:08.176 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:08.182 E         - PACKAGE_NAME <null>
2025-06-30 05:40:08.188 E         - ROUTINE_NAME <null>
2025-06-30 05:40:08.194 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:08.201 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:08.207 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:08.215 E         - SQL_TEXT
2025-06-30 05:40:08.222 E         - select mod(id, 5),
2025-06-30 05:40:08.230 E         - sum(val)
2025-06-30 05:40:08.238 E         - from tab
2025-06-30 05:40:08.245 E         - where id <= 50
2025-06-30 05:40:08.250 E         - group by mod(id, 5)
2025-06-30 05:40:08.255 E         - order by sum(val)
2025-06-30 05:40:08.261 E         - CURSOR_ID 1
2025-06-30 05:40:08.268 E         - CURSOR_NAME <null>
2025-06-30 05:40:08.274 E         - CURSOR_LINE_NUM
2025-06-30 05:40:08.283 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:08.292 E         - RECORD_SOURCE_ID 6
2025-06-30 05:40:08.303 E         - PARENT_RECORD_SOURCE_ID 5
2025-06-30 05:40:08.312 E         - ACCESS_PATH 84:b
2025-06-30 05:40:08.320 E         - -> Table "TAB" Full Scan
2025-06-30 05:40:08.327 E         - OPEN_COUNTER 1
2025-06-30 05:40:08.333 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:08.348 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:08.358 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.366 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:08.375 E         - FETCH_COUNTER
2025-06-30 05:40:08.385 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:08.394 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:08.407 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.417 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:08.425 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.432 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-30 05:40:08.438 E         - PROFILE_ID 2
2025-06-30 05:40:08.444 E         - STATEMENT_ID
2025-06-30 05:40:08.451 E         - STATEMENT_TYPE BLOCK
2025-06-30 05:40:08.457 E         - PACKAGE_NAME <null>
2025-06-30 05:40:08.464 E         - ROUTINE_NAME <null>
2025-06-30 05:40:08.470 E         - PARENT_STATEMENT_ID
2025-06-30 05:40:08.479 E         - PARENT_STATEMENT_TYPE <null>
2025-06-30 05:40:08.491 E         - PARENT_ROUTINE_NAME <null>
2025-06-30 05:40:08.502 E         - SQL_TEXT
2025-06-30 05:40:08.513 E         - select mod(id, 5),
2025-06-30 05:40:08.526 E         - sum(val)
2025-06-30 05:40:08.535 E         - from tab
2025-06-30 05:40:08.542 E         - where id <= 50
2025-06-30 05:40:08.552 E         - group by mod(id, 5)
2025-06-30 05:40:08.563 E         - order by sum(val)
2025-06-30 05:40:08.573 E         - CURSOR_ID 1
2025-06-30 05:40:08.580 E         - CURSOR_NAME <null>
2025-06-30 05:40:08.587 E         - CURSOR_LINE_NUM
2025-06-30 05:40:08.594 E         - CURSOR_COLUMN_NUM
2025-06-30 05:40:08.601 E         - RECORD_SOURCE_ID 1
2025-06-30 05:40:08.607 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-30 05:40:08.620 E         - ACCESS_PATH 84:6
2025-06-30 05:40:08.629 E         - Select Expression
2025-06-30 05:40:08.635 E         - OPEN_COUNTER 1
2025-06-30 05:40:08.642 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:08.648 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:08.659 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.665 E         - OPEN_AVG_ELAPSED_TIME
2025-06-30 05:40:08.670 E         - FETCH_COUNTER
2025-06-30 05:40:08.677 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:08.684 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:08.690 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.696 E         - FETCH_AVG_ELAPSED_TIME
2025-06-30 05:40:08.702 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.712 E         - Records affected: 12
2025-06-30 05:40:08.722 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-30 05:40:08.731 E         - PROFILE_ID 1
2025-06-30 05:40:08.738 E         - REQUEST_ID
2025-06-30 05:40:08.753 E         - STATEMENT_ID
2025-06-30 05:40:08.767 E         - CALLER_REQUEST_ID
2025-06-30 05:40:08.775 E         - START_TIMESTAMP
2025-06-30 05:40:08.783 E         - FINISH_TIMESTAMP
2025-06-30 05:40:08.791 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.798 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-30 05:40:08.806 E         - PROFILE_ID 1
2025-06-30 05:40:08.814 E         - REQUEST_ID
2025-06-30 05:40:08.823 E         - STATEMENT_ID
2025-06-30 05:40:08.837 E         - CALLER_REQUEST_ID
2025-06-30 05:40:08.849 E         - START_TIMESTAMP
2025-06-30 05:40:08.860 E         - FINISH_TIMESTAMP
2025-06-30 05:40:08.868 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.876 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-30 05:40:08.881 E         - PROFILE_ID 1
2025-06-30 05:40:08.887 E         - REQUEST_ID
2025-06-30 05:40:08.892 E         - STATEMENT_ID
2025-06-30 05:40:08.897 E         - CALLER_REQUEST_ID
2025-06-30 05:40:08.903 E         - START_TIMESTAMP
2025-06-30 05:40:08.909 E         - FINISH_TIMESTAMP
2025-06-30 05:40:08.920 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.929 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-30 05:40:08.937 E         - PROFILE_ID 1
2025-06-30 05:40:08.943 E         - REQUEST_ID
2025-06-30 05:40:08.950 E         - STATEMENT_ID
2025-06-30 05:40:08.958 E         - CALLER_REQUEST_ID
2025-06-30 05:40:08.964 E         - START_TIMESTAMP
2025-06-30 05:40:08.971 E         - FINISH_TIMESTAMP
2025-06-30 05:40:08.978 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:08.989 E         - Records affected: 4
2025-06-30 05:40:08.997 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.010 E         - PROFILE_ID 1
2025-06-30 05:40:09.024 E         - REQUEST_ID
2025-06-30 05:40:09.034 E         - LINE_NUM
2025-06-30 05:40:09.044 E         - COLUMN_NUM
2025-06-30 05:40:09.058 E         - STATEMENT_ID
2025-06-30 05:40:09.069 E         - COUNTER 1
2025-06-30 05:40:09.078 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.085 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.093 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.100 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.107 E         - PROFILE_ID 1
2025-06-30 05:40:09.113 E         - REQUEST_ID
2025-06-30 05:40:09.120 E         - LINE_NUM
2025-06-30 05:40:09.128 E         - COLUMN_NUM
2025-06-30 05:40:09.142 E         - STATEMENT_ID
2025-06-30 05:40:09.153 E         - COUNTER 1
2025-06-30 05:40:09.164 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.178 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.187 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.200 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.210 E         - PROFILE_ID 1
2025-06-30 05:40:09.219 E         - REQUEST_ID
2025-06-30 05:40:09.226 E         - LINE_NUM
2025-06-30 05:40:09.235 E         - COLUMN_NUM
2025-06-30 05:40:09.248 E         - STATEMENT_ID
2025-06-30 05:40:09.260 E         - COUNTER 1
2025-06-30 05:40:09.270 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.282 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.293 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.303 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.314 E         - PROFILE_ID 1
2025-06-30 05:40:09.324 E         - REQUEST_ID
2025-06-30 05:40:09.332 E         - LINE_NUM
2025-06-30 05:40:09.340 E         - COLUMN_NUM
2025-06-30 05:40:09.347 E         - STATEMENT_ID
2025-06-30 05:40:09.355 E         - COUNTER 1001
2025-06-30 05:40:09.364 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.377 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.385 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.393 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.400 E         - PROFILE_ID 1
2025-06-30 05:40:09.407 E         - REQUEST_ID
2025-06-30 05:40:09.414 E         - LINE_NUM
2025-06-30 05:40:09.430 E         - COLUMN_NUM
2025-06-30 05:40:09.440 E         - STATEMENT_ID
2025-06-30 05:40:09.448 E         - COUNTER 1000
2025-06-30 05:40:09.456 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.463 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.477 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.490 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.500 E         - PROFILE_ID 1
2025-06-30 05:40:09.508 E         - REQUEST_ID
2025-06-30 05:40:09.516 E         - LINE_NUM
2025-06-30 05:40:09.525 E         - COLUMN_NUM
2025-06-30 05:40:09.538 E         - STATEMENT_ID
2025-06-30 05:40:09.551 E         - COUNTER 500
2025-06-30 05:40:09.562 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.575 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.586 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.596 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.604 E         - PROFILE_ID 1
2025-06-30 05:40:09.612 E         - REQUEST_ID
2025-06-30 05:40:09.619 E         - LINE_NUM
2025-06-30 05:40:09.631 E         - COLUMN_NUM
2025-06-30 05:40:09.639 E         - STATEMENT_ID
2025-06-30 05:40:09.646 E         - COUNTER 1000
2025-06-30 05:40:09.653 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.660 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.667 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.674 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-30 05:40:09.683 E         - PROFILE_ID 1
2025-06-30 05:40:09.691 E         - REQUEST_ID
2025-06-30 05:40:09.698 E         - LINE_NUM
2025-06-30 05:40:09.711 E         - COLUMN_NUM
2025-06-30 05:40:09.719 E         - STATEMENT_ID
2025-06-30 05:40:09.732 E         - COUNTER 500
2025-06-30 05:40:09.741 E         - MIN_ELAPSED_TIME
2025-06-30 05:40:09.749 E         - MAX_ELAPSED_TIME
2025-06-30 05:40:09.763 E         - TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.773 E         - Records affected: 8
2025-06-30 05:40:09.779 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:09.785 E         - PROFILE_ID 2
2025-06-30 05:40:09.790 E         - REQUEST_ID
2025-06-30 05:40:09.795 E         - CURSOR_ID 1
2025-06-30 05:40:09.801 E         - RECORD_SOURCE_ID 1
2025-06-30 05:40:09.806 E         - STATEMENT_ID
2025-06-30 05:40:09.812 E         - OPEN_COUNTER 0
2025-06-30 05:40:09.817 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:09.824 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:09.831 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.838 E         - FETCH_COUNTER
2025-06-30 05:40:09.847 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:09.859 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:09.868 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.875 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:09.882 E         - PROFILE_ID 2
2025-06-30 05:40:09.891 E         - REQUEST_ID
2025-06-30 05:40:09.897 E         - CURSOR_ID 1
2025-06-30 05:40:09.904 E         - RECORD_SOURCE_ID 2
2025-06-30 05:40:09.911 E         - STATEMENT_ID
2025-06-30 05:40:09.924 E         - OPEN_COUNTER 0
2025-06-30 05:40:09.931 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:09.937 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:09.945 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.952 E         - FETCH_COUNTER
2025-06-30 05:40:09.960 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:09.967 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:09.975 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:09.983 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:09.996 E         - PROFILE_ID 2
2025-06-30 05:40:10.006 E         - REQUEST_ID
2025-06-30 05:40:10.018 E         - CURSOR_ID 1
2025-06-30 05:40:10.028 E         - RECORD_SOURCE_ID 1
2025-06-30 05:40:10.037 E         - STATEMENT_ID
2025-06-30 05:40:10.045 E         - OPEN_COUNTER 1
2025-06-30 05:40:10.057 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:10.069 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:10.082 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.096 E         - FETCH_COUNTER
2025-06-30 05:40:10.105 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:10.112 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:10.118 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.127 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:10.142 E         - PROFILE_ID 2
2025-06-30 05:40:10.152 E         - REQUEST_ID
2025-06-30 05:40:10.159 E         - CURSOR_ID 1
2025-06-30 05:40:10.165 E         - RECORD_SOURCE_ID 2
2025-06-30 05:40:10.170 E         - STATEMENT_ID
2025-06-30 05:40:10.176 E         - OPEN_COUNTER 1
2025-06-30 05:40:10.182 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:10.189 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:10.198 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.206 E         - FETCH_COUNTER
2025-06-30 05:40:10.220 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:10.231 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:10.241 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.248 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:10.255 E         - PROFILE_ID 2
2025-06-30 05:40:10.261 E         - REQUEST_ID
2025-06-30 05:40:10.268 E         - CURSOR_ID 1
2025-06-30 05:40:10.275 E         - RECORD_SOURCE_ID 3
2025-06-30 05:40:10.286 E         - STATEMENT_ID
2025-06-30 05:40:10.295 E         - OPEN_COUNTER 1
2025-06-30 05:40:10.303 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:10.313 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:10.323 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.335 E         - FETCH_COUNTER
2025-06-30 05:40:10.347 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:10.359 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:10.368 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.376 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:10.383 E         - PROFILE_ID 2
2025-06-30 05:40:10.391 E         - REQUEST_ID
2025-06-30 05:40:10.401 E         - CURSOR_ID 1
2025-06-30 05:40:10.413 E         - RECORD_SOURCE_ID 4
2025-06-30 05:40:10.422 E         - STATEMENT_ID
2025-06-30 05:40:10.429 E         - OPEN_COUNTER 1
2025-06-30 05:40:10.436 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:10.443 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:10.454 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.463 E         - FETCH_COUNTER
2025-06-30 05:40:10.470 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:10.479 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:10.491 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.501 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:10.514 E         - PROFILE_ID 2
2025-06-30 05:40:10.528 E         - REQUEST_ID
2025-06-30 05:40:10.541 E         - CURSOR_ID 1
2025-06-30 05:40:10.550 E         - RECORD_SOURCE_ID 5
2025-06-30 05:40:10.562 E         - STATEMENT_ID
2025-06-30 05:40:10.569 E         - OPEN_COUNTER 1
2025-06-30 05:40:10.576 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:10.583 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:10.593 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.599 E         - FETCH_COUNTER
2025-06-30 05:40:10.610 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:10.624 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:10.633 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.641 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-30 05:40:10.651 E         - PROFILE_ID 2
2025-06-30 05:40:10.659 E         - REQUEST_ID
2025-06-30 05:40:10.668 E         - CURSOR_ID 1
2025-06-30 05:40:10.678 E         - RECORD_SOURCE_ID 6
2025-06-30 05:40:10.685 E         - STATEMENT_ID
2025-06-30 05:40:10.699 E         - OPEN_COUNTER 1
2025-06-30 05:40:10.710 E         - OPEN_MIN_ELAPSED_TIME
2025-06-30 05:40:10.723 E         - OPEN_MAX_ELAPSED_TIME
2025-06-30 05:40:10.732 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.747 E         - FETCH_COUNTER
2025-06-30 05:40:10.758 E         - FETCH_MIN_ELAPSED_TIME
2025-06-30 05:40:10.768 E         - FETCH_MAX_ELAPSED_TIME
2025-06-30 05:40:10.777 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-30 05:40:10.785 E         - Records affected: 8
2025-06-30 05:40:10.791
2025-06-30 05:40:10.804 tests/bugs/gh_7086_test.py:1795: AssertionError
2025-06-30 05:40:10.813 ---------------------------- Captured stdout setup -----------------------------
2025-06-30 05:40:10.821 Creating db: localhost:/var/tmp/qa_2024/test_11498/test.fdb [page_size=None, sql_dialect=None, charset='NONE', user=SYSDBA, password=masterkey]
3 #text
act = <firebird.qa.plugin.Action pytest object at [hex]>

    @pytest.mark.version('>=5.0')
    def test_1(act: Action):
        act.expected_stdout = fb5x_expected_out if act.is_version('<6') else fb6x_expected_out
        act.execute(combine_output = True)
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E           START_SESSION 1
E           START_SESSION 2
E         + Statement failed, SQLSTATE = 42S02
E         + Dynamic SQL Error
E         + -SQL error code = -204
E         + -Table unknown
E         + -"PLG$PROF_SESSIONS"
E         + -At line 5, column 10
E         + Statement failed, SQLSTATE = 42S02
E         + Dynamic SQL Error
E         + -SQL error code = -204
E         + -Table unknown
E         + -"PLG$PROF_PSQL_STATS_VIEW"
E         + -At line 14, column 10
E         + Statement failed, SQLSTATE = 42S02
E         + Dynamic SQL Error
E         + -SQL error code = -204
E         + -Table unknown
E         + -"PLG$PROF_RECORD_SOURCE_STATS_VIEW"
E         + -At line 31, column 10
E         + Statement failed, SQLSTATE = 42S02
E         + Dynamic SQL Error
E         + -SQL error code = -204
E         + -Table unknown
E         + -"PLG$PROF_REQUESTS"
E         + -At line 11, column 12
E         + Statement failed, SQLSTATE = 42S02
E         + Dynamic SQL Error
E         + -SQL error code = -204
E         + -Table unknown
E         + -"PLG$PROF_PSQL_STATS"
E         + -At line 13, column 12
E         + Statement failed, SQLSTATE = 42S02
E         + Dynamic SQL Error
E         + -SQL error code = -204
E         + -Table unknown
E         + -"PLG$PROF_RECORD_SOURCE_STATS"
E         + -At line 17, column 12
E         - MSG --- [ 1: plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - ATTACHMENT_ID
E         - USER_NAME SYSDBA
E         - DESCRIPTION profile session 1
E         - START_TIMESTAMP
E         - FINISH_TIMESTAMP
E         - MSG --- [ 1: plg$prof_sessions ] ---
E         - PROFILE_ID 2
E         - ATTACHMENT_ID
E         - USER_NAME SYSDBA
E         - DESCRIPTION profile session 2
E         - START_TIMESTAMP
E         - FINISH_TIMESTAMP
E         - Records affected: 2
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE BLOCK
E         - SQL_TEXT
E         - execute block
E         - as
E         - begin
E         - execute procedure ins;
E         - delete from tab;
E         - end
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 1
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE BLOCK
E         - SQL_TEXT
E         - execute block
E         - as
E         - begin
E         - execute procedure ins;
E         - delete from tab;
E         - end
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 1
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE PROCEDURE
E         - SQL_TEXT
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 1
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE PROCEDURE
E         - SQL_TEXT
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 1001
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE PROCEDURE
E         - SQL_TEXT
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 1000
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE PROCEDURE
E         - SQL_TEXT
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 500
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE PROCEDURE
E         - SQL_TEXT
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 1000
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_TYPE FUNCTION
E         - SQL_TEXT
E         - LINE_NUM
E         - COLUMN_NUM
E         - COUNTER 500
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - AVG_ELAPSED_TIME
E         - Records affected: 8
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select rdb$profiler.start_session('profile session 1') from rdb$database
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 2
E         - PARENT_RECORD_SOURCE_ID 1
E         - ACCESS_PATH 84:1
E         - -> Table "RDB$DATABASE" Full Scan
E         - OPEN_COUNTER 0
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select rdb$profiler.start_session('profile session 1') from rdb$database
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 1
E         - PARENT_RECORD_SOURCE_ID <null>
E         - ACCESS_PATH 84:0
E         - Select Expression
E         - OPEN_COUNTER 0
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - execute block
E         - as
E         - begin
E         - execute procedure ins;
E         - delete from tab;
E         - end
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 2
E         - PARENT_RECORD_SOURCE_ID 1
E         - ACCESS_PATH 84:3
E         - -> Table "TAB" Full Scan
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 1
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - execute block
E         - as
E         - begin
E         - execute procedure ins;
E         - delete from tab;
E         - end
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 1
E         - PARENT_RECORD_SOURCE_ID <null>
E         - ACCESS_PATH 84:2
E         - Select Expression (line 5, column 9)
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select rdb$profiler.start_session('profile session 2') from rdb$database
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 2
E         - PARENT_RECORD_SOURCE_ID 1
E         - ACCESS_PATH 84:5
E         - -> Table "RDB$DATABASE" Full Scan
E         - OPEN_COUNTER 0
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select rdb$profiler.start_session('profile session 2') from rdb$database
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 1
E         - PARENT_RECORD_SOURCE_ID <null>
E         - ACCESS_PATH 84:4
E         - Select Expression
E         - OPEN_COUNTER 0
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select mod(id, 5),
E         - sum(val)
E         - from tab
E         - where id <= 50
E         - group by mod(id, 5)
E         - order by sum(val)
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 2
E         - PARENT_RECORD_SOURCE_ID 1
E         - ACCESS_PATH 84:7
E         - -> Sort (record length: 44, key length: 12)
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select mod(id, 5),
E         - sum(val)
E         - from tab
E         - where id <= 50
E         - group by mod(id, 5)
E         - order by sum(val)
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 3
E         - PARENT_RECORD_SOURCE_ID 2
E         - ACCESS_PATH 84:8
E         - -> Aggregate
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select mod(id, 5),
E         - sum(val)
E         - from tab
E         - where id <= 50
E         - group by mod(id, 5)
E         - order by sum(val)
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 4
E         - PARENT_RECORD_SOURCE_ID 3
E         - ACCESS_PATH 84:9
E         - -> Sort (record length: 44, key length: 8)
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select mod(id, 5),
E         - sum(val)
E         - from tab
E         - where id <= 50
E         - group by mod(id, 5)
E         - order by sum(val)
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 5
E         - PARENT_RECORD_SOURCE_ID 4
E         - ACCESS_PATH 84:a
E         - -> Filter
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select mod(id, 5),
E         - sum(val)
E         - from tab
E         - where id <= 50
E         - group by mod(id, 5)
E         - order by sum(val)
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 6
E         - PARENT_RECORD_SOURCE_ID 5
E         - ACCESS_PATH 84:b
E         - -> Table "TAB" Full Scan
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
E         - PROFILE_ID 2
E         - STATEMENT_ID
E         - STATEMENT_TYPE BLOCK
E         - PACKAGE_NAME <null>
E         - ROUTINE_NAME <null>
E         - PARENT_STATEMENT_ID
E         - PARENT_STATEMENT_TYPE <null>
E         - PARENT_ROUTINE_NAME <null>
E         - SQL_TEXT
E         - select mod(id, 5),
E         - sum(val)
E         - from tab
E         - where id <= 50
E         - group by mod(id, 5)
E         - order by sum(val)
E         - CURSOR_ID 1
E         - CURSOR_NAME <null>
E         - CURSOR_LINE_NUM
E         - CURSOR_COLUMN_NUM
E         - RECORD_SOURCE_ID 1
E         - PARENT_RECORD_SOURCE_ID <null>
E         - ACCESS_PATH 84:6
E         - Select Expression
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - OPEN_AVG_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - FETCH_AVG_ELAPSED_TIME
E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
E         - Records affected: 12
E         - MSG --- [ 4: plg$prof_requests ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - STATEMENT_ID
E         - CALLER_REQUEST_ID
E         - START_TIMESTAMP
E         - FINISH_TIMESTAMP
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 4: plg$prof_requests ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - STATEMENT_ID
E         - CALLER_REQUEST_ID
E         - START_TIMESTAMP
E         - FINISH_TIMESTAMP
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 4: plg$prof_requests ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - STATEMENT_ID
E         - CALLER_REQUEST_ID
E         - START_TIMESTAMP
E         - FINISH_TIMESTAMP
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 4: plg$prof_requests ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - STATEMENT_ID
E         - CALLER_REQUEST_ID
E         - START_TIMESTAMP
E         - FINISH_TIMESTAMP
E         - TOTAL_ELAPSED_TIME
E         - Records affected: 4
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 1
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 1
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 1
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 1001
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 1000
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 500
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 1000
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
E         - PROFILE_ID 1
E         - REQUEST_ID
E         - LINE_NUM
E         - COLUMN_NUM
E         - STATEMENT_ID
E         - COUNTER 500
E         - MIN_ELAPSED_TIME
E         - MAX_ELAPSED_TIME
E         - TOTAL_ELAPSED_TIME
E         - Records affected: 8
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 1
E         - STATEMENT_ID
E         - OPEN_COUNTER 0
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 2
E         - STATEMENT_ID
E         - OPEN_COUNTER 0
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 1
E         - STATEMENT_ID
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 2
E         - STATEMENT_ID
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 3
E         - STATEMENT_ID
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 4
E         - STATEMENT_ID
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 5
E         - STATEMENT_ID
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
E         - PROFILE_ID 2
E         - REQUEST_ID
E         - CURSOR_ID 1
E         - RECORD_SOURCE_ID 6
E         - STATEMENT_ID
E         - OPEN_COUNTER 1
E         - OPEN_MIN_ELAPSED_TIME
E         - OPEN_MAX_ELAPSED_TIME
E         - OPEN_TOTAL_ELAPSED_TIME
E         - FETCH_COUNTER
E         - FETCH_MIN_ELAPSED_TIME
E         - FETCH_MAX_ELAPSED_TIME
E         - FETCH_TOTAL_ELAPSED_TIME
E         - Records affected: 8

tests/bugs/gh_7086_test.py:1795: AssertionError
Full history of outcomes and elapsed time, ms:
NN SNAP_INFO CS_outcome SS_outcome CS_run_time SS_run_time CS_run_beg CS_run_end SS_run_beg SS_run_end
1 6.0.0.881 2025.06.27 7035d F F 1202 764 2025.06.30 01:57:03.464 2025.06.30 01:57:04.666 2025.06.29 23:12:08.046 2025.06.29 23:12:08.810
2 6.0.0.877 2025.06.26 8e38f F F 1148 1056 2025.06.27 01:36:30.074 2025.06.27 01:36:31.222 2025.06.26 23:03:55.594 2025.06.26 23:03:56.650
3 6.0.0.876 2025.06.25 b1bec F F 1055 1096 2025.06.26 01:40:26.582 2025.06.26 01:40:27.637 2025.06.25 23:05:36.203 2025.06.25 23:05:37.299
4 6.0.0.863 2025.06.24 c3c20 F F 1052 1043 2025.06.25 01:40:40.830 2025.06.25 01:40:41.882 2025.06.24 23:05:21.051 2025.06.24 23:05:22.094
5 6.0.0.858 2025.06.23 8d6f7 F F 1084 1199 2025.06.24 01:41:05.585 2025.06.24 01:41:06.669 2025.06.23 23:05:23.032 2025.06.23 23:05:24.231
6 6.0.0.849 2025.06.20 7b79c F F 1215 1295 2025.06.21 01:52:36.150 2025.06.21 01:52:37.365 2025.06.20 23:14:16.597 2025.06.20 23:14:17.892
7 6.0.0.848 2025.06.19 c483c F F 1071 1378 2025.06.20 01:48:55.668 2025.06.20 01:48:56.739 2025.06.19 23:11:05.794 2025.06.19 23:11:07.172
8 6.0.0.845 2025.06.18 22b12 F F 1115 775 2025.06.19 01:57:27.612 2025.06.19 01:57:28.727 2025.06.18 23:14:06.196 2025.06.18 23:14:06.971
9 6.0.0.843 2025.06.16 995f4 F F 1129 1191 2025.06.18 01:55:45.144 2025.06.18 01:55:46.273 2025.06.17 23:16:56.764 2025.06.17 23:16:57.955
10 6.0.0.840 2025.06.14 29bca F F 1160 1043 2025.06.16 01:47:29.281 2025.06.16 01:47:30.441 2025.06.15 23:08:33.487 2025.06.15 23:08:34.530
11 6.0.0.838 2025.06.13 0e28a F F 1204 1323 2025.06.14 02:00:21.909 2025.06.14 02:00:23.113 2025.06.13 23:16:03.698 2025.06.13 23:16:05.021
12 6.0.0.835 2025.06.12 2cf29 F F 1071 1300 2025.06.13 02:00:38.367 2025.06.13 02:00:39.438 2025.06.12 23:21:47.790 2025.06.12 23:21:49.090
13 6.0.0.834 2025.06.11 e889f F F 1075 1409 2025.06.12 01:55:40.228 2025.06.12 01:55:41.303 2025.06.11 23:16:20.881 2025.06.11 23:16:22.290
14 6.0.0.800 2025.06.10 1f226 P P 763 939 2025.06.11 00:22:39.338 2025.06.11 00:22:40.101 2025.06.10 22:15:49.898 2025.06.10 22:15:50.837
15 6.0.0.799 2025.06.07 be644 P P 1473 644 2025.06.10 00:23:33.078 2025.06.10 00:23:34.551 2025.06.09 22:15:18.938 2025.06.09 22:15:19.582
16 6.0.0.797 2025.06.06 303e8 P P 1591 828 2025.06.07 00:27:13.382 2025.06.07 00:27:14.973 2025.06.06 22:14:43.035 2025.06.06 22:14:43.863
17 6.0.0.795 2025.05.29 7a71a P P 838 759 2025.06.06 00:22:50.021 2025.06.06 00:22:50.859 2025.06.05 22:14:02.900 2025.06.05 22:14:03.659
18 6.0.0.792 2025.05.28 b4327 P P 1026 921 2025.05.29 00:35:02.278 2025.05.29 00:35:03.304 2025.05.28 22:16:16.083 2025.05.28 22:16:17.004
19 6.0.0.791 2025.05.27 02db8 P P 942 1039 2025.05.28 00:32:55.756 2025.05.28 00:32:56.698 2025.05.27 22:15:43.815 2025.05.27 22:15:44.854
20 6.0.0.789 2025.05.21 64051 P P 1520 827 2025.05.25 00:25:32.838 2025.05.25 00:25:34.358 2025.05.24 22:14:42.523 2025.05.24 22:14:43.350
21 6.0.0.787 2025.05.20 230ad P P 939 694 2025.05.21 00:23:11.928 2025.05.21 00:23:12.867 2025.05.20 22:13:24.575 2025.05.20 22:13:25.269
22 6.0.0.783 2025.05.12 37320 P P 1009 715 2025.05.19 11:56:45.025 2025.05.19 11:56:46.034 2025.05.19 10:02:45.552 2025.05.19 10:02:46.267
23 6.0.0.779 2025.05.11 136fa P P 1176 948 2025.05.12 00:18:22.016 2025.05.12 00:18:23.192 2025.05.11 22:13:07.545 2025.05.11 22:13:08.493
24 6.0.0.778 2025.05.07 d735e P P 819 908 2025.05.08 00:20:37.106 2025.05.08 00:20:37.925 2025.05.07 22:11:53.775 2025.05.07 22:11:54.683
25 6.0.0.776 2025.05.06 007cd P P 1660 1069 2025.05.07 00:14:37.750 2025.05.07 00:14:39.410 2025.05.06 22:11:22.836 2025.05.06 22:11:23.905
26 6.0.0.770 2025.05.05 82c4a P P 840 1075 2025.05.06 00:14:34.430 2025.05.06 00:14:35.270 2025.05.05 22:10:48.307 2025.05.05 22:10:49.382
27 6.0.0.767 2025.05.01 cdd29 P P 852 943 2025.05.02 00:12:16.882 2025.05.02 00:12:17.734 2025.05.01 22:10:25.731 2025.05.01 22:10:26.674
28 6.0.0.762 2025.04.30 5cb15 P P 1472 853 2025.05.01 00:08:06.902 2025.05.01 00:08:08.374 2025.04.30 22:09:09.566 2025.04.30 22:09:10.419
29 6.0.0.755 2025.04.29 739c6 P P 1433 958 2025.04.30 00:10:28.345 2025.04.30 00:10:29.778 2025.04.29 22:10:23.519 2025.04.29 22:10:24.477
30 6.0.0.753 2025.04.27 29ab3 P P 1437 953 2025.04.28 00:12:19.490 2025.04.28 00:12:20.927 2025.04.27 22:09:52.666 2025.04.27 22:09:53.619
31 6.0.0.745 2025.04.21 78ad8 P P 1258 1172 2025.04.26 00:08:56.130 2025.04.26 00:08:57.388 2025.04.25 22:11:54.682 2025.04.25 22:11:55.854
32 6.0.0.744 2025.04.19 e883a P P 812 940 2025.04.20 00:10:32.618 2025.04.20 00:10:33.430 2025.04.19 22:10:45.734 2025.04.19 22:10:46.674
33 6.0.0.742 2025.04.17 abc3b P P 1034 870 2025.04.19 00:12:31.825 2025.04.19 00:12:32.859 2025.04.18 22:10:55.641 2025.04.18 22:10:56.511
34 6.0.0.737 2025.04.16 fe52b P P 876 831 2025.04.17 00:09:38.055 2025.04.17 00:09:38.931 2025.04.16 22:10:54.523 2025.04.16 22:10:55.354
35 6.0.0.736 2025.04.14 3e6be P P 1401 619 2025.04.14 23:51:15.118 2025.04.14 23:51:16.519 2025.04.14 22:04:11.206 2025.04.14 22:04:11.825
36 6.0.0.735 2025.04.13 6635c P P 1295 720 2025.04.13 23:54:39.547 2025.04.13 23:54:40.842 2025.04.13 22:04:55.622 2025.04.13 22:04:56.342
37 6.0.0.734 2025.04.12 12f3f P P 1372 674 2025.04.12 23:52:10.628 2025.04.12 23:52:12.000 2025.04.12 22:04:24.812 2025.04.12 22:04:25.486
38 6.0.0.730 2025.04.11 240b8 P P 802 638 2025.04.11 23:54:22.671 2025.04.11 23:54:23.473 2025.04.11 22:03:53.987 2025.04.11 22:03:54.625
39 6.0.0.726 2025.04.10 d79c6 P P 1221 588 2025.04.10 23:53:46.605 2025.04.10 23:53:47.826 2025.04.10 22:04:08.141 2025.04.10 22:04:08.729
40 6.0.0.725 2025.04.09 a2b05 P P 1478 820 2025.04.09 23:54:52.686 2025.04.09 23:54:54.164 2025.04.09 22:05:28.755 2025.04.09 22:05:29.575
41 6.0.0.722 2025.04.08 a8b86 P P 861 1051 2025.04.09 00:10:29.303 2025.04.09 00:10:30.164 2025.04.08 22:10:20.776 2025.04.08 22:10:21.827
42 6.0.0.719 2025.04.06 90fd9 P P 1440 1096 2025.04.07 00:08:04.022 2025.04.07 00:08:05.462 2025.04.06 22:09:12.474 2025.04.06 22:09:13.570
43 6.0.0.717 2025.04.04 53d70 P P 882 803 2025.04.05 00:02:40.753 2025.04.05 00:02:41.635 2025.04.04 22:08:39.335 2025.04.04 22:08:40.138
44 6.0.0.716 2025.04.03 fc636 P P 892 981 2025.04.04 00:07:33.557 2025.04.04 00:07:34.449 2025.04.03 22:09:55.335 2025.04.03 22:09:56.316
45 6.0.0.715 2025.04.02 907ed P P 886 788 2025.04.03 00:07:22.017 2025.04.03 00:07:22.903 2025.04.02 22:10:09.521 2025.04.02 22:10:10.309
46 6.0.0.710 2025.04.01 40651 P P 918 1081 2025.04.02 00:06:00.847 2025.04.02 00:06:01.765 2025.04.01 22:09:13.398 2025.04.01 22:09:14.479
47 6.0.0.708 2025.03.31 cb069 P P 826 668 2025.03.31 23:57:14.427 2025.03.31 23:57:15.253 2025.03.31 22:04:58.738 2025.03.31 22:04:59.406
48 6.0.0.707 2025.03.28 4bd4f P P 773 821 2025.03.30 23:56:38.227 2025.03.30 23:56:39.000 2025.03.30 22:05:20.080 2025.03.30 22:05:20.901
49 6.0.0.698 2025.03.26 d72a7 P P 1582 967 2025.03.28 00:17:55.661 2025.03.28 00:17:57.243 2025.03.27 22:10:13.010 2025.03.27 22:10:13.977
50 6.0.0.693 2025.03.24 0b559 P P 938 958 2025.03.25 00:05:32.551 2025.03.25 00:05:33.489 2025.03.24 22:07:17.235 2025.03.24 22:07:18.193
51 6.0.0.687 2025.03.22 730aa P P 1048 1011 2025.03.24 00:15:37.337 2025.03.24 00:15:38.385 2025.03.23 22:14:15.686 2025.03.23 22:14:16.697
52 6.0.0.686 2025.03.20 71bf6 P P 894 609 2025.03.21 00:21:27.247 2025.03.21 00:21:28.141 2025.03.20 22:15:56.992 2025.03.20 22:15:57.601
53 6.0.0.685 2025.03.19 a8577 P P 1539 1023 2025.03.20 00:23:18.987 2025.03.20 00:23:20.526 2025.03.19 22:14:16.896 2025.03.19 22:14:17.919
54 6.0.0.680 2025.03.18 90d29 P P 20314 20930 2025.03.19 10:44:44.386 2025.03.19 10:45:04.700 2025.03.19 09:00:49.868 2025.03.19 09:01:10.798
55 6.0.0.677 2025.03.16 c0a60 P P 26520 29488 2025.03.17 00:13:59.477 2025.03.17 00:14:25.997 2025.03.16 22:14:08.431 2025.03.16 22:14:37.919
56 6.0.0.676 2025.03.15 3034f P P 18473 15075 2025.03.16 15:46:36.309 2025.03.16 15:46:54.782 2025.03.16 14:05:42.559 2025.03.16 14:05:57.634
57 6.0.0.673 2025.03.13 40f5b P P 28574 27695 2025.03.14 00:12:03.493 2025.03.14 00:12:32.067 2025.03.13 22:12:58.951 2025.03.13 22:13:26.646
58 6.0.0.671 2025.03.12 a4fff P P 23004 30295 2025.03.13 00:16:43.538 2025.03.13 00:17:06.542 2025.03.12 22:15:34.007 2025.03.12 22:16:04.302
59 6.0.0.663 2025.03.11 daad2 P P 27826 30437 2025.03.12 00:14:35.817 2025.03.12 00:15:03.643 2025.03.11 22:15:01.785 2025.03.11 22:15:32.222
60 6.0.0.661 2025.03.07 b9869 P P 13465 23161 2025.03.10 23:54:05.423 2025.03.10 23:54:18.888 2025.03.10 22:06:58.362 2025.03.10 22:07:21.523
61 6.0.0.660 2025.03.04 a6700 P P 27860 28464 2025.03.07 00:02:22.302 2025.03.07 00:02:50.162 2025.03.06 22:10:07.290 2025.03.06 22:10:35.754
62 6.0.0.658 2025.03.03 f15f8 P P 18192 21356 2025.03.03 23:57:30.294 2025.03.03 23:57:48.486 2025.03.03 22:07:02.842 2025.03.03 22:07:24.198
63 6.0.0.656 2025.02.27 25fb4 P P 29871 24294 2025.03.03 00:24:37.620 2025.03.03 00:25:07.491 2025.03.02 22:16:45.253 2025.03.02 22:17:09.547
64 6.0.0.655 2025.02.25 6e3e0 P P 14944 23431 2025.02.27 00:02:10.867 2025.02.27 00:02:25.811 2025.02.26 22:08:43.595 2025.02.26 22:09:07.026
65 6.0.0.654 2025.02.24 b7141 P P 23526 24093 2025.02.25 00:04:16.880 2025.02.25 00:04:40.406 2025.02.24 22:09:54.746 2025.02.24 22:10:18.839
66 6.0.0.652 2025.02.22 22662 P P 20536 17377 2025.02.24 07:21:46.934 2025.02.24 07:22:07.470 2025.02.24 00:24:33.206 2025.02.24 00:24:50.583
67 6.0.0.647 2025.02.21 9fccb P P 13263 16553 2025.02.22 00:05:32.359 2025.02.22 00:05:45.622 2025.02.21 22:14:30.985 2025.02.21 22:14:47.538
68 6.0.0.640 2025.02.19 9b8ac P P 14931 23711 2025.02.20 00:04:15.939 2025.02.20 00:04:30.870 2025.02.19 22:08:14.185 2025.02.19 22:08:37.896
69 6.0.0.639 2025.02.18 201a4 P P 13761 22826 2025.02.18 23:56:59.198 2025.02.18 23:57:12.959 2025.02.18 22:07:44.318 2025.02.18 22:08:07.144
70 6.0.0.637 2025.02.12 6d0f5 P P 16621 28449 2025.02.14 00:13:09.828 2025.02.14 00:13:26.449 2025.02.13 22:13:43.694 2025.02.13 22:14:12.143
71 6.0.0.636 2025.02.11 0424f P P 20201 29097 2025.02.12 00:11:20.310 2025.02.12 00:11:40.511 2025.02.11 22:13:23.674 2025.02.11 22:13:52.771
72 6.0.0.635 2025.02.10 f640f P P 15199 32133 2025.02.11 00:08:47.330 2025.02.11 00:09:02.529 2025.02.10 22:13:57.179 2025.02.10 22:14:29.312
73 6.0.0.629 2025.02.07 194f9 P P 26788 27235 2025.02.08 00:08:54.738 2025.02.08 00:09:21.526 2025.02.07 22:12:39.212 2025.02.07 22:13:06.447
74 6.0.0.628 2025.02.06 859d5 P P 28028 28117 2025.02.07 00:24:25.243 2025.02.07 00:24:53.271 2025.02.06 22:19:15.361 2025.02.06 22:19:43.478
75 6.0.0.621 2025.02.05 34fe7 P P 20895 29871 2025.02.06 00:21:43.573 2025.02.06 00:22:04.468 2025.02.05 22:19:59.607 2025.02.05 22:20:29.478
76 6.0.0.609 2025.02.04 76d57 P P 17412 21951 2025.02.05 00:14:12.931 2025.02.05 00:14:30.343 2025.02.04 22:17:41.947 2025.02.04 22:18:03.898
77 6.0.0.607 2025.02.03 1985b P P 23174 24822 2025.02.04 00:13:26.302 2025.02.04 00:13:49.476 2025.02.03 22:18:00.901 2025.02.03 22:18:25.723
78 6.0.0.601 2025.02.01 6af07 P P 25265 29356 2025.02.02 00:06:07.341 2025.02.02 00:06:32.606 2025.02.01 22:11:34.782 2025.02.01 22:12:04.138
79 6.0.0.600 2025.01.27 188de P P 17100 31855 2025.01.28 00:14:09.395 2025.01.28 00:14:26.495 2025.01.27 22:13:21.978 2025.01.27 22:13:53.833
80 6.0.0.599 2025.01.25 ba588 P P 26477 30562 2025.01.26 00:13:16.710 2025.01.26 00:13:43.187 2025.01.25 22:14:06.381 2025.01.25 22:14:36.943
81 6.0.0.598 2025.01.23 ddbc3 P P 26933 29439 2025.01.25 00:14:10.349 2025.01.25 00:14:37.282 2025.01.24 22:12:35.011 2025.01.24 22:13:04.450
82 6.0.0.595 2025.01.22 e62f3 P P 16012 25897 2025.01.23 00:05:56.737 2025.01.23 00:06:12.749 2025.01.22 22:09:50.033 2025.01.22 22:10:15.930
83 6.0.0.594 2025.01.21 47fb6 P P 15097 27005 2025.01.22 00:01:05.752 2025.01.22 00:01:20.849 2025.01.21 22:09:16.292 2025.01.21 22:09:43.297
84 6.0.0.590 2025.01.20 9dc1e P P 15790 32009 2025.01.21 00:09:11.321 2025.01.21 00:09:27.111 2025.01.20 22:12:43.518 2025.01.20 22:13:15.527
85 6.0.0.588 2025.01.19 b1c4e P P 27488 25841 2025.01.20 00:05:03.046 2025.01.20 00:05:30.534 2025.01.19 22:11:43.283 2025.01.19 22:12:09.124
86 6.0.0.587 2025.01.18 63e6e P P 24702 28538 2025.01.19 00:10:24.325 2025.01.19 00:10:49.027 2025.01.18 22:13:19.746 2025.01.18 22:13:48.284
87 6.0.0.585 2025.01.16 2d6bb P P 25000 26697 2025.01.18 00:02:09.487 2025.01.18 00:02:34.487 2025.01.17 22:10:42.982 2025.01.17 22:11:09.679
88 6.0.0.584 2025.01.15 a0aa2 P P 23416 31432 2025.01.16 00:07:56.435 2025.01.16 00:08:19.851 2025.01.15 22:12:57.658 2025.01.15 22:13:29.090
89 6.0.0.581 2025.01.14 21e9e P P 24567 25503 2025.01.15 00:09:18.374 2025.01.15 00:09:42.941 2025.01.14 22:11:58.783 2025.01.14 22:12:24.286
90 6.0.0.577 2025.01.13 7e293 P P 16994 28080 2025.01.14 00:09:55.404 2025.01.14 00:10:12.398 2025.01.13 22:12:08.307 2025.01.13 22:12:36.387
91 6.0.0.576 2025.01.12 05898 P P 16340 26415 2025.01.13 00:05:18.617 2025.01.13 00:05:34.957 2025.01.12 22:10:34.551 2025.01.12 22:11:00.966
92 6.0.0.573 2025.01.10 c20f3 P P 25522 29848 2025.01.11 00:07:29.687 2025.01.11 00:07:55.209 2025.01.10 22:11:43.650 2025.01.10 22:12:13.498
93 6.0.0.571 2024.12.31 81bba P P 19273 11483 2024.12.31 23:44:16.974 2024.12.31 23:44:36.247 2024.12.31 21:57:21.366 2024.12.31 21:57:32.849
94 6.0.0.570 2024.12.30 c3c8d P P 18541 11327 2024.12.30 23:44:23.205 2024.12.30 23:44:41.746 2024.12.30 21:57:24.646 2024.12.30 21:57:35.973
95 6.0.0.565 2024.12.28 5fc59 P P 11644 11962 2024.12.30 12:20:48.691 2024.12.30 12:21:00.335 2024.12.30 11:06:04.481 2024.12.30 11:06:16.443
96 6.0.0.564 2024.12.26 12514 P P 18244 11544 2024.12.26 23:44:52.910 2024.12.26 23:45:11.154 2024.12.26 21:57:21.626 2024.12.26 21:57:33.170
97 6.0.0.560 2024.12.25 fa83e P P 18163 11328 2024.12.25 23:37:34.652 2024.12.25 23:37:52.815 2024.12.25 21:57:19.775 2024.12.25 21:57:31.103
98 6.0.0.559 2024.12.23 cc800 P P 11224 11544 2024.12.24 23:39:02.403 2024.12.24 23:39:13.627 2024.12.24 21:57:45.093 2024.12.24 21:57:56.637
99 6.0.0.556 2024.12.22 a0404 P P 15408 11490 2024.12.22 23:45:13.711 2024.12.22 23:45:29.119 2024.12.22 21:57:11.300 2024.12.22 21:57:22.790
100 6.0.0.555 2024.12.19 6990a P P 11613 11571 2024.12.21 12:56:17.645 2024.12.21 12:56:29.258 2024.12.21 11:41:56.889 2024.12.21 11:42:08.460
101 6.0.0.553 2024.12.17 d1f8a P P 11344 11731 2024.12.17 23:39:49.795 2024.12.17 23:40:01.139 2024.12.17 21:57:50.238 2024.12.17 21:58:01.969
102 6.0.0.552 2024.12.11 85e25 P P 19797 11485 2024.12.15 23:44:59.110 2024.12.15 23:45:18.907 2024.12.15 21:57:31.797 2024.12.15 21:57:43.282
103 6.0.0.550 2024.12.10 b37ac P P 14238 11695 2024.12.10 23:40:42.761 2024.12.10 23:40:56.999 2024.12.10 21:58:38.318 2024.12.10 21:58:50.013
104 6.0.0.548 2024.12.08 2cc77 P P 18467 11687 2024.12.08 23:35:05.191 2024.12.08 23:35:23.658 2024.12.08 21:56:33.778 2024.12.08 21:56:45.465
105 6.0.0.544 2024.12.05 96943 P P 11688 12289 2024.12.05 23:39:13.552 2024.12.05 23:39:25.240 2024.12.05 21:59:54.907 2024.12.05 22:00:07.196
106 6.0.0.543 2024.12.03 30b77 P P 11680 12649 2024.12.03 23:39:38.326 2024.12.03 23:39:50.006 2024.12.03 21:58:25.388 2024.12.03 21:58:38.037
107 6.0.0.540 2024.12.02 4a1f4 P P 11807 11628 2024.12.02 23:36:21.481 2024.12.02 23:36:33.288 2024.12.02 21:57:46.564 2024.12.02 21:57:58.192
108 6.0.0.539 2024.11.28 1f283 P P 11648 11597 2024.11.29 23:47:57.389 2024.11.29 23:48:09.037 2024.11.29 21:58:11.434 2024.11.29 21:58:23.031
109 6.0.0.535 2024.11.26 77b95 P P 18500 11365 2024.11.26 23:30:12.435 2024.11.26 23:30:30.935 2024.11.26 21:55:53.535 2024.11.26 21:56:04.900
110 6.0.0.534 2024.11.25 e9584 P P 17675 11430 2024.11.25 23:31:28.028 2024.11.25 23:31:45.703 2024.11.25 21:56:38.483 2024.11.25 21:56:49.913
111 6.0.0.533 2024.11.17 933ac P P 11530 11848 2024.11.22 09:38:00.839 2024.11.22 09:38:12.369 2024.11.22 08:26:04.944 2024.11.22 08:26:16.792
112 6.0.0.532 2024.11.16 9e263 P P 12632 12034 2024.11.16 23:20:20.863 2024.11.16 23:20:33.495 2024.11.16 21:56:35.243 2024.11.16 21:56:47.277
113 6.0.0.530 2024.11.15 49804 P P 16375 11217 2024.11.16 01:29:33.688 2024.11.16 01:29:50.063 2024.11.15 23:55:59.069 2024.11.15 23:56:10.286
114 6.0.0.528 2024.11.14 9625b P P 16818 10921 2024.11.15 01:32:40.595 2024.11.15 01:32:57.413 2024.11.14 23:57:15.202 2024.11.14 23:57:26.123
115 6.0.0.526 2024.11.12 65b80 P P 19093 11598 2024.11.14 01:31:43.862 2024.11.14 01:32:02.955 2024.11.13 23:56:46.430 2024.11.13 23:56:58.028
116 6.0.0.523 2024.11.08 8ca23 P P 16468 10904 2024.11.11 01:28:29.178 2024.11.11 01:28:45.646 2024.11.10 23:55:44.921 2024.11.10 23:55:55.825
117 6.0.0.520 2024.11.07 4eefa P P 16574 10895 2024.11.08 01:25:53.160 2024.11.08 01:26:09.734 2024.11.07 23:55:24.803 2024.11.07 23:55:35.698
118 6.0.0.516 2024.11.04 b0c36 P P 16168 10705 2024.11.05 01:25:04.438 2024.11.05 01:25:20.606 2024.11.04 23:55:12.153 2024.11.04 23:55:22.858
119 6.0.0.515 2024.10.30 d53f3 P P 16896 10842 2024.11.04 01:27:31.922 2024.11.04 01:27:48.818 2024.11.03 23:55:40.718 2024.11.03 23:55:51.560
120 6.0.0.512 2024.10.29 833ef P P 17106 11008 2024.10.30 01:29:54.725 2024.10.30 01:30:11.831 2024.10.29 23:56:59.132 2024.10.29 23:57:10.140
121 6.0.0.511 2024.10.26 c4bc9 P P 16886 11105 2024.10.29 01:30:08.573 2024.10.29 01:30:25.459 2024.10.28 23:56:38.403 2024.10.28 23:56:49.508
122 6.0.0.509 2024.10.25 3aedb P P 18649 13069 2024.10.26 01:39:36.829 2024.10.26 01:39:55.478 2024.10.25 23:59:13.696 2024.10.25 23:59:26.765
123 6.0.0.508 2024.10.24 a8f5b P P 16991 11401 2024.10.25 01:34:01.796 2024.10.25 01:34:18.787 2024.10.24 23:57:44.497 2024.10.24 23:57:55.898
124 6.0.0.502 2024.10.22 6bfd7 P P 17013 11766 2024.10.23 01:33:33.130 2024.10.23 01:33:50.143 2024.10.22 23:57:24.357 2024.10.22 23:57:36.123
125 6.0.0.500 2024.10.21 be565 P P 12338 11720 2024.10.22 17:41:00.505 2024.10.22 17:41:12.843 2024.10.22 16:27:01.286 2024.10.22 16:27:13.006
126 6.0.0.499 2024.10.19 6214b P P 17560 11359 2024.10.20 01:34:53.110 2024.10.20 01:35:10.670 2024.10.19 23:58:22.286 2024.10.19 23:58:33.645
127 6.0.0.498 2024.10.18 591a7 P P 16760 10949 2024.10.19 01:32:07.917 2024.10.19 01:32:24.677 2024.10.18 23:56:51.455 2024.10.18 23:57:02.404
128 6.0.0.494 2024.10.17 cf5a4 P P 16916 11104 2024.10.18 01:33:04.037 2024.10.18 01:33:20.953 2024.10.17 23:58:11.352 2024.10.17 23:58:22.456
129 6.0.0.491 2024.10.14 dc5fb P P 16816 10669 2024.10.15 01:29:20.549 2024.10.15 01:29:37.365 2024.10.14 23:56:08.520 2024.10.14 23:56:19.189
130 6.0.0.489 2024.10.11 2ba59 P P 17782 12067 2024.10.12 01:35:43.192 2024.10.12 01:36:00.974 2024.10.11 23:58:00.380 2024.10.11 23:58:12.447
131 6.0.0.488 2024.10.09 1c93e P P 18887 12941 2024.10.10 01:44:00.705 2024.10.10 01:44:19.592 2024.10.10 00:00:30.506 2024.10.10 00:00:43.447
132 6.0.0.487 2024.10.06 065a3 P P 20684 12655 2024.10.07 01:43:06.949 2024.10.07 01:43:27.633 2024.10.07 00:00:24.495 2024.10.07 00:00:37.150
133 6.0.0.485 2024.10.04 e95c1 P P 20103 12944 2024.10.05 01:45:15.250 2024.10.05 01:45:35.353 2024.10.05 00:00:14.077 2024.10.05 00:00:27.021
134 6.0.0.483 2024.10.02 5e5ae P P 17781 11766 2024.10.03 01:40:30.238 2024.10.03 01:40:48.019 2024.10.02 23:59:45.131 2024.10.02 23:59:56.897
135 6.0.0.478 2024.09.30 b5010 P P 17410 11807 2024.10.01 01:35:56.831 2024.10.01 01:36:14.241 2024.09.30 23:59:16.689 2024.09.30 23:59:28.496
136 6.0.0.474 2024.09.26 e4efb P P 16878 10925 2024.09.30 01:35:55.884 2024.09.30 01:36:12.762 2024.09.29 23:58:15.656 2024.09.29 23:58:26.581
137 6.0.0.471 2024.09.24 01b51 P P 18807 12219 2024.09.25 23:39:10.930 2024.09.25 23:39:29.737 2024.09.25 21:58:41.524 2024.09.25 21:58:53.743
138 6.0.0.470 2024.09.23 77cc0 P P 18000 12183 2024.09.23 23:37:57.393 2024.09.23 23:38:15.393 2024.09.23 21:59:00.573 2024.09.23 21:59:12.756
139 6.0.0.467 2024.09.21 ea0b8 P P 17590 11639 2024.09.22 23:36:10.824 2024.09.22 23:36:28.414 2024.09.22 21:58:15.344 2024.09.22 21:58:26.983
140 6.0.0.466 2024.09.20 32dc6 P P 17484 11482 2024.09.20 23:34:50.321 2024.09.20 23:35:07.805 2024.09.20 21:58:00.550 2024.09.20 21:58:12.032
141 6.0.0.461 2024.09.17 2c895 P P 16282 15354 2024.09.18 00:07:52.825 2024.09.18 00:08:09.107 2024.09.17 22:16:56.636 2024.09.17 22:17:11.990
142 6.0.0.460 2024.09.11 3c253 P P 18306 21264 2024.09.17 00:09:14.204 2024.09.17 00:09:32.510 2024.09.16 22:17:57.274 2024.09.16 22:18:18.538
143 6.0.0.457 2024.09.09 fdc6f P P 25033 36632 2024.09.10 00:31:30.185 2024.09.10 00:31:55.218 2024.09.09 22:25:59.093 2024.09.09 22:26:35.725
144 6.0.0.455 2024.09.07 500d8 P P 22381 33377 2024.09.08 00:27:12.253 2024.09.08 00:27:34.634 2024.09.07 22:24:18.202 2024.09.07 22:24:51.579
145 6.0.0.454 2024.09.05 4d70f P P 27467 23755 2024.09.06 00:10:23.208 2024.09.06 00:10:50.675 2024.09.05 22:20:10.340 2024.09.05 22:20:34.095
146 6.0.0.452 2024.09.04 9ff9c P P 18459 23051 2024.09.05 00:08:41.352 2024.09.05 00:08:59.811 2024.09.04 22:18:09.245 2024.09.04 22:18:32.296
147 6.0.0.450 2024.09.02 27124 P P 67912 35523 2024.09.04 01:13:13.419 2024.09.04 01:14:21.331 2024.09.03 22:43:23.953 2024.09.03 22:43:59.476
148 6.0.0.447 2024.09.01 056ec P P 21172 25909 2024.09.02 00:31:51.692 2024.09.02 00:32:12.864 2024.09.01 22:24:07.383 2024.09.01 22:24:33.292
149 6.0.0.446 2024.08.30 fe1b2 P P 19946 22571 2024.09.01 00:37:12.602 2024.09.01 00:37:32.548 2024.08.31 22:35:53.898 2024.08.31 22:36:16.469
150 6.0.0.444 2024.08.28 785d4 P P 24815 31773 2024.08.30 00:49:09.540 2024.08.30 00:49:34.355 2024.08.29 22:44:00.982 2024.08.29 22:44:32.755
151 6.0.0.442 2024.08.21 4a68f P P 30566 55974 2024.08.28 02:29:00.965 2024.08.28 02:29:31.531 2024.08.27 23:34:48.515 2024.08.27 23:35:44.489
152 6.0.0.441 2024.08.20 75042 P P 33090 34067 2024.08.21 00:22:37.411 2024.08.21 00:23:10.501 2024.08.20 22:24:54.338 2024.08.20 22:25:28.405
153 6.0.0.438 2024.08.16 088b5 P P 10942 11183 2024.08.18 23:40:10.985 2024.08.18 23:40:21.927 2024.08.18 22:04:21.728 2024.08.18 22:04:32.911
154 6.0.0.437 2024.08.14 3c88b P P 17172 11005 2024.08.15 23:37:52.781 2024.08.15 23:38:09.953 2024.08.15 22:03:14.878 2024.08.15 22:03:25.883
155 6.0.0.432 2024.08.11 e82ac P P 11668 11055 2024.08.12 23:36:51.469 2024.08.12 23:37:03.137 2024.08.12 22:02:30.385 2024.08.12 22:02:41.440
156 6.0.0.431 2024.08.09 de5a7 P P 16932 11394 2024.08.09 23:38:06.637 2024.08.09 23:38:23.569 2024.08.09 22:03:18.447 2024.08.09 22:03:29.841
157 6.0.0.428 2024.08.08 9191b P P 12485 11286 2024.08.08 23:37:31.269 2024.08.08 23:37:43.754 2024.08.08 22:02:55.054 2024.08.08 22:03:06.340
158 6.0.0.423 2024.08.07 33b41 P P 11764 11499 2024.08.08 09:26:39.652 2024.08.08 09:26:51.416 2024.08.08 08:10:31.707 2024.08.08 08:10:43.206
159 6.0.0.421 2024.08.06 ed60d P P 16226 11307 2024.08.06 23:20:12.417 2024.08.06 23:20:28.643 2024.08.06 21:59:05.143 2024.08.06 21:59:16.450
160 6.0.0.419 2024.08.05 3505a P P 13901 10690 2024.08.05 23:22:25.552 2024.08.05 23:22:39.453 2024.08.05 21:59:10.452 2024.08.05 21:59:21.142
161 6.0.0.409 2024.08.02 ec18f P P 18252 11578 2024.08.04 23:26:29.277 2024.08.04 23:26:47.529 2024.08.04 21:59:55.810 2024.08.04 22:00:07.388
162 6.0.0.406 2024.08.01 b20be P P 17215 11288 2024.08.01 23:25:21.937 2024.08.01 23:25:39.152 2024.08.01 21:59:23.973 2024.08.01 21:59:35.261
163 6.0.0.405 2024.07.31 a62ac P P 16384 11078 2024.07.31 23:23:53.237 2024.07.31 23:24:09.621 2024.07.31 21:59:08.826 2024.07.31 21:59:19.904
164 6.0.0.403 2024.07.29 30f03 P P 16485 11014 2024.07.29 23:23:27.240 2024.07.29 23:23:43.725 2024.07.29 21:58:54.732 2024.07.29 21:59:05.746
165 6.0.0.401 2024.07.26 24e41 P P 13532 10843 2024.07.26 23:20:06.314 2024.07.26 23:20:19.846 2024.07.26 21:58:49.162 2024.07.26 21:59:00.005
166 6.0.0.400 2024.07.24 5bb78 P P 13205 10880 2024.07.24 23:19:44.442 2024.07.24 23:19:57.647 2024.07.24 21:59:05.307 2024.07.24 21:59:16.187
167 6.0.0.398 2024.07.23 85b18 P P 16982 11179 2024.07.23 23:27:43.511 2024.07.23 23:28:00.493 2024.07.23 22:04:10.609 2024.07.23 22:04:21.788
168 6.0.0.397 2024.07.22 c734c P P 12517 10743 2024.07.22 23:19:41.391 2024.07.22 23:19:53.908 2024.07.22 21:59:01.398 2024.07.22 21:59:12.141
169 6.0.0.396 2024.07.13 cf952 P P 16784 11282 2024.07.21 23:20:21.969 2024.07.21 23:20:38.753 2024.07.21 21:58:45.614 2024.07.21 21:58:56.896
170 6.0.0.395 2024.07.10 845f4 P P 18244 11193 2024.07.12 23:21:48.745 2024.07.12 23:22:06.989 2024.07.12 21:58:21.541 2024.07.12 21:58:32.734
171 6.0.0.392 2024.07.09 ea301 P P 10774 11191 2024.07.09 23:17:53.875 2024.07.09 23:18:04.649 2024.07.09 21:57:55.653 2024.07.09 21:58:06.844
172 6.0.0.391 2024.07.08 7d50c P P 15746 11047 2024.07.08 23:18:53.959 2024.07.08 23:19:09.705 2024.07.08 21:58:49.763 2024.07.08 21:59:00.810
173 6.0.0.389 2024.07.05 cc71c P P 14364 11520 2024.07.05 23:22:24.641 2024.07.05 23:22:39.005 2024.07.05 21:58:40.564 2024.07.05 21:58:52.084
174 6.0.0.388 2024.06.30 e5700 P P 13606 11412 2024.06.30 23:19:06.817 2024.06.30 23:19:20.423 2024.06.30 21:59:09.295 2024.06.30 21:59:20.707
175 6.0.0.387 2024.06.27 7c28a P P 14812 10849 2024.06.27 23:18:18.801 2024.06.27 23:18:33.613 2024.06.27 21:58:56.567 2024.06.27 21:59:07.416
176 6.0.0.386 2024.06.23 7c57f P P 12678 10969 2024.06.23 23:15:52.144 2024.06.23 23:16:04.822 2024.06.23 21:57:40.770 2024.06.23 21:57:51.739
177 6.0.0.384 2024.06.21 24d99 P P 16904 11321 2024.06.21 23:19:59.581 2024.06.21 23:20:16.485 2024.06.21 21:58:37.757 2024.06.21 21:58:49.078
178 6.0.0.374 2024.06.13 0097d P P 12780 11260 2024.06.20 23:18:12.206 2024.06.20 23:18:24.986 2024.06.20 21:58:07.371 2024.06.20 21:58:18.631
179 6.0.0.373 2024.06.09 363f0 P P 11525 11121 2024.06.13 13:30:15.044 2024.06.13 13:30:26.569 2024.06.13 12:21:48.297 2024.06.13 12:21:59.418
180 6.0.0.371 2024.06.08 f7130 P P 11378 11199 2024.06.11 22:17:20.449 2024.06.11 22:17:31.827 2024.06.11 21:16:12.498 2024.06.11 21:16:23.697
181 6.0.0.366 2024.05.30 ab2c9 P P 11821 10596 2024.06.12 09:24:27.880 2024.06.12 09:24:39.701 2024.06.12 07:50:50.596 2024.06.12 07:51:01.192
182 6.0.0.363 2024.05.27 06703 P P 11665 11127 2024.06.12 14:23:45.759 2024.06.12 14:23:57.424 2024.06.12 13:19:45.642 2024.06.12 13:19:56.769
183 6.0.0.359 2024.05.23 9cb11 P P 11378 11445 2024.06.12 12:16:00.262 2024.06.12 12:16:11.640 2024.06.12 11:11:58.319 2024.06.12 11:12:09.764
184 6.0.0.358 2024.05.21 995dd P P 11677 11732 2024.06.12 16:59:11.260 2024.06.12 16:59:22.937 2024.06.12 15:56:29.877 2024.06.12 15:56:41.609
185 6.0.0.357 2024.05.18 bf6c4 P P 11779 11275 2024.06.12 21:35:36.303 2024.06.12 21:35:48.082 2024.06.12 20:32:39.802 2024.06.12 20:32:51.077
186 6.0.0.356 2024.05.17 eab06 P P 12026 11152 2024.06.13 05:41:58.050 2024.06.13 05:42:10.076 2024.06.13 04:39:11.997 2024.06.13 04:39:23.149
187 6.0.0.355 2024.05.16 8dd6e P P 11704 12156 2024.06.13 07:49:17.177 2024.06.13 07:49:28.881 2024.06.13 06:47:05.128 2024.06.13 06:47:17.284
188 6.0.0.354 2024.05.15 d3adc P P 12446 11889 2024.06.13 10:55:08.638 2024.06.13 10:55:21.084 2024.06.13 09:47:13.095 2024.06.13 09:47:24.984
189 6.0.0.351 2024.05.14 2e3e0 P P 11667 11950 2024.06.13 16:08:57.014 2024.06.13 16:09:08.681 2024.06.13 15:00:05.339 2024.06.13 15:00:17.289

Elapsed time, ms. Chart for last 150 runs:

Last commits information (all timestamps in UTC):