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-28 05:16:00.790
2025-06-28 05:16:00.795 act = <firebird.qa.plugin.Action object at [hex]>
2025-06-28 05:16:00.799
2025-06-28 05:16:00.803 @pytest.mark.version('>=5.0')
2025-06-28 05:16:00.808 def test_1(act: Action):
2025-06-28 05:16:00.812 act.expected_stdout = fb5x_expected_out if act.is_version('<6') else fb6x_expected_out
2025-06-28 05:16:00.817 act.execute(combine_output = True)
2025-06-28 05:16:00.821 >       assert act.clean_stdout == act.clean_expected_stdout
2025-06-28 05:16:00.825 E       assert
2025-06-28 05:16:00.830 E           START_SESSION 1
2025-06-28 05:16:00.834 E           START_SESSION 2
2025-06-28 05:16:00.838 E         + Statement failed, SQLSTATE = 42S02
2025-06-28 05:16:00.843 E         + Dynamic SQL Error
2025-06-28 05:16:00.847 E         + -SQL error code = -204
2025-06-28 05:16:00.851 E         + -Table unknown
2025-06-28 05:16:00.856 E         + -"PLG$PROF_SESSIONS"
2025-06-28 05:16:00.860 E         + -At line 5, column 10
2025-06-28 05:16:00.864 E         + Statement failed, SQLSTATE = 42S02
2025-06-28 05:16:00.869 E         + Dynamic SQL Error
2025-06-28 05:16:00.873 E         + -SQL error code = -204
2025-06-28 05:16:00.878 E         + -Table unknown
2025-06-28 05:16:00.882 E         + -"PLG$PROF_PSQL_STATS_VIEW"
2025-06-28 05:16:00.886 E         + -At line 14, column 10
2025-06-28 05:16:00.891 E         + Statement failed, SQLSTATE = 42S02
2025-06-28 05:16:00.895 E         + Dynamic SQL Error
2025-06-28 05:16:00.900 E         + -SQL error code = -204
2025-06-28 05:16:00.904 E         + -Table unknown
2025-06-28 05:16:00.908 E         + -"PLG$PROF_RECORD_SOURCE_STATS_VIEW"
2025-06-28 05:16:00.913 E         + -At line 31, column 10
2025-06-28 05:16:00.917 E         + Statement failed, SQLSTATE = 42S02
2025-06-28 05:16:00.921 E         + Dynamic SQL Error
2025-06-28 05:16:00.926 E         + -SQL error code = -204
2025-06-28 05:16:00.930 E         + -Table unknown
2025-06-28 05:16:00.934 E         + -"PLG$PROF_REQUESTS"
2025-06-28 05:16:00.939 E         + -At line 11, column 12
2025-06-28 05:16:00.943 E         + Statement failed, SQLSTATE = 42S02
2025-06-28 05:16:00.948 E         + Dynamic SQL Error
2025-06-28 05:16:00.952 E         + -SQL error code = -204
2025-06-28 05:16:00.956 E         + -Table unknown
2025-06-28 05:16:00.961 E         + -"PLG$PROF_PSQL_STATS"
2025-06-28 05:16:00.965 E         + -At line 13, column 12
2025-06-28 05:16:00.969 E         + Statement failed, SQLSTATE = 42S02
2025-06-28 05:16:00.974 E         + Dynamic SQL Error
2025-06-28 05:16:00.978 E         + -SQL error code = -204
2025-06-28 05:16:00.982 E         + -Table unknown
2025-06-28 05:16:00.987 E         + -"PLG$PROF_RECORD_SOURCE_STATS"
2025-06-28 05:16:00.991 E         + -At line 17, column 12
2025-06-28 05:16:00.995 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-06-28 05:16:01.000 E         - PROFILE_ID 1
2025-06-28 05:16:01.004 E         - ATTACHMENT_ID
2025-06-28 05:16:01.010 E         - USER_NAME SYSDBA
2025-06-28 05:16:01.014 E         - DESCRIPTION profile session 1
2025-06-28 05:16:01.019 E         - START_TIMESTAMP
2025-06-28 05:16:01.023 E         - FINISH_TIMESTAMP
2025-06-28 05:16:01.031 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-06-28 05:16:01.038 E         - PROFILE_ID 2
2025-06-28 05:16:01.050 E         - ATTACHMENT_ID
2025-06-28 05:16:01.058 E         - USER_NAME SYSDBA
2025-06-28 05:16:01.070 E         - DESCRIPTION profile session 2
2025-06-28 05:16:01.079 E         - START_TIMESTAMP
2025-06-28 05:16:01.086 E         - FINISH_TIMESTAMP
2025-06-28 05:16:01.097 E         - Records affected: 2
2025-06-28 05:16:01.108 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.118 E         - PROFILE_ID 1
2025-06-28 05:16:01.127 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:01.141 E         - SQL_TEXT
2025-06-28 05:16:01.149 E         - execute block
2025-06-28 05:16:01.156 E         - as
2025-06-28 05:16:01.163 E         - begin
2025-06-28 05:16:01.171 E         - execute procedure ins;
2025-06-28 05:16:01.183 E         - delete from tab;
2025-06-28 05:16:01.191 E         - end
2025-06-28 05:16:01.198 E         - LINE_NUM
2025-06-28 05:16:01.206 E         - COLUMN_NUM
2025-06-28 05:16:01.213 E         - COUNTER 1
2025-06-28 05:16:01.220 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.226 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.232 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.240 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.246 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.253 E         - PROFILE_ID 1
2025-06-28 05:16:01.259 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:01.266 E         - SQL_TEXT
2025-06-28 05:16:01.272 E         - execute block
2025-06-28 05:16:01.279 E         - as
2025-06-28 05:16:01.286 E         - begin
2025-06-28 05:16:01.292 E         - execute procedure ins;
2025-06-28 05:16:01.299 E         - delete from tab;
2025-06-28 05:16:01.305 E         - end
2025-06-28 05:16:01.312 E         - LINE_NUM
2025-06-28 05:16:01.318 E         - COLUMN_NUM
2025-06-28 05:16:01.324 E         - COUNTER 1
2025-06-28 05:16:01.331 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.337 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.343 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.350 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.356 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.362 E         - PROFILE_ID 1
2025-06-28 05:16:01.369 E         - STATEMENT_TYPE PROCEDURE
2025-06-28 05:16:01.375 E         - SQL_TEXT
2025-06-28 05:16:01.381 E         - LINE_NUM
2025-06-28 05:16:01.387 E         - COLUMN_NUM
2025-06-28 05:16:01.394 E         - COUNTER 1
2025-06-28 05:16:01.407 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.417 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.424 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.430 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.439 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.447 E         - PROFILE_ID 1
2025-06-28 05:16:01.455 E         - STATEMENT_TYPE PROCEDURE
2025-06-28 05:16:01.464 E         - SQL_TEXT
2025-06-28 05:16:01.471 E         - LINE_NUM
2025-06-28 05:16:01.478 E         - COLUMN_NUM
2025-06-28 05:16:01.486 E         - COUNTER 1001
2025-06-28 05:16:01.498 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.507 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.516 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.525 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.538 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.546 E         - PROFILE_ID 1
2025-06-28 05:16:01.554 E         - STATEMENT_TYPE PROCEDURE
2025-06-28 05:16:01.560 E         - SQL_TEXT
2025-06-28 05:16:01.567 E         - LINE_NUM
2025-06-28 05:16:01.573 E         - COLUMN_NUM
2025-06-28 05:16:01.579 E         - COUNTER 1000
2025-06-28 05:16:01.585 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.591 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.597 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.609 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.620 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.628 E         - PROFILE_ID 1
2025-06-28 05:16:01.639 E         - STATEMENT_TYPE PROCEDURE
2025-06-28 05:16:01.649 E         - SQL_TEXT
2025-06-28 05:16:01.657 E         - LINE_NUM
2025-06-28 05:16:01.664 E         - COLUMN_NUM
2025-06-28 05:16:01.671 E         - COUNTER 500
2025-06-28 05:16:01.678 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.684 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.691 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.697 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.704 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.711 E         - PROFILE_ID 1
2025-06-28 05:16:01.719 E         - STATEMENT_TYPE PROCEDURE
2025-06-28 05:16:01.726 E         - SQL_TEXT
2025-06-28 05:16:01.733 E         - LINE_NUM
2025-06-28 05:16:01.740 E         - COLUMN_NUM
2025-06-28 05:16:01.746 E         - COUNTER 1000
2025-06-28 05:16:01.753 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.760 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.767 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.774 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.781 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-28 05:16:01.787 E         - PROFILE_ID 1
2025-06-28 05:16:01.794 E         - STATEMENT_TYPE FUNCTION
2025-06-28 05:16:01.800 E         - SQL_TEXT
2025-06-28 05:16:01.806 E         - LINE_NUM
2025-06-28 05:16:01.812 E         - COLUMN_NUM
2025-06-28 05:16:01.819 E         - COUNTER 500
2025-06-28 05:16:01.825 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:01.830 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:01.835 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:01.840 E         - AVG_ELAPSED_TIME
2025-06-28 05:16:01.845 E         - Records affected: 8
2025-06-28 05:16:01.850 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:01.855 E         - PROFILE_ID 1
2025-06-28 05:16:01.860 E         - STATEMENT_ID
2025-06-28 05:16:01.872 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:01.880 E         - PACKAGE_NAME <null>
2025-06-28 05:16:01.887 E         - ROUTINE_NAME <null>
2025-06-28 05:16:01.894 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:01.900 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:01.908 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:01.914 E         - SQL_TEXT
2025-06-28 05:16:01.923 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-06-28 05:16:01.933 E         - CURSOR_ID 1
2025-06-28 05:16:01.940 E         - CURSOR_NAME <null>
2025-06-28 05:16:01.951 E         - CURSOR_LINE_NUM
2025-06-28 05:16:01.962 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:01.974 E         - RECORD_SOURCE_ID 2
2025-06-28 05:16:01.985 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-28 05:16:01.993 E         - ACCESS_PATH 84:1
2025-06-28 05:16:02.000 E         - -> Table "RDB$DATABASE" Full Scan
2025-06-28 05:16:02.007 E         - OPEN_COUNTER 0
2025-06-28 05:16:02.015 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:02.023 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:02.030 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.037 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:02.043 E         - FETCH_COUNTER
2025-06-28 05:16:02.049 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:02.056 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:02.063 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.069 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:02.075 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.081 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:02.088 E         - PROFILE_ID 1
2025-06-28 05:16:02.095 E         - STATEMENT_ID
2025-06-28 05:16:02.103 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:02.110 E         - PACKAGE_NAME <null>
2025-06-28 05:16:02.116 E         - ROUTINE_NAME <null>
2025-06-28 05:16:02.122 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:02.129 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:02.135 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:02.141 E         - SQL_TEXT
2025-06-28 05:16:02.147 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-06-28 05:16:02.153 E         - CURSOR_ID 1
2025-06-28 05:16:02.159 E         - CURSOR_NAME <null>
2025-06-28 05:16:02.165 E         - CURSOR_LINE_NUM
2025-06-28 05:16:02.170 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:02.176 E         - RECORD_SOURCE_ID 1
2025-06-28 05:16:02.181 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-28 05:16:02.186 E         - ACCESS_PATH 84:0
2025-06-28 05:16:02.192 E         - Select Expression
2025-06-28 05:16:02.198 E         - OPEN_COUNTER 0
2025-06-28 05:16:02.204 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:02.211 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:02.218 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.226 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:02.237 E         - FETCH_COUNTER
2025-06-28 05:16:02.247 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:02.255 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:02.263 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.269 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:02.275 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.280 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:02.286 E         - PROFILE_ID 1
2025-06-28 05:16:02.292 E         - STATEMENT_ID
2025-06-28 05:16:02.298 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:02.308 E         - PACKAGE_NAME <null>
2025-06-28 05:16:02.318 E         - ROUTINE_NAME <null>
2025-06-28 05:16:02.326 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:02.338 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:02.350 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:02.358 E         - SQL_TEXT
2025-06-28 05:16:02.365 E         - execute block
2025-06-28 05:16:02.371 E         - as
2025-06-28 05:16:02.377 E         - begin
2025-06-28 05:16:02.382 E         - execute procedure ins;
2025-06-28 05:16:02.390 E         - delete from tab;
2025-06-28 05:16:02.398 E         - end
2025-06-28 05:16:02.411 E         - CURSOR_ID 1
2025-06-28 05:16:02.418 E         - CURSOR_NAME <null>
2025-06-28 05:16:02.424 E         - CURSOR_LINE_NUM
2025-06-28 05:16:02.430 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:02.435 E         - RECORD_SOURCE_ID 2
2025-06-28 05:16:02.440 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-28 05:16:02.446 E         - ACCESS_PATH 84:3
2025-06-28 05:16:02.456 E         - -> Table "TAB" Full Scan
2025-06-28 05:16:02.465 E         - OPEN_COUNTER 1
2025-06-28 05:16:02.471 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:02.478 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:02.484 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.490 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:02.495 E         - FETCH_COUNTER
2025-06-28 05:16:02.507 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:02.517 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:02.528 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.539 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:02.548 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.559 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:02.570 E         - PROFILE_ID 1
2025-06-28 05:16:02.577 E         - STATEMENT_ID
2025-06-28 05:16:02.585 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:02.592 E         - PACKAGE_NAME <null>
2025-06-28 05:16:02.598 E         - ROUTINE_NAME <null>
2025-06-28 05:16:02.603 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:02.607 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:02.613 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:02.619 E         - SQL_TEXT
2025-06-28 05:16:02.624 E         - execute block
2025-06-28 05:16:02.630 E         - as
2025-06-28 05:16:02.635 E         - begin
2025-06-28 05:16:02.641 E         - execute procedure ins;
2025-06-28 05:16:02.647 E         - delete from tab;
2025-06-28 05:16:02.655 E         - end
2025-06-28 05:16:02.661 E         - CURSOR_ID 1
2025-06-28 05:16:02.667 E         - CURSOR_NAME <null>
2025-06-28 05:16:02.672 E         - CURSOR_LINE_NUM
2025-06-28 05:16:02.677 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:02.682 E         - RECORD_SOURCE_ID 1
2025-06-28 05:16:02.689 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-28 05:16:02.698 E         - ACCESS_PATH 84:2
2025-06-28 05:16:02.708 E         - Select Expression (line 5, column 9)
2025-06-28 05:16:02.715 E         - OPEN_COUNTER 1
2025-06-28 05:16:02.721 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:02.727 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:02.736 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.745 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:02.752 E         - FETCH_COUNTER
2025-06-28 05:16:02.760 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:02.770 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:02.779 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.786 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:02.792 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.797 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:02.809 E         - PROFILE_ID 2
2025-06-28 05:16:02.818 E         - STATEMENT_ID
2025-06-28 05:16:02.825 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:02.832 E         - PACKAGE_NAME <null>
2025-06-28 05:16:02.838 E         - ROUTINE_NAME <null>
2025-06-28 05:16:02.844 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:02.849 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:02.855 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:02.863 E         - SQL_TEXT
2025-06-28 05:16:02.873 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-06-28 05:16:02.881 E         - CURSOR_ID 1
2025-06-28 05:16:02.887 E         - CURSOR_NAME <null>
2025-06-28 05:16:02.897 E         - CURSOR_LINE_NUM
2025-06-28 05:16:02.905 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:02.912 E         - RECORD_SOURCE_ID 2
2025-06-28 05:16:02.919 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-28 05:16:02.925 E         - ACCESS_PATH 84:5
2025-06-28 05:16:02.935 E         - -> Table "RDB$DATABASE" Full Scan
2025-06-28 05:16:02.945 E         - OPEN_COUNTER 0
2025-06-28 05:16:02.952 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:02.959 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:02.965 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:02.972 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:02.979 E         - FETCH_COUNTER
2025-06-28 05:16:02.987 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:02.999 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:03.008 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.014 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:03.020 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.026 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:03.032 E         - PROFILE_ID 2
2025-06-28 05:16:03.038 E         - STATEMENT_ID
2025-06-28 05:16:03.046 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:03.053 E         - PACKAGE_NAME <null>
2025-06-28 05:16:03.060 E         - ROUTINE_NAME <null>
2025-06-28 05:16:03.066 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:03.071 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:03.077 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:03.083 E         - SQL_TEXT
2025-06-28 05:16:03.088 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-06-28 05:16:03.094 E         - CURSOR_ID 1
2025-06-28 05:16:03.099 E         - CURSOR_NAME <null>
2025-06-28 05:16:03.106 E         - CURSOR_LINE_NUM
2025-06-28 05:16:03.114 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:03.121 E         - RECORD_SOURCE_ID 1
2025-06-28 05:16:03.127 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-28 05:16:03.133 E         - ACCESS_PATH 84:4
2025-06-28 05:16:03.137 E         - Select Expression
2025-06-28 05:16:03.143 E         - OPEN_COUNTER 0
2025-06-28 05:16:03.148 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:03.154 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:03.163 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.173 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:03.180 E         - FETCH_COUNTER
2025-06-28 05:16:03.186 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:03.192 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:03.198 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.204 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:03.210 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.216 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:03.222 E         - PROFILE_ID 2
2025-06-28 05:16:03.229 E         - STATEMENT_ID
2025-06-28 05:16:03.235 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:03.242 E         - PACKAGE_NAME <null>
2025-06-28 05:16:03.248 E         - ROUTINE_NAME <null>
2025-06-28 05:16:03.255 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:03.261 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:03.273 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:03.283 E         - SQL_TEXT
2025-06-28 05:16:03.291 E         - select mod(id, 5),
2025-06-28 05:16:03.298 E         - sum(val)
2025-06-28 05:16:03.310 E         - from tab
2025-06-28 05:16:03.323 E         - where id <= 50
2025-06-28 05:16:03.336 E         - group by mod(id, 5)
2025-06-28 05:16:03.344 E         - order by sum(val)
2025-06-28 05:16:03.352 E         - CURSOR_ID 1
2025-06-28 05:16:03.358 E         - CURSOR_NAME <null>
2025-06-28 05:16:03.368 E         - CURSOR_LINE_NUM
2025-06-28 05:16:03.379 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:03.389 E         - RECORD_SOURCE_ID 2
2025-06-28 05:16:03.400 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-28 05:16:03.410 E         - ACCESS_PATH 84:7
2025-06-28 05:16:03.421 E         - -> Sort (record length: 44, key length: 12)
2025-06-28 05:16:03.434 E         - OPEN_COUNTER 1
2025-06-28 05:16:03.446 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:03.454 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:03.461 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.467 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:03.474 E         - FETCH_COUNTER
2025-06-28 05:16:03.485 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:03.493 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:03.500 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.506 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:03.517 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.526 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:03.533 E         - PROFILE_ID 2
2025-06-28 05:16:03.542 E         - STATEMENT_ID
2025-06-28 05:16:03.553 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:03.563 E         - PACKAGE_NAME <null>
2025-06-28 05:16:03.571 E         - ROUTINE_NAME <null>
2025-06-28 05:16:03.578 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:03.590 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:03.599 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:03.606 E         - SQL_TEXT
2025-06-28 05:16:03.617 E         - select mod(id, 5),
2025-06-28 05:16:03.631 E         - sum(val)
2025-06-28 05:16:03.641 E         - from tab
2025-06-28 05:16:03.653 E         - where id <= 50
2025-06-28 05:16:03.664 E         - group by mod(id, 5)
2025-06-28 05:16:03.674 E         - order by sum(val)
2025-06-28 05:16:03.686 E         - CURSOR_ID 1
2025-06-28 05:16:03.698 E         - CURSOR_NAME <null>
2025-06-28 05:16:03.711 E         - CURSOR_LINE_NUM
2025-06-28 05:16:03.723 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:03.732 E         - RECORD_SOURCE_ID 3
2025-06-28 05:16:03.740 E         - PARENT_RECORD_SOURCE_ID 2
2025-06-28 05:16:03.747 E         - ACCESS_PATH 84:8
2025-06-28 05:16:03.753 E         - -> Aggregate
2025-06-28 05:16:03.760 E         - OPEN_COUNTER 1
2025-06-28 05:16:03.766 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:03.771 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:03.779 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.790 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:03.802 E         - FETCH_COUNTER
2025-06-28 05:16:03.812 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:03.820 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:03.825 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.830 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:03.834 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:03.839 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:03.843 E         - PROFILE_ID 2
2025-06-28 05:16:03.848 E         - STATEMENT_ID
2025-06-28 05:16:03.858 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:03.868 E         - PACKAGE_NAME <null>
2025-06-28 05:16:03.875 E         - ROUTINE_NAME <null>
2025-06-28 05:16:03.884 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:03.896 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:03.908 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:03.918 E         - SQL_TEXT
2025-06-28 05:16:03.929 E         - select mod(id, 5),
2025-06-28 05:16:03.939 E         - sum(val)
2025-06-28 05:16:03.947 E         - from tab
2025-06-28 05:16:03.954 E         - where id <= 50
2025-06-28 05:16:03.964 E         - group by mod(id, 5)
2025-06-28 05:16:03.973 E         - order by sum(val)
2025-06-28 05:16:03.984 E         - CURSOR_ID 1
2025-06-28 05:16:03.994 E         - CURSOR_NAME <null>
2025-06-28 05:16:04.005 E         - CURSOR_LINE_NUM
2025-06-28 05:16:04.015 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:04.023 E         - RECORD_SOURCE_ID 4
2025-06-28 05:16:04.031 E         - PARENT_RECORD_SOURCE_ID 3
2025-06-28 05:16:04.038 E         - ACCESS_PATH 84:9
2025-06-28 05:16:04.048 E         - -> Sort (record length: 44, key length: 8)
2025-06-28 05:16:04.058 E         - OPEN_COUNTER 1
2025-06-28 05:16:04.068 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:04.078 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:04.089 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.098 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:04.108 E         - FETCH_COUNTER
2025-06-28 05:16:04.120 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:04.131 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:04.143 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.154 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:04.166 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.177 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:04.187 E         - PROFILE_ID 2
2025-06-28 05:16:04.198 E         - STATEMENT_ID
2025-06-28 05:16:04.206 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:04.212 E         - PACKAGE_NAME <null>
2025-06-28 05:16:04.218 E         - ROUTINE_NAME <null>
2025-06-28 05:16:04.223 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:04.228 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:04.234 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:04.239 E         - SQL_TEXT
2025-06-28 05:16:04.244 E         - select mod(id, 5),
2025-06-28 05:16:04.250 E         - sum(val)
2025-06-28 05:16:04.260 E         - from tab
2025-06-28 05:16:04.269 E         - where id <= 50
2025-06-28 05:16:04.279 E         - group by mod(id, 5)
2025-06-28 05:16:04.290 E         - order by sum(val)
2025-06-28 05:16:04.299 E         - CURSOR_ID 1
2025-06-28 05:16:04.307 E         - CURSOR_NAME <null>
2025-06-28 05:16:04.314 E         - CURSOR_LINE_NUM
2025-06-28 05:16:04.320 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:04.326 E         - RECORD_SOURCE_ID 5
2025-06-28 05:16:04.334 E         - PARENT_RECORD_SOURCE_ID 4
2025-06-28 05:16:04.346 E         - ACCESS_PATH 84:a
2025-06-28 05:16:04.355 E         - -> Filter
2025-06-28 05:16:04.363 E         - OPEN_COUNTER 1
2025-06-28 05:16:04.370 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:04.376 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:04.382 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.389 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:04.395 E         - FETCH_COUNTER
2025-06-28 05:16:04.400 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:04.406 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:04.416 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.428 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:04.437 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.445 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:04.456 E         - PROFILE_ID 2
2025-06-28 05:16:04.469 E         - STATEMENT_ID
2025-06-28 05:16:04.479 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:04.490 E         - PACKAGE_NAME <null>
2025-06-28 05:16:04.499 E         - ROUTINE_NAME <null>
2025-06-28 05:16:04.507 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:04.518 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:04.528 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:04.536 E         - SQL_TEXT
2025-06-28 05:16:04.542 E         - select mod(id, 5),
2025-06-28 05:16:04.548 E         - sum(val)
2025-06-28 05:16:04.554 E         - from tab
2025-06-28 05:16:04.559 E         - where id <= 50
2025-06-28 05:16:04.566 E         - group by mod(id, 5)
2025-06-28 05:16:04.576 E         - order by sum(val)
2025-06-28 05:16:04.584 E         - CURSOR_ID 1
2025-06-28 05:16:04.591 E         - CURSOR_NAME <null>
2025-06-28 05:16:04.598 E         - CURSOR_LINE_NUM
2025-06-28 05:16:04.608 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:04.617 E         - RECORD_SOURCE_ID 6
2025-06-28 05:16:04.629 E         - PARENT_RECORD_SOURCE_ID 5
2025-06-28 05:16:04.640 E         - ACCESS_PATH 84:b
2025-06-28 05:16:04.648 E         - -> Table "TAB" Full Scan
2025-06-28 05:16:04.654 E         - OPEN_COUNTER 1
2025-06-28 05:16:04.664 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:04.674 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:04.682 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.689 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:04.697 E         - FETCH_COUNTER
2025-06-28 05:16:04.703 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:04.711 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:04.721 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.730 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:04.741 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:04.751 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-28 05:16:04.758 E         - PROFILE_ID 2
2025-06-28 05:16:04.769 E         - STATEMENT_ID
2025-06-28 05:16:04.781 E         - STATEMENT_TYPE BLOCK
2025-06-28 05:16:04.790 E         - PACKAGE_NAME <null>
2025-06-28 05:16:04.801 E         - ROUTINE_NAME <null>
2025-06-28 05:16:04.812 E         - PARENT_STATEMENT_ID
2025-06-28 05:16:04.821 E         - PARENT_STATEMENT_TYPE <null>
2025-06-28 05:16:04.831 E         - PARENT_ROUTINE_NAME <null>
2025-06-28 05:16:04.843 E         - SQL_TEXT
2025-06-28 05:16:04.853 E         - select mod(id, 5),
2025-06-28 05:16:04.865 E         - sum(val)
2025-06-28 05:16:04.877 E         - from tab
2025-06-28 05:16:04.886 E         - where id <= 50
2025-06-28 05:16:04.895 E         - group by mod(id, 5)
2025-06-28 05:16:04.908 E         - order by sum(val)
2025-06-28 05:16:04.917 E         - CURSOR_ID 1
2025-06-28 05:16:04.927 E         - CURSOR_NAME <null>
2025-06-28 05:16:04.935 E         - CURSOR_LINE_NUM
2025-06-28 05:16:04.942 E         - CURSOR_COLUMN_NUM
2025-06-28 05:16:04.948 E         - RECORD_SOURCE_ID 1
2025-06-28 05:16:04.955 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-28 05:16:04.961 E         - ACCESS_PATH 84:6
2025-06-28 05:16:04.971 E         - Select Expression
2025-06-28 05:16:04.982 E         - OPEN_COUNTER 1
2025-06-28 05:16:04.990 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:05.001 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:05.012 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.021 E         - OPEN_AVG_ELAPSED_TIME
2025-06-28 05:16:05.027 E         - FETCH_COUNTER
2025-06-28 05:16:05.035 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:05.040 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:05.046 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.052 E         - FETCH_AVG_ELAPSED_TIME
2025-06-28 05:16:05.058 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.064 E         - Records affected: 12
2025-06-28 05:16:05.070 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-28 05:16:05.080 E         - PROFILE_ID 1
2025-06-28 05:16:05.089 E         - REQUEST_ID
2025-06-28 05:16:05.098 E         - STATEMENT_ID
2025-06-28 05:16:05.111 E         - CALLER_REQUEST_ID
2025-06-28 05:16:05.126 E         - START_TIMESTAMP
2025-06-28 05:16:05.136 E         - FINISH_TIMESTAMP
2025-06-28 05:16:05.143 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.151 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-28 05:16:05.157 E         - PROFILE_ID 1
2025-06-28 05:16:05.162 E         - REQUEST_ID
2025-06-28 05:16:05.169 E         - STATEMENT_ID
2025-06-28 05:16:05.174 E         - CALLER_REQUEST_ID
2025-06-28 05:16:05.179 E         - START_TIMESTAMP
2025-06-28 05:16:05.183 E         - FINISH_TIMESTAMP
2025-06-28 05:16:05.189 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.195 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-28 05:16:05.202 E         - PROFILE_ID 1
2025-06-28 05:16:05.213 E         - REQUEST_ID
2025-06-28 05:16:05.223 E         - STATEMENT_ID
2025-06-28 05:16:05.231 E         - CALLER_REQUEST_ID
2025-06-28 05:16:05.237 E         - START_TIMESTAMP
2025-06-28 05:16:05.244 E         - FINISH_TIMESTAMP
2025-06-28 05:16:05.250 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.260 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-28 05:16:05.268 E         - PROFILE_ID 1
2025-06-28 05:16:05.276 E         - REQUEST_ID
2025-06-28 05:16:05.282 E         - STATEMENT_ID
2025-06-28 05:16:05.292 E         - CALLER_REQUEST_ID
2025-06-28 05:16:05.300 E         - START_TIMESTAMP
2025-06-28 05:16:05.307 E         - FINISH_TIMESTAMP
2025-06-28 05:16:05.313 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.319 E         - Records affected: 4
2025-06-28 05:16:05.324 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:05.335 E         - PROFILE_ID 1
2025-06-28 05:16:05.346 E         - REQUEST_ID
2025-06-28 05:16:05.359 E         - LINE_NUM
2025-06-28 05:16:05.369 E         - COLUMN_NUM
2025-06-28 05:16:05.383 E         - STATEMENT_ID
2025-06-28 05:16:05.394 E         - COUNTER 1
2025-06-28 05:16:05.401 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:05.407 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:05.414 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.420 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:05.425 E         - PROFILE_ID 1
2025-06-28 05:16:05.430 E         - REQUEST_ID
2025-06-28 05:16:05.435 E         - LINE_NUM
2025-06-28 05:16:05.442 E         - COLUMN_NUM
2025-06-28 05:16:05.452 E         - STATEMENT_ID
2025-06-28 05:16:05.464 E         - COUNTER 1
2025-06-28 05:16:05.475 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:05.485 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:05.493 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.507 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:05.518 E         - PROFILE_ID 1
2025-06-28 05:16:05.530 E         - REQUEST_ID
2025-06-28 05:16:05.541 E         - LINE_NUM
2025-06-28 05:16:05.549 E         - COLUMN_NUM
2025-06-28 05:16:05.561 E         - STATEMENT_ID
2025-06-28 05:16:05.575 E         - COUNTER 1
2025-06-28 05:16:05.588 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:05.598 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:05.610 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.621 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:05.630 E         - PROFILE_ID 1
2025-06-28 05:16:05.638 E         - REQUEST_ID
2025-06-28 05:16:05.647 E         - LINE_NUM
2025-06-28 05:16:05.659 E         - COLUMN_NUM
2025-06-28 05:16:05.670 E         - STATEMENT_ID
2025-06-28 05:16:05.678 E         - COUNTER 1001
2025-06-28 05:16:05.688 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:05.701 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:05.712 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.721 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:05.728 E         - PROFILE_ID 1
2025-06-28 05:16:05.736 E         - REQUEST_ID
2025-06-28 05:16:05.747 E         - LINE_NUM
2025-06-28 05:16:05.755 E         - COLUMN_NUM
2025-06-28 05:16:05.763 E         - STATEMENT_ID
2025-06-28 05:16:05.773 E         - COUNTER 1000
2025-06-28 05:16:05.786 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:05.795 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:05.801 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.812 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:05.825 E         - PROFILE_ID 1
2025-06-28 05:16:05.834 E         - REQUEST_ID
2025-06-28 05:16:05.843 E         - LINE_NUM
2025-06-28 05:16:05.852 E         - COLUMN_NUM
2025-06-28 05:16:05.860 E         - STATEMENT_ID
2025-06-28 05:16:05.867 E         - COUNTER 500
2025-06-28 05:16:05.873 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:05.879 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:05.884 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.890 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:05.900 E         - PROFILE_ID 1
2025-06-28 05:16:05.910 E         - REQUEST_ID
2025-06-28 05:16:05.917 E         - LINE_NUM
2025-06-28 05:16:05.925 E         - COLUMN_NUM
2025-06-28 05:16:05.937 E         - STATEMENT_ID
2025-06-28 05:16:05.950 E         - COUNTER 1000
2025-06-28 05:16:05.961 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:05.970 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:05.982 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:05.995 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-28 05:16:06.006 E         - PROFILE_ID 1
2025-06-28 05:16:06.013 E         - REQUEST_ID
2025-06-28 05:16:06.020 E         - LINE_NUM
2025-06-28 05:16:06.026 E         - COLUMN_NUM
2025-06-28 05:16:06.033 E         - STATEMENT_ID
2025-06-28 05:16:06.039 E         - COUNTER 500
2025-06-28 05:16:06.046 E         - MIN_ELAPSED_TIME
2025-06-28 05:16:06.053 E         - MAX_ELAPSED_TIME
2025-06-28 05:16:06.059 E         - TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.065 E         - Records affected: 8
2025-06-28 05:16:06.072 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.079 E         - PROFILE_ID 2
2025-06-28 05:16:06.087 E         - REQUEST_ID
2025-06-28 05:16:06.095 E         - CURSOR_ID 1
2025-06-28 05:16:06.104 E         - RECORD_SOURCE_ID 1
2025-06-28 05:16:06.115 E         - STATEMENT_ID
2025-06-28 05:16:06.122 E         - OPEN_COUNTER 0
2025-06-28 05:16:06.128 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.139 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.151 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.158 E         - FETCH_COUNTER
2025-06-28 05:16:06.165 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.176 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.186 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.194 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.203 E         - PROFILE_ID 2
2025-06-28 05:16:06.214 E         - REQUEST_ID
2025-06-28 05:16:06.222 E         - CURSOR_ID 1
2025-06-28 05:16:06.230 E         - RECORD_SOURCE_ID 2
2025-06-28 05:16:06.237 E         - STATEMENT_ID
2025-06-28 05:16:06.246 E         - OPEN_COUNTER 0
2025-06-28 05:16:06.255 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.266 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.276 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.285 E         - FETCH_COUNTER
2025-06-28 05:16:06.296 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.308 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.317 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.325 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.332 E         - PROFILE_ID 2
2025-06-28 05:16:06.338 E         - REQUEST_ID
2025-06-28 05:16:06.351 E         - CURSOR_ID 1
2025-06-28 05:16:06.361 E         - RECORD_SOURCE_ID 1
2025-06-28 05:16:06.368 E         - STATEMENT_ID
2025-06-28 05:16:06.375 E         - OPEN_COUNTER 1
2025-06-28 05:16:06.382 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.389 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.396 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.404 E         - FETCH_COUNTER
2025-06-28 05:16:06.410 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.415 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.421 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.426 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.432 E         - PROFILE_ID 2
2025-06-28 05:16:06.439 E         - REQUEST_ID
2025-06-28 05:16:06.450 E         - CURSOR_ID 1
2025-06-28 05:16:06.458 E         - RECORD_SOURCE_ID 2
2025-06-28 05:16:06.464 E         - STATEMENT_ID
2025-06-28 05:16:06.470 E         - OPEN_COUNTER 1
2025-06-28 05:16:06.480 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.490 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.498 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.505 E         - FETCH_COUNTER
2025-06-28 05:16:06.511 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.523 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.533 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.541 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.548 E         - PROFILE_ID 2
2025-06-28 05:16:06.557 E         - REQUEST_ID
2025-06-28 05:16:06.571 E         - CURSOR_ID 1
2025-06-28 05:16:06.580 E         - RECORD_SOURCE_ID 3
2025-06-28 05:16:06.589 E         - STATEMENT_ID
2025-06-28 05:16:06.596 E         - OPEN_COUNTER 1
2025-06-28 05:16:06.602 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.607 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.612 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.616 E         - FETCH_COUNTER
2025-06-28 05:16:06.622 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.635 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.646 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.653 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.660 E         - PROFILE_ID 2
2025-06-28 05:16:06.666 E         - REQUEST_ID
2025-06-28 05:16:06.672 E         - CURSOR_ID 1
2025-06-28 05:16:06.679 E         - RECORD_SOURCE_ID 4
2025-06-28 05:16:06.685 E         - STATEMENT_ID
2025-06-28 05:16:06.690 E         - OPEN_COUNTER 1
2025-06-28 05:16:06.700 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.710 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.718 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.725 E         - FETCH_COUNTER
2025-06-28 05:16:06.734 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.743 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.752 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.760 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.766 E         - PROFILE_ID 2
2025-06-28 05:16:06.774 E         - REQUEST_ID
2025-06-28 05:16:06.779 E         - CURSOR_ID 1
2025-06-28 05:16:06.786 E         - RECORD_SOURCE_ID 5
2025-06-28 05:16:06.796 E         - STATEMENT_ID
2025-06-28 05:16:06.805 E         - OPEN_COUNTER 1
2025-06-28 05:16:06.813 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.820 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.825 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.831 E         - FETCH_COUNTER
2025-06-28 05:16:06.838 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.849 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.857 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.864 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-28 05:16:06.870 E         - PROFILE_ID 2
2025-06-28 05:16:06.881 E         - REQUEST_ID
2025-06-28 05:16:06.888 E         - CURSOR_ID 1
2025-06-28 05:16:06.895 E         - RECORD_SOURCE_ID 6
2025-06-28 05:16:06.901 E         - STATEMENT_ID
2025-06-28 05:16:06.906 E         - OPEN_COUNTER 1
2025-06-28 05:16:06.918 E         - OPEN_MIN_ELAPSED_TIME
2025-06-28 05:16:06.929 E         - OPEN_MAX_ELAPSED_TIME
2025-06-28 05:16:06.937 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.944 E         - FETCH_COUNTER
2025-06-28 05:16:06.951 E         - FETCH_MIN_ELAPSED_TIME
2025-06-28 05:16:06.958 E         - FETCH_MAX_ELAPSED_TIME
2025-06-28 05:16:06.972 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-28 05:16:06.981 E         - Records affected: 8
2025-06-28 05:16:06.990
2025-06-28 05:16:07.003 tests/bugs/gh_7086_test.py:1795: AssertionError
2025-06-28 05:16:07.013 ---------------------------- Captured stdout setup -----------------------------
2025-06-28 05:16:07.021 Creating db: localhost:/var/tmp/qa_2024/test_11493/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 1083 856 2025.06.28 01:35:36.687 2025.06.28 01:35:37.770 2025.06.27 23:02:45.616 2025.06.27 23:02:46.472
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):