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-07-01 05:53:42.523
2025-07-01 05:53:42.530 act = <firebird.qa.plugin.Action object at [hex]>
2025-07-01 05:53:42.536
2025-07-01 05:53:42.542 @pytest.mark.version('>=5.0')
2025-07-01 05:53:42.548 def test_1(act: Action):
2025-07-01 05:53:42.555 act.expected_stdout = fb5x_expected_out if act.is_version('<6') else fb6x_expected_out
2025-07-01 05:53:42.562 act.execute(combine_output = True)
2025-07-01 05:53:42.568 >       assert act.clean_stdout == act.clean_expected_stdout
2025-07-01 05:53:42.573 E       assert
2025-07-01 05:53:42.578 E           START_SESSION 1
2025-07-01 05:53:42.584 E           START_SESSION 2
2025-07-01 05:53:42.591 E         + Statement failed, SQLSTATE = 42S02
2025-07-01 05:53:42.598 E         + Dynamic SQL Error
2025-07-01 05:53:42.604 E         + -SQL error code = -204
2025-07-01 05:53:42.611 E         + -Table unknown
2025-07-01 05:53:42.618 E         + -"PLG$PROF_SESSIONS"
2025-07-01 05:53:42.626 E         + -At line 5, column 10
2025-07-01 05:53:42.637 E         + Statement failed, SQLSTATE = 42S02
2025-07-01 05:53:42.644 E         + Dynamic SQL Error
2025-07-01 05:53:42.654 E         + -SQL error code = -204
2025-07-01 05:53:42.665 E         + -Table unknown
2025-07-01 05:53:42.674 E         + -"PLG$PROF_PSQL_STATS_VIEW"
2025-07-01 05:53:42.681 E         + -At line 14, column 10
2025-07-01 05:53:42.688 E         + Statement failed, SQLSTATE = 42S02
2025-07-01 05:53:42.694 E         + Dynamic SQL Error
2025-07-01 05:53:42.700 E         + -SQL error code = -204
2025-07-01 05:53:42.706 E         + -Table unknown
2025-07-01 05:53:42.710 E         + -"PLG$PROF_RECORD_SOURCE_STATS_VIEW"
2025-07-01 05:53:42.717 E         + -At line 31, column 10
2025-07-01 05:53:42.723 E         + Statement failed, SQLSTATE = 42S02
2025-07-01 05:53:42.729 E         + Dynamic SQL Error
2025-07-01 05:53:42.736 E         + -SQL error code = -204
2025-07-01 05:53:42.742 E         + -Table unknown
2025-07-01 05:53:42.749 E         + -"PLG$PROF_REQUESTS"
2025-07-01 05:53:42.760 E         + -At line 11, column 12
2025-07-01 05:53:42.768 E         + Statement failed, SQLSTATE = 42S02
2025-07-01 05:53:42.775 E         + Dynamic SQL Error
2025-07-01 05:53:42.782 E         + -SQL error code = -204
2025-07-01 05:53:42.792 E         + -Table unknown
2025-07-01 05:53:42.801 E         + -"PLG$PROF_PSQL_STATS"
2025-07-01 05:53:42.809 E         + -At line 13, column 12
2025-07-01 05:53:42.821 E         + Statement failed, SQLSTATE = 42S02
2025-07-01 05:53:42.831 E         + Dynamic SQL Error
2025-07-01 05:53:42.839 E         + -SQL error code = -204
2025-07-01 05:53:42.847 E         + -Table unknown
2025-07-01 05:53:42.853 E         + -"PLG$PROF_RECORD_SOURCE_STATS"
2025-07-01 05:53:42.858 E         + -At line 17, column 12
2025-07-01 05:53:42.867 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-07-01 05:53:42.875 E         - PROFILE_ID 1
2025-07-01 05:53:42.883 E         - ATTACHMENT_ID
2025-07-01 05:53:42.891 E         - USER_NAME SYSDBA
2025-07-01 05:53:42.900 E         - DESCRIPTION profile session 1
2025-07-01 05:53:42.908 E         - START_TIMESTAMP
2025-07-01 05:53:42.915 E         - FINISH_TIMESTAMP
2025-07-01 05:53:42.921 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-07-01 05:53:42.926 E         - PROFILE_ID 2
2025-07-01 05:53:42.933 E         - ATTACHMENT_ID
2025-07-01 05:53:42.939 E         - USER_NAME SYSDBA
2025-07-01 05:53:42.947 E         - DESCRIPTION profile session 2
2025-07-01 05:53:42.955 E         - START_TIMESTAMP
2025-07-01 05:53:42.966 E         - FINISH_TIMESTAMP
2025-07-01 05:53:42.976 E         - Records affected: 2
2025-07-01 05:53:42.983 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:42.990 E         - PROFILE_ID 1
2025-07-01 05:53:42.994 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:43.000 E         - SQL_TEXT
2025-07-01 05:53:43.006 E         - execute block
2025-07-01 05:53:43.012 E         - as
2025-07-01 05:53:43.018 E         - begin
2025-07-01 05:53:43.024 E         - execute procedure ins;
2025-07-01 05:53:43.030 E         - delete from tab;
2025-07-01 05:53:43.034 E         - end
2025-07-01 05:53:43.040 E         - LINE_NUM
2025-07-01 05:53:43.046 E         - COLUMN_NUM
2025-07-01 05:53:43.052 E         - COUNTER 1
2025-07-01 05:53:43.060 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.067 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.074 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.080 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.086 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:43.095 E         - PROFILE_ID 1
2025-07-01 05:53:43.099 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:43.104 E         - SQL_TEXT
2025-07-01 05:53:43.109 E         - execute block
2025-07-01 05:53:43.113 E         - as
2025-07-01 05:53:43.118 E         - begin
2025-07-01 05:53:43.122 E         - execute procedure ins;
2025-07-01 05:53:43.127 E         - delete from tab;
2025-07-01 05:53:43.132 E         - end
2025-07-01 05:53:43.138 E         - LINE_NUM
2025-07-01 05:53:43.143 E         - COLUMN_NUM
2025-07-01 05:53:43.149 E         - COUNTER 1
2025-07-01 05:53:43.156 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.163 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.169 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.173 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.178 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:43.183 E         - PROFILE_ID 1
2025-07-01 05:53:43.188 E         - STATEMENT_TYPE PROCEDURE
2025-07-01 05:53:43.194 E         - SQL_TEXT
2025-07-01 05:53:43.200 E         - LINE_NUM
2025-07-01 05:53:43.208 E         - COLUMN_NUM
2025-07-01 05:53:43.217 E         - COUNTER 1
2025-07-01 05:53:43.229 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.242 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.253 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.261 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.268 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:43.280 E         - PROFILE_ID 1
2025-07-01 05:53:43.287 E         - STATEMENT_TYPE PROCEDURE
2025-07-01 05:53:43.295 E         - SQL_TEXT
2025-07-01 05:53:43.303 E         - LINE_NUM
2025-07-01 05:53:43.313 E         - COLUMN_NUM
2025-07-01 05:53:43.322 E         - COUNTER 1001
2025-07-01 05:53:43.333 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.343 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.355 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.361 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.367 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:43.373 E         - PROFILE_ID 1
2025-07-01 05:53:43.379 E         - STATEMENT_TYPE PROCEDURE
2025-07-01 05:53:43.386 E         - SQL_TEXT
2025-07-01 05:53:43.391 E         - LINE_NUM
2025-07-01 05:53:43.396 E         - COLUMN_NUM
2025-07-01 05:53:43.402 E         - COUNTER 1000
2025-07-01 05:53:43.415 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.425 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.432 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.439 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.446 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:43.452 E         - PROFILE_ID 1
2025-07-01 05:53:43.458 E         - STATEMENT_TYPE PROCEDURE
2025-07-01 05:53:43.464 E         - SQL_TEXT
2025-07-01 05:53:43.471 E         - LINE_NUM
2025-07-01 05:53:43.483 E         - COLUMN_NUM
2025-07-01 05:53:43.492 E         - COUNTER 500
2025-07-01 05:53:43.499 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.506 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.512 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.518 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.529 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:43.539 E         - PROFILE_ID 1
2025-07-01 05:53:43.548 E         - STATEMENT_TYPE PROCEDURE
2025-07-01 05:53:43.555 E         - SQL_TEXT
2025-07-01 05:53:43.569 E         - LINE_NUM
2025-07-01 05:53:43.582 E         - COLUMN_NUM
2025-07-01 05:53:43.591 E         - COUNTER 1000
2025-07-01 05:53:43.598 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.605 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.611 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.617 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.624 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-07-01 05:53:43.630 E         - PROFILE_ID 1
2025-07-01 05:53:43.634 E         - STATEMENT_TYPE FUNCTION
2025-07-01 05:53:43.640 E         - SQL_TEXT
2025-07-01 05:53:43.646 E         - LINE_NUM
2025-07-01 05:53:43.652 E         - COLUMN_NUM
2025-07-01 05:53:43.658 E         - COUNTER 500
2025-07-01 05:53:43.664 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:43.670 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:43.675 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.680 E         - AVG_ELAPSED_TIME
2025-07-01 05:53:43.686 E         - Records affected: 8
2025-07-01 05:53:43.691 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:43.697 E         - PROFILE_ID 1
2025-07-01 05:53:43.703 E         - STATEMENT_ID
2025-07-01 05:53:43.709 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:43.715 E         - PACKAGE_NAME <null>
2025-07-01 05:53:43.723 E         - ROUTINE_NAME <null>
2025-07-01 05:53:43.733 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:43.741 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:43.748 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:43.754 E         - SQL_TEXT
2025-07-01 05:53:43.760 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-07-01 05:53:43.767 E         - CURSOR_ID 1
2025-07-01 05:53:43.773 E         - CURSOR_NAME <null>
2025-07-01 05:53:43.778 E         - CURSOR_LINE_NUM
2025-07-01 05:53:43.786 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:43.797 E         - RECORD_SOURCE_ID 2
2025-07-01 05:53:43.805 E         - PARENT_RECORD_SOURCE_ID 1
2025-07-01 05:53:43.811 E         - ACCESS_PATH 84:1
2025-07-01 05:53:43.823 E         - -> Table "RDB$DATABASE" Full Scan
2025-07-01 05:53:43.833 E         - OPEN_COUNTER 0
2025-07-01 05:53:43.844 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:43.855 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:43.866 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.875 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:43.884 E         - FETCH_COUNTER
2025-07-01 05:53:43.892 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:43.898 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:43.909 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.919 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:43.930 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:43.940 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:43.947 E         - PROFILE_ID 1
2025-07-01 05:53:43.954 E         - STATEMENT_ID
2025-07-01 05:53:43.961 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:43.966 E         - PACKAGE_NAME <null>
2025-07-01 05:53:43.972 E         - ROUTINE_NAME <null>
2025-07-01 05:53:43.978 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:43.989 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:44.001 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:44.011 E         - SQL_TEXT
2025-07-01 05:53:44.023 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-07-01 05:53:44.033 E         - CURSOR_ID 1
2025-07-01 05:53:44.044 E         - CURSOR_NAME <null>
2025-07-01 05:53:44.052 E         - CURSOR_LINE_NUM
2025-07-01 05:53:44.060 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:44.067 E         - RECORD_SOURCE_ID 1
2025-07-01 05:53:44.074 E         - PARENT_RECORD_SOURCE_ID <null>
2025-07-01 05:53:44.080 E         - ACCESS_PATH 84:0
2025-07-01 05:53:44.086 E         - Select Expression
2025-07-01 05:53:44.097 E         - OPEN_COUNTER 0
2025-07-01 05:53:44.107 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:44.115 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:44.122 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.131 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:44.143 E         - FETCH_COUNTER
2025-07-01 05:53:44.150 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:44.157 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:44.163 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.168 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:44.173 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.178 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:44.183 E         - PROFILE_ID 1
2025-07-01 05:53:44.187 E         - STATEMENT_ID
2025-07-01 05:53:44.192 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:44.197 E         - PACKAGE_NAME <null>
2025-07-01 05:53:44.202 E         - ROUTINE_NAME <null>
2025-07-01 05:53:44.207 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:44.211 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:44.216 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:44.221 E         - SQL_TEXT
2025-07-01 05:53:44.225 E         - execute block
2025-07-01 05:53:44.230 E         - as
2025-07-01 05:53:44.234 E         - begin
2025-07-01 05:53:44.239 E         - execute procedure ins;
2025-07-01 05:53:44.244 E         - delete from tab;
2025-07-01 05:53:44.249 E         - end
2025-07-01 05:53:44.256 E         - CURSOR_ID 1
2025-07-01 05:53:44.263 E         - CURSOR_NAME <null>
2025-07-01 05:53:44.270 E         - CURSOR_LINE_NUM
2025-07-01 05:53:44.281 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:44.293 E         - RECORD_SOURCE_ID 2
2025-07-01 05:53:44.302 E         - PARENT_RECORD_SOURCE_ID 1
2025-07-01 05:53:44.309 E         - ACCESS_PATH 84:3
2025-07-01 05:53:44.316 E         - -> Table "TAB" Full Scan
2025-07-01 05:53:44.323 E         - OPEN_COUNTER 1
2025-07-01 05:53:44.329 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:44.336 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:44.343 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.350 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:44.357 E         - FETCH_COUNTER
2025-07-01 05:53:44.363 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:44.376 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:44.387 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.394 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:44.400 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.406 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:44.417 E         - PROFILE_ID 1
2025-07-01 05:53:44.427 E         - STATEMENT_ID
2025-07-01 05:53:44.435 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:44.441 E         - PACKAGE_NAME <null>
2025-07-01 05:53:44.449 E         - ROUTINE_NAME <null>
2025-07-01 05:53:44.459 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:44.469 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:44.477 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:44.483 E         - SQL_TEXT
2025-07-01 05:53:44.488 E         - execute block
2025-07-01 05:53:44.494 E         - as
2025-07-01 05:53:44.499 E         - begin
2025-07-01 05:53:44.506 E         - execute procedure ins;
2025-07-01 05:53:44.517 E         - delete from tab;
2025-07-01 05:53:44.525 E         - end
2025-07-01 05:53:44.532 E         - CURSOR_ID 1
2025-07-01 05:53:44.539 E         - CURSOR_NAME <null>
2025-07-01 05:53:44.545 E         - CURSOR_LINE_NUM
2025-07-01 05:53:44.551 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:44.556 E         - RECORD_SOURCE_ID 1
2025-07-01 05:53:44.562 E         - PARENT_RECORD_SOURCE_ID <null>
2025-07-01 05:53:44.567 E         - ACCESS_PATH 84:2
2025-07-01 05:53:44.573 E         - Select Expression (line 5, column 9)
2025-07-01 05:53:44.585 E         - OPEN_COUNTER 1
2025-07-01 05:53:44.597 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:44.606 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:44.612 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.618 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:44.629 E         - FETCH_COUNTER
2025-07-01 05:53:44.641 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:44.650 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:44.655 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.660 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:44.665 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.671 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:44.678 E         - PROFILE_ID 2
2025-07-01 05:53:44.685 E         - STATEMENT_ID
2025-07-01 05:53:44.691 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:44.697 E         - PACKAGE_NAME <null>
2025-07-01 05:53:44.702 E         - ROUTINE_NAME <null>
2025-07-01 05:53:44.708 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:44.713 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:44.719 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:44.726 E         - SQL_TEXT
2025-07-01 05:53:44.736 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-07-01 05:53:44.748 E         - CURSOR_ID 1
2025-07-01 05:53:44.761 E         - CURSOR_NAME <null>
2025-07-01 05:53:44.773 E         - CURSOR_LINE_NUM
2025-07-01 05:53:44.784 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:44.795 E         - RECORD_SOURCE_ID 2
2025-07-01 05:53:44.804 E         - PARENT_RECORD_SOURCE_ID 1
2025-07-01 05:53:44.813 E         - ACCESS_PATH 84:5
2025-07-01 05:53:44.822 E         - -> Table "RDB$DATABASE" Full Scan
2025-07-01 05:53:44.831 E         - OPEN_COUNTER 0
2025-07-01 05:53:44.843 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:44.853 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:44.861 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.868 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:44.874 E         - FETCH_COUNTER
2025-07-01 05:53:44.884 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:44.895 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:44.903 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.913 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:44.926 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:44.937 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:44.945 E         - PROFILE_ID 2
2025-07-01 05:53:44.953 E         - STATEMENT_ID
2025-07-01 05:53:44.960 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:44.969 E         - PACKAGE_NAME <null>
2025-07-01 05:53:44.981 E         - ROUTINE_NAME <null>
2025-07-01 05:53:44.991 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:45.004 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:45.015 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:45.022 E         - SQL_TEXT
2025-07-01 05:53:45.030 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-07-01 05:53:45.036 E         - CURSOR_ID 1
2025-07-01 05:53:45.042 E         - CURSOR_NAME <null>
2025-07-01 05:53:45.049 E         - CURSOR_LINE_NUM
2025-07-01 05:53:45.054 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:45.061 E         - RECORD_SOURCE_ID 1
2025-07-01 05:53:45.067 E         - PARENT_RECORD_SOURCE_ID <null>
2025-07-01 05:53:45.072 E         - ACCESS_PATH 84:4
2025-07-01 05:53:45.077 E         - Select Expression
2025-07-01 05:53:45.083 E         - OPEN_COUNTER 0
2025-07-01 05:53:45.091 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:45.100 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:45.108 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.118 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:45.127 E         - FETCH_COUNTER
2025-07-01 05:53:45.138 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:45.146 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:45.157 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.169 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:45.182 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.196 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:45.208 E         - PROFILE_ID 2
2025-07-01 05:53:45.220 E         - STATEMENT_ID
2025-07-01 05:53:45.228 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:45.235 E         - PACKAGE_NAME <null>
2025-07-01 05:53:45.242 E         - ROUTINE_NAME <null>
2025-07-01 05:53:45.249 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:45.256 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:45.262 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:45.274 E         - SQL_TEXT
2025-07-01 05:53:45.285 E         - select mod(id, 5),
2025-07-01 05:53:45.295 E         - sum(val)
2025-07-01 05:53:45.306 E         - from tab
2025-07-01 05:53:45.317 E         - where id <= 50
2025-07-01 05:53:45.324 E         - group by mod(id, 5)
2025-07-01 05:53:45.330 E         - order by sum(val)
2025-07-01 05:53:45.335 E         - CURSOR_ID 1
2025-07-01 05:53:45.343 E         - CURSOR_NAME <null>
2025-07-01 05:53:45.352 E         - CURSOR_LINE_NUM
2025-07-01 05:53:45.360 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:45.367 E         - RECORD_SOURCE_ID 2
2025-07-01 05:53:45.374 E         - PARENT_RECORD_SOURCE_ID 1
2025-07-01 05:53:45.380 E         - ACCESS_PATH 84:7
2025-07-01 05:53:45.386 E         - -> Sort (record length: 44, key length: 12)
2025-07-01 05:53:45.392 E         - OPEN_COUNTER 1
2025-07-01 05:53:45.398 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:45.403 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:45.409 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.414 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:45.424 E         - FETCH_COUNTER
2025-07-01 05:53:45.440 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:45.452 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:45.462 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.474 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:45.485 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.494 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:45.502 E         - PROFILE_ID 2
2025-07-01 05:53:45.513 E         - STATEMENT_ID
2025-07-01 05:53:45.523 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:45.533 E         - PACKAGE_NAME <null>
2025-07-01 05:53:45.542 E         - ROUTINE_NAME <null>
2025-07-01 05:53:45.553 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:45.560 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:45.567 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:45.573 E         - SQL_TEXT
2025-07-01 05:53:45.579 E         - select mod(id, 5),
2025-07-01 05:53:45.584 E         - sum(val)
2025-07-01 05:53:45.590 E         - from tab
2025-07-01 05:53:45.601 E         - where id <= 50
2025-07-01 05:53:45.611 E         - group by mod(id, 5)
2025-07-01 05:53:45.620 E         - order by sum(val)
2025-07-01 05:53:45.627 E         - CURSOR_ID 1
2025-07-01 05:53:45.633 E         - CURSOR_NAME <null>
2025-07-01 05:53:45.640 E         - CURSOR_LINE_NUM
2025-07-01 05:53:45.646 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:45.651 E         - RECORD_SOURCE_ID 3
2025-07-01 05:53:45.660 E         - PARENT_RECORD_SOURCE_ID 2
2025-07-01 05:53:45.671 E         - ACCESS_PATH 84:8
2025-07-01 05:53:45.679 E         - -> Aggregate
2025-07-01 05:53:45.687 E         - OPEN_COUNTER 1
2025-07-01 05:53:45.695 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:45.701 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:45.707 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.713 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:45.719 E         - FETCH_COUNTER
2025-07-01 05:53:45.726 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:45.738 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:45.747 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.757 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:45.764 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:45.770 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:45.780 E         - PROFILE_ID 2
2025-07-01 05:53:45.789 E         - STATEMENT_ID
2025-07-01 05:53:45.796 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:45.802 E         - PACKAGE_NAME <null>
2025-07-01 05:53:45.808 E         - ROUTINE_NAME <null>
2025-07-01 05:53:45.814 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:45.819 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:45.826 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:45.837 E         - SQL_TEXT
2025-07-01 05:53:45.845 E         - select mod(id, 5),
2025-07-01 05:53:45.856 E         - sum(val)
2025-07-01 05:53:45.866 E         - from tab
2025-07-01 05:53:45.878 E         - where id <= 50
2025-07-01 05:53:45.889 E         - group by mod(id, 5)
2025-07-01 05:53:45.900 E         - order by sum(val)
2025-07-01 05:53:45.912 E         - CURSOR_ID 1
2025-07-01 05:53:45.923 E         - CURSOR_NAME <null>
2025-07-01 05:53:45.931 E         - CURSOR_LINE_NUM
2025-07-01 05:53:45.939 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:45.947 E         - RECORD_SOURCE_ID 4
2025-07-01 05:53:45.958 E         - PARENT_RECORD_SOURCE_ID 3
2025-07-01 05:53:45.965 E         - ACCESS_PATH 84:9
2025-07-01 05:53:45.973 E         - -> Sort (record length: 44, key length: 8)
2025-07-01 05:53:45.980 E         - OPEN_COUNTER 1
2025-07-01 05:53:45.986 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:45.991 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:45.997 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.003 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:46.012 E         - FETCH_COUNTER
2025-07-01 05:53:46.020 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:46.028 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:46.034 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.045 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:46.053 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.060 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:46.067 E         - PROFILE_ID 2
2025-07-01 05:53:46.076 E         - STATEMENT_ID
2025-07-01 05:53:46.084 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:46.091 E         - PACKAGE_NAME <null>
2025-07-01 05:53:46.098 E         - ROUTINE_NAME <null>
2025-07-01 05:53:46.103 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:46.108 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:46.114 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:46.119 E         - SQL_TEXT
2025-07-01 05:53:46.127 E         - select mod(id, 5),
2025-07-01 05:53:46.135 E         - sum(val)
2025-07-01 05:53:46.142 E         - from tab
2025-07-01 05:53:46.150 E         - where id <= 50
2025-07-01 05:53:46.161 E         - group by mod(id, 5)
2025-07-01 05:53:46.171 E         - order by sum(val)
2025-07-01 05:53:46.178 E         - CURSOR_ID 1
2025-07-01 05:53:46.187 E         - CURSOR_NAME <null>
2025-07-01 05:53:46.195 E         - CURSOR_LINE_NUM
2025-07-01 05:53:46.203 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:46.213 E         - RECORD_SOURCE_ID 5
2025-07-01 05:53:46.221 E         - PARENT_RECORD_SOURCE_ID 4
2025-07-01 05:53:46.228 E         - ACCESS_PATH 84:a
2025-07-01 05:53:46.235 E         - -> Filter
2025-07-01 05:53:46.244 E         - OPEN_COUNTER 1
2025-07-01 05:53:46.256 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:46.268 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:46.279 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.291 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:46.300 E         - FETCH_COUNTER
2025-07-01 05:53:46.308 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:46.314 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:46.320 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.327 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:46.340 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.351 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:46.362 E         - PROFILE_ID 2
2025-07-01 05:53:46.374 E         - STATEMENT_ID
2025-07-01 05:53:46.387 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:46.397 E         - PACKAGE_NAME <null>
2025-07-01 05:53:46.407 E         - ROUTINE_NAME <null>
2025-07-01 05:53:46.418 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:46.434 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:46.445 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:46.453 E         - SQL_TEXT
2025-07-01 05:53:46.460 E         - select mod(id, 5),
2025-07-01 05:53:46.465 E         - sum(val)
2025-07-01 05:53:46.471 E         - from tab
2025-07-01 05:53:46.476 E         - where id <= 50
2025-07-01 05:53:46.481 E         - group by mod(id, 5)
2025-07-01 05:53:46.487 E         - order by sum(val)
2025-07-01 05:53:46.494 E         - CURSOR_ID 1
2025-07-01 05:53:46.500 E         - CURSOR_NAME <null>
2025-07-01 05:53:46.506 E         - CURSOR_LINE_NUM
2025-07-01 05:53:46.514 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:46.523 E         - RECORD_SOURCE_ID 6
2025-07-01 05:53:46.531 E         - PARENT_RECORD_SOURCE_ID 5
2025-07-01 05:53:46.537 E         - ACCESS_PATH 84:b
2025-07-01 05:53:46.542 E         - -> Table "TAB" Full Scan
2025-07-01 05:53:46.551 E         - OPEN_COUNTER 1
2025-07-01 05:53:46.557 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:46.564 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:46.570 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.580 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:46.591 E         - FETCH_COUNTER
2025-07-01 05:53:46.604 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:46.613 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:46.622 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.632 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:46.643 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.654 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-07-01 05:53:46.663 E         - PROFILE_ID 2
2025-07-01 05:53:46.672 E         - STATEMENT_ID
2025-07-01 05:53:46.679 E         - STATEMENT_TYPE BLOCK
2025-07-01 05:53:46.685 E         - PACKAGE_NAME <null>
2025-07-01 05:53:46.691 E         - ROUTINE_NAME <null>
2025-07-01 05:53:46.697 E         - PARENT_STATEMENT_ID
2025-07-01 05:53:46.703 E         - PARENT_STATEMENT_TYPE <null>
2025-07-01 05:53:46.709 E         - PARENT_ROUTINE_NAME <null>
2025-07-01 05:53:46.715 E         - SQL_TEXT
2025-07-01 05:53:46.720 E         - select mod(id, 5),
2025-07-01 05:53:46.726 E         - sum(val)
2025-07-01 05:53:46.732 E         - from tab
2025-07-01 05:53:46.737 E         - where id <= 50
2025-07-01 05:53:46.743 E         - group by mod(id, 5)
2025-07-01 05:53:46.749 E         - order by sum(val)
2025-07-01 05:53:46.754 E         - CURSOR_ID 1
2025-07-01 05:53:46.760 E         - CURSOR_NAME <null>
2025-07-01 05:53:46.766 E         - CURSOR_LINE_NUM
2025-07-01 05:53:46.772 E         - CURSOR_COLUMN_NUM
2025-07-01 05:53:46.777 E         - RECORD_SOURCE_ID 1
2025-07-01 05:53:46.783 E         - PARENT_RECORD_SOURCE_ID <null>
2025-07-01 05:53:46.789 E         - ACCESS_PATH 84:6
2025-07-01 05:53:46.794 E         - Select Expression
2025-07-01 05:53:46.801 E         - OPEN_COUNTER 1
2025-07-01 05:53:46.807 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:46.813 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:46.819 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.825 E         - OPEN_AVG_ELAPSED_TIME
2025-07-01 05:53:46.831 E         - FETCH_COUNTER
2025-07-01 05:53:46.837 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:46.842 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:46.848 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.854 E         - FETCH_AVG_ELAPSED_TIME
2025-07-01 05:53:46.860 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.866 E         - Records affected: 12
2025-07-01 05:53:46.871 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-07-01 05:53:46.878 E         - PROFILE_ID 1
2025-07-01 05:53:46.884 E         - REQUEST_ID
2025-07-01 05:53:46.890 E         - STATEMENT_ID
2025-07-01 05:53:46.895 E         - CALLER_REQUEST_ID
2025-07-01 05:53:46.901 E         - START_TIMESTAMP
2025-07-01 05:53:46.906 E         - FINISH_TIMESTAMP
2025-07-01 05:53:46.912 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.918 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-07-01 05:53:46.923 E         - PROFILE_ID 1
2025-07-01 05:53:46.929 E         - REQUEST_ID
2025-07-01 05:53:46.936 E         - STATEMENT_ID
2025-07-01 05:53:46.942 E         - CALLER_REQUEST_ID
2025-07-01 05:53:46.948 E         - START_TIMESTAMP
2025-07-01 05:53:46.954 E         - FINISH_TIMESTAMP
2025-07-01 05:53:46.959 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:46.965 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-07-01 05:53:46.971 E         - PROFILE_ID 1
2025-07-01 05:53:46.977 E         - REQUEST_ID
2025-07-01 05:53:46.983 E         - STATEMENT_ID
2025-07-01 05:53:46.988 E         - CALLER_REQUEST_ID
2025-07-01 05:53:46.994 E         - START_TIMESTAMP
2025-07-01 05:53:47.000 E         - FINISH_TIMESTAMP
2025-07-01 05:53:47.011 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.022 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-07-01 05:53:47.031 E         - PROFILE_ID 1
2025-07-01 05:53:47.037 E         - REQUEST_ID
2025-07-01 05:53:47.048 E         - STATEMENT_ID
2025-07-01 05:53:47.057 E         - CALLER_REQUEST_ID
2025-07-01 05:53:47.065 E         - START_TIMESTAMP
2025-07-01 05:53:47.071 E         - FINISH_TIMESTAMP
2025-07-01 05:53:47.084 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.095 E         - Records affected: 4
2025-07-01 05:53:47.104 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.112 E         - PROFILE_ID 1
2025-07-01 05:53:47.118 E         - REQUEST_ID
2025-07-01 05:53:47.124 E         - LINE_NUM
2025-07-01 05:53:47.136 E         - COLUMN_NUM
2025-07-01 05:53:47.144 E         - STATEMENT_ID
2025-07-01 05:53:47.151 E         - COUNTER 1
2025-07-01 05:53:47.159 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.172 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.183 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.192 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.200 E         - PROFILE_ID 1
2025-07-01 05:53:47.206 E         - REQUEST_ID
2025-07-01 05:53:47.212 E         - LINE_NUM
2025-07-01 05:53:47.221 E         - COLUMN_NUM
2025-07-01 05:53:47.227 E         - STATEMENT_ID
2025-07-01 05:53:47.233 E         - COUNTER 1
2025-07-01 05:53:47.239 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.245 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.251 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.259 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.272 E         - PROFILE_ID 1
2025-07-01 05:53:47.279 E         - REQUEST_ID
2025-07-01 05:53:47.286 E         - LINE_NUM
2025-07-01 05:53:47.292 E         - COLUMN_NUM
2025-07-01 05:53:47.298 E         - STATEMENT_ID
2025-07-01 05:53:47.304 E         - COUNTER 1
2025-07-01 05:53:47.311 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.317 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.324 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.331 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.341 E         - PROFILE_ID 1
2025-07-01 05:53:47.354 E         - REQUEST_ID
2025-07-01 05:53:47.364 E         - LINE_NUM
2025-07-01 05:53:47.374 E         - COLUMN_NUM
2025-07-01 05:53:47.383 E         - STATEMENT_ID
2025-07-01 05:53:47.390 E         - COUNTER 1001
2025-07-01 05:53:47.400 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.407 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.413 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.420 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.427 E         - PROFILE_ID 1
2025-07-01 05:53:47.435 E         - REQUEST_ID
2025-07-01 05:53:47.442 E         - LINE_NUM
2025-07-01 05:53:47.450 E         - COLUMN_NUM
2025-07-01 05:53:47.456 E         - STATEMENT_ID
2025-07-01 05:53:47.463 E         - COUNTER 1000
2025-07-01 05:53:47.470 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.477 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.482 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.490 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.496 E         - PROFILE_ID 1
2025-07-01 05:53:47.502 E         - REQUEST_ID
2025-07-01 05:53:47.509 E         - LINE_NUM
2025-07-01 05:53:47.517 E         - COLUMN_NUM
2025-07-01 05:53:47.523 E         - STATEMENT_ID
2025-07-01 05:53:47.529 E         - COUNTER 500
2025-07-01 05:53:47.534 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.540 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.546 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.552 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.559 E         - PROFILE_ID 1
2025-07-01 05:53:47.566 E         - REQUEST_ID
2025-07-01 05:53:47.572 E         - LINE_NUM
2025-07-01 05:53:47.577 E         - COLUMN_NUM
2025-07-01 05:53:47.582 E         - STATEMENT_ID
2025-07-01 05:53:47.589 E         - COUNTER 1000
2025-07-01 05:53:47.594 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.600 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.606 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.613 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-07-01 05:53:47.619 E         - PROFILE_ID 1
2025-07-01 05:53:47.626 E         - REQUEST_ID
2025-07-01 05:53:47.638 E         - LINE_NUM
2025-07-01 05:53:47.646 E         - COLUMN_NUM
2025-07-01 05:53:47.652 E         - STATEMENT_ID
2025-07-01 05:53:47.658 E         - COUNTER 500
2025-07-01 05:53:47.663 E         - MIN_ELAPSED_TIME
2025-07-01 05:53:47.668 E         - MAX_ELAPSED_TIME
2025-07-01 05:53:47.673 E         - TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.677 E         - Records affected: 8
2025-07-01 05:53:47.682 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:47.687 E         - PROFILE_ID 2
2025-07-01 05:53:47.693 E         - REQUEST_ID
2025-07-01 05:53:47.699 E         - CURSOR_ID 1
2025-07-01 05:53:47.705 E         - RECORD_SOURCE_ID 1
2025-07-01 05:53:47.711 E         - STATEMENT_ID
2025-07-01 05:53:47.720 E         - OPEN_COUNTER 0
2025-07-01 05:53:47.732 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:47.740 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:47.747 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.753 E         - FETCH_COUNTER
2025-07-01 05:53:47.759 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:47.769 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:47.781 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.793 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:47.805 E         - PROFILE_ID 2
2025-07-01 05:53:47.817 E         - REQUEST_ID
2025-07-01 05:53:47.829 E         - CURSOR_ID 1
2025-07-01 05:53:47.840 E         - RECORD_SOURCE_ID 2
2025-07-01 05:53:47.854 E         - STATEMENT_ID
2025-07-01 05:53:47.866 E         - OPEN_COUNTER 0
2025-07-01 05:53:47.877 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:47.889 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:47.899 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.910 E         - FETCH_COUNTER
2025-07-01 05:53:47.920 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:47.927 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:47.934 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:47.941 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:47.946 E         - PROFILE_ID 2
2025-07-01 05:53:47.956 E         - REQUEST_ID
2025-07-01 05:53:47.965 E         - CURSOR_ID 1
2025-07-01 05:53:47.973 E         - RECORD_SOURCE_ID 1
2025-07-01 05:53:47.980 E         - STATEMENT_ID
2025-07-01 05:53:47.986 E         - OPEN_COUNTER 1
2025-07-01 05:53:47.996 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:48.004 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:48.012 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.019 E         - FETCH_COUNTER
2025-07-01 05:53:48.025 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:48.031 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:48.037 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.042 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:48.048 E         - PROFILE_ID 2
2025-07-01 05:53:48.054 E         - REQUEST_ID
2025-07-01 05:53:48.060 E         - CURSOR_ID 1
2025-07-01 05:53:48.066 E         - RECORD_SOURCE_ID 2
2025-07-01 05:53:48.072 E         - STATEMENT_ID
2025-07-01 05:53:48.079 E         - OPEN_COUNTER 1
2025-07-01 05:53:48.085 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:48.092 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:48.099 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.105 E         - FETCH_COUNTER
2025-07-01 05:53:48.110 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:48.121 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:48.133 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.142 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:48.149 E         - PROFILE_ID 2
2025-07-01 05:53:48.155 E         - REQUEST_ID
2025-07-01 05:53:48.161 E         - CURSOR_ID 1
2025-07-01 05:53:48.167 E         - RECORD_SOURCE_ID 3
2025-07-01 05:53:48.175 E         - STATEMENT_ID
2025-07-01 05:53:48.187 E         - OPEN_COUNTER 1
2025-07-01 05:53:48.196 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:48.204 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:48.211 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.217 E         - FETCH_COUNTER
2025-07-01 05:53:48.223 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:48.235 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:48.244 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.253 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:48.260 E         - PROFILE_ID 2
2025-07-01 05:53:48.269 E         - REQUEST_ID
2025-07-01 05:53:48.280 E         - CURSOR_ID 1
2025-07-01 05:53:48.289 E         - RECORD_SOURCE_ID 4
2025-07-01 05:53:48.297 E         - STATEMENT_ID
2025-07-01 05:53:48.304 E         - OPEN_COUNTER 1
2025-07-01 05:53:48.310 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:48.324 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:48.333 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.340 E         - FETCH_COUNTER
2025-07-01 05:53:48.345 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:48.351 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:48.358 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.368 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:48.379 E         - PROFILE_ID 2
2025-07-01 05:53:48.390 E         - REQUEST_ID
2025-07-01 05:53:48.398 E         - CURSOR_ID 1
2025-07-01 05:53:48.408 E         - RECORD_SOURCE_ID 5
2025-07-01 05:53:48.415 E         - STATEMENT_ID
2025-07-01 05:53:48.421 E         - OPEN_COUNTER 1
2025-07-01 05:53:48.427 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:48.435 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:48.442 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.448 E         - FETCH_COUNTER
2025-07-01 05:53:48.455 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:48.463 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:48.470 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.477 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-07-01 05:53:48.484 E         - PROFILE_ID 2
2025-07-01 05:53:48.490 E         - REQUEST_ID
2025-07-01 05:53:48.502 E         - CURSOR_ID 1
2025-07-01 05:53:48.513 E         - RECORD_SOURCE_ID 6
2025-07-01 05:53:48.525 E         - STATEMENT_ID
2025-07-01 05:53:48.534 E         - OPEN_COUNTER 1
2025-07-01 05:53:48.541 E         - OPEN_MIN_ELAPSED_TIME
2025-07-01 05:53:48.548 E         - OPEN_MAX_ELAPSED_TIME
2025-07-01 05:53:48.555 E         - OPEN_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.562 E         - FETCH_COUNTER
2025-07-01 05:53:48.568 E         - FETCH_MIN_ELAPSED_TIME
2025-07-01 05:53:48.575 E         - FETCH_MAX_ELAPSED_TIME
2025-07-01 05:53:48.582 E         - FETCH_TOTAL_ELAPSED_TIME
2025-07-01 05:53:48.589 E         - Records affected: 8
2025-07-01 05:53:48.596
2025-07-01 05:53:48.602 tests/bugs/gh_7086_test.py:1795: AssertionError
2025-07-01 05:53:48.609 ---------------------------- Captured stdout setup -----------------------------
2025-07-01 05:53:48.615 Creating db: localhost:/var/tmp/qa_2024/test_11498/test.fdb [page_size=None, sql_dialect=None, charset='NONE', user=SYSDBA, password=masterkey]
3 #text
act = <firebird.qa.plugin.Action pytest object at [hex]>

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

tests/bugs/gh_7086_test.py:1795: AssertionError
Full history of outcomes and elapsed time, ms:
NN SNAP_INFO CS_outcome SS_outcome CS_run_time SS_run_time CS_run_beg CS_run_end SS_run_beg SS_run_end
1 6.0.0.884 2025.06.30 f7e5f F F 1067 1017 2025.07.01 02:07:15.086 2025.07.01 02:07:16.153 2025.06.30 23:25:25.006 2025.06.30 23:25:26.023
2 6.0.0.881 2025.06.27 7035d F F 1202 764 2025.06.30 01:57:03.464 2025.06.30 01:57:04.666 2025.06.29 23:12:08.046 2025.06.29 23:12:08.810
3 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
4 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
5 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
6 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
7 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
8 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
9 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
10 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
11 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
12 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
13 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
14 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
15 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
16 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
17 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
18 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
19 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
20 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
21 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
22 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
23 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
24 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
25 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
26 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
27 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
28 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
29 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
30 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
31 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
32 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
33 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
34 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
35 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
36 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
37 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
38 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
39 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
40 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
41 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
42 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
43 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
44 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
45 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
46 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
47 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
48 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
49 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
50 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
51 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
52 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
53 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
54 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
55 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
56 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
57 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
58 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
59 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
60 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
61 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
62 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
63 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
64 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
65 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
66 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
67 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
68 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
69 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
70 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
71 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
72 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
73 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
74 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
75 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
76 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
77 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
78 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
79 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
80 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
81 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
82 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
83 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
84 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
85 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
86 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
87 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
88 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
89 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
90 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
91 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
92 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
93 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
94 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
95 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
96 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
97 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
98 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
99 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
100 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
101 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
102 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
103 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
104 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
105 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
106 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
107 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
108 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
109 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
110 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
111 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
112 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
113 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
114 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
115 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
116 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
117 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
118 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
119 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
120 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
121 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
122 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
123 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
124 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
125 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
126 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
127 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
128 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
129 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
130 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
131 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
132 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
133 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
134 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
135 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
136 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
137 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
138 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
139 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
140 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
141 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
142 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
143 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
144 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
145 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
146 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
147 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
148 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
149 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
150 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
151 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
152 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
153 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
154 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
155 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
156 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
157 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
158 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
159 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
160 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
161 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
162 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
163 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
164 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
165 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
166 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
167 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
168 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
169 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
170 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
171 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
172 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
173 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
174 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
175 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
176 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
177 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
178 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
179 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
180 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
181 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
182 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
183 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
184 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
185 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
186 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
187 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
188 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
189 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
190 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):