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

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

LOG DETAILS:

2025-06-27 05:17:12.503
2025-06-27 05:17:12.510 act = <firebird.qa.plugin.Action object at [hex]>
2025-06-27 05:17:12.516
2025-06-27 05:17:12.522 @pytest.mark.version('>=5.0')
2025-06-27 05:17:12.527 def test_1(act: Action):
2025-06-27 05:17:12.534 act.expected_stdout = fb5x_expected_out if act.is_version('<6') else fb6x_expected_out
2025-06-27 05:17:12.540 act.execute(combine_output = True)
2025-06-27 05:17:12.545 >       assert act.clean_stdout == act.clean_expected_stdout
2025-06-27 05:17:12.551 E       assert
2025-06-27 05:17:12.556 E           START_SESSION 1
2025-06-27 05:17:12.562 E           START_SESSION 2
2025-06-27 05:17:12.572 E         + Statement failed, SQLSTATE = 42S02
2025-06-27 05:17:12.583 E         + Dynamic SQL Error
2025-06-27 05:17:12.593 E         + -SQL error code = -204
2025-06-27 05:17:12.600 E         + -Table unknown
2025-06-27 05:17:12.605 E         + -"PLG$PROF_SESSIONS"
2025-06-27 05:17:12.611 E         + -At line 5, column 10
2025-06-27 05:17:12.616 E         + Statement failed, SQLSTATE = 42S02
2025-06-27 05:17:12.620 E         + Dynamic SQL Error
2025-06-27 05:17:12.625 E         + -SQL error code = -204
2025-06-27 05:17:12.630 E         + -Table unknown
2025-06-27 05:17:12.635 E         + -"PLG$PROF_PSQL_STATS_VIEW"
2025-06-27 05:17:12.642 E         + -At line 14, column 10
2025-06-27 05:17:12.649 E         + Statement failed, SQLSTATE = 42S02
2025-06-27 05:17:12.661 E         + Dynamic SQL Error
2025-06-27 05:17:12.671 E         + -SQL error code = -204
2025-06-27 05:17:12.681 E         + -Table unknown
2025-06-27 05:17:12.689 E         + -"PLG$PROF_RECORD_SOURCE_STATS_VIEW"
2025-06-27 05:17:12.695 E         + -At line 31, column 10
2025-06-27 05:17:12.701 E         + Statement failed, SQLSTATE = 42S02
2025-06-27 05:17:12.706 E         + Dynamic SQL Error
2025-06-27 05:17:12.711 E         + -SQL error code = -204
2025-06-27 05:17:12.721 E         + -Table unknown
2025-06-27 05:17:12.728 E         + -"PLG$PROF_REQUESTS"
2025-06-27 05:17:12.741 E         + -At line 11, column 12
2025-06-27 05:17:12.750 E         + Statement failed, SQLSTATE = 42S02
2025-06-27 05:17:12.762 E         + Dynamic SQL Error
2025-06-27 05:17:12.769 E         + -SQL error code = -204
2025-06-27 05:17:12.775 E         + -Table unknown
2025-06-27 05:17:12.785 E         + -"PLG$PROF_PSQL_STATS"
2025-06-27 05:17:12.796 E         + -At line 13, column 12
2025-06-27 05:17:12.809 E         + Statement failed, SQLSTATE = 42S02
2025-06-27 05:17:12.819 E         + Dynamic SQL Error
2025-06-27 05:17:12.830 E         + -SQL error code = -204
2025-06-27 05:17:12.838 E         + -Table unknown
2025-06-27 05:17:12.844 E         + -"PLG$PROF_RECORD_SOURCE_STATS"
2025-06-27 05:17:12.850 E         + -At line 17, column 12
2025-06-27 05:17:12.856 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-06-27 05:17:12.863 E         - PROFILE_ID 1
2025-06-27 05:17:12.869 E         - ATTACHMENT_ID
2025-06-27 05:17:12.876 E         - USER_NAME SYSDBA
2025-06-27 05:17:12.882 E         - DESCRIPTION profile session 1
2025-06-27 05:17:12.889 E         - START_TIMESTAMP
2025-06-27 05:17:12.895 E         - FINISH_TIMESTAMP
2025-06-27 05:17:12.902 E         - MSG --- [ 1: plg$prof_sessions ] ---
2025-06-27 05:17:12.913 E         - PROFILE_ID 2
2025-06-27 05:17:12.922 E         - ATTACHMENT_ID
2025-06-27 05:17:12.929 E         - USER_NAME SYSDBA
2025-06-27 05:17:12.936 E         - DESCRIPTION profile session 2
2025-06-27 05:17:12.942 E         - START_TIMESTAMP
2025-06-27 05:17:12.952 E         - FINISH_TIMESTAMP
2025-06-27 05:17:12.961 E         - Records affected: 2
2025-06-27 05:17:12.967 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:12.973 E         - PROFILE_ID 1
2025-06-27 05:17:12.979 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:12.985 E         - SQL_TEXT
2025-06-27 05:17:12.996 E         - execute block
2025-06-27 05:17:13.004 E         - as
2025-06-27 05:17:13.012 E         - begin
2025-06-27 05:17:13.017 E         - execute procedure ins;
2025-06-27 05:17:13.023 E         - delete from tab;
2025-06-27 05:17:13.027 E         - end
2025-06-27 05:17:13.032 E         - LINE_NUM
2025-06-27 05:17:13.036 E         - COLUMN_NUM
2025-06-27 05:17:13.041 E         - COUNTER 1
2025-06-27 05:17:13.045 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.050 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.057 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.064 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.071 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:13.077 E         - PROFILE_ID 1
2025-06-27 05:17:13.084 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:13.091 E         - SQL_TEXT
2025-06-27 05:17:13.097 E         - execute block
2025-06-27 05:17:13.104 E         - as
2025-06-27 05:17:13.111 E         - begin
2025-06-27 05:17:13.118 E         - execute procedure ins;
2025-06-27 05:17:13.124 E         - delete from tab;
2025-06-27 05:17:13.131 E         - end
2025-06-27 05:17:13.137 E         - LINE_NUM
2025-06-27 05:17:13.142 E         - COLUMN_NUM
2025-06-27 05:17:13.148 E         - COUNTER 1
2025-06-27 05:17:13.155 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.166 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.177 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.187 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.197 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:13.204 E         - PROFILE_ID 1
2025-06-27 05:17:13.214 E         - STATEMENT_TYPE PROCEDURE
2025-06-27 05:17:13.226 E         - SQL_TEXT
2025-06-27 05:17:13.235 E         - LINE_NUM
2025-06-27 05:17:13.248 E         - COLUMN_NUM
2025-06-27 05:17:13.260 E         - COUNTER 1
2025-06-27 05:17:13.271 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.279 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.287 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.293 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.299 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:13.306 E         - PROFILE_ID 1
2025-06-27 05:17:13.315 E         - STATEMENT_TYPE PROCEDURE
2025-06-27 05:17:13.324 E         - SQL_TEXT
2025-06-27 05:17:13.332 E         - LINE_NUM
2025-06-27 05:17:13.340 E         - COLUMN_NUM
2025-06-27 05:17:13.346 E         - COUNTER 1001
2025-06-27 05:17:13.357 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.365 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.372 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.379 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.388 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:13.400 E         - PROFILE_ID 1
2025-06-27 05:17:13.411 E         - STATEMENT_TYPE PROCEDURE
2025-06-27 05:17:13.420 E         - SQL_TEXT
2025-06-27 05:17:13.427 E         - LINE_NUM
2025-06-27 05:17:13.436 E         - COLUMN_NUM
2025-06-27 05:17:13.448 E         - COUNTER 1000
2025-06-27 05:17:13.460 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.469 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.477 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.484 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.490 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:13.495 E         - PROFILE_ID 1
2025-06-27 05:17:13.499 E         - STATEMENT_TYPE PROCEDURE
2025-06-27 05:17:13.504 E         - SQL_TEXT
2025-06-27 05:17:13.508 E         - LINE_NUM
2025-06-27 05:17:13.514 E         - COLUMN_NUM
2025-06-27 05:17:13.521 E         - COUNTER 500
2025-06-27 05:17:13.528 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.535 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.541 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.547 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.555 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:13.565 E         - PROFILE_ID 1
2025-06-27 05:17:13.573 E         - STATEMENT_TYPE PROCEDURE
2025-06-27 05:17:13.580 E         - SQL_TEXT
2025-06-27 05:17:13.586 E         - LINE_NUM
2025-06-27 05:17:13.597 E         - COLUMN_NUM
2025-06-27 05:17:13.606 E         - COUNTER 1000
2025-06-27 05:17:13.616 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.627 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.638 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.647 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.656 E         - MSG --- [ 2: plg$prof_psql_stats_view ] ---
2025-06-27 05:17:13.663 E         - PROFILE_ID 1
2025-06-27 05:17:13.671 E         - STATEMENT_TYPE FUNCTION
2025-06-27 05:17:13.682 E         - SQL_TEXT
2025-06-27 05:17:13.690 E         - LINE_NUM
2025-06-27 05:17:13.698 E         - COLUMN_NUM
2025-06-27 05:17:13.709 E         - COUNTER 500
2025-06-27 05:17:13.717 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:13.725 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:13.732 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.739 E         - AVG_ELAPSED_TIME
2025-06-27 05:17:13.744 E         - Records affected: 8
2025-06-27 05:17:13.749 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:13.755 E         - PROFILE_ID 1
2025-06-27 05:17:13.760 E         - STATEMENT_ID
2025-06-27 05:17:13.765 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:13.770 E         - PACKAGE_NAME <null>
2025-06-27 05:17:13.777 E         - ROUTINE_NAME <null>
2025-06-27 05:17:13.786 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:13.793 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:13.799 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:13.806 E         - SQL_TEXT
2025-06-27 05:17:13.816 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-06-27 05:17:13.827 E         - CURSOR_ID 1
2025-06-27 05:17:13.836 E         - CURSOR_NAME <null>
2025-06-27 05:17:13.846 E         - CURSOR_LINE_NUM
2025-06-27 05:17:13.855 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:13.864 E         - RECORD_SOURCE_ID 2
2025-06-27 05:17:13.872 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-27 05:17:13.879 E         - ACCESS_PATH 84:1
2025-06-27 05:17:13.888 E         - -> Table "RDB$DATABASE" Full Scan
2025-06-27 05:17:13.898 E         - OPEN_COUNTER 0
2025-06-27 05:17:13.905 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:13.915 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:13.925 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.934 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:13.941 E         - FETCH_COUNTER
2025-06-27 05:17:13.947 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:13.954 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:13.964 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.973 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:13.980 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:13.989 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:14.000 E         - PROFILE_ID 1
2025-06-27 05:17:14.007 E         - STATEMENT_ID
2025-06-27 05:17:14.013 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:14.018 E         - PACKAGE_NAME <null>
2025-06-27 05:17:14.022 E         - ROUTINE_NAME <null>
2025-06-27 05:17:14.027 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:14.033 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:14.039 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:14.045 E         - SQL_TEXT
2025-06-27 05:17:14.051 E         - select rdb$profiler.start_session('profile session 1') from rdb$database
2025-06-27 05:17:14.059 E         - CURSOR_ID 1
2025-06-27 05:17:14.071 E         - CURSOR_NAME <null>
2025-06-27 05:17:14.082 E         - CURSOR_LINE_NUM
2025-06-27 05:17:14.089 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:14.096 E         - RECORD_SOURCE_ID 1
2025-06-27 05:17:14.102 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-27 05:17:14.108 E         - ACCESS_PATH 84:0
2025-06-27 05:17:14.115 E         - Select Expression
2025-06-27 05:17:14.122 E         - OPEN_COUNTER 0
2025-06-27 05:17:14.128 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:14.133 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:14.139 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.145 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:14.150 E         - FETCH_COUNTER
2025-06-27 05:17:14.155 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:14.161 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:14.166 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.173 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:14.180 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.186 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:14.191 E         - PROFILE_ID 1
2025-06-27 05:17:14.196 E         - STATEMENT_ID
2025-06-27 05:17:14.201 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:14.206 E         - PACKAGE_NAME <null>
2025-06-27 05:17:14.217 E         - ROUTINE_NAME <null>
2025-06-27 05:17:14.225 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:14.231 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:14.237 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:14.247 E         - SQL_TEXT
2025-06-27 05:17:14.257 E         - execute block
2025-06-27 05:17:14.265 E         - as
2025-06-27 05:17:14.271 E         - begin
2025-06-27 05:17:14.281 E         - execute procedure ins;
2025-06-27 05:17:14.289 E         - delete from tab;
2025-06-27 05:17:14.295 E         - end
2025-06-27 05:17:14.302 E         - CURSOR_ID 1
2025-06-27 05:17:14.309 E         - CURSOR_NAME <null>
2025-06-27 05:17:14.316 E         - CURSOR_LINE_NUM
2025-06-27 05:17:14.323 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:14.330 E         - RECORD_SOURCE_ID 2
2025-06-27 05:17:14.337 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-27 05:17:14.344 E         - ACCESS_PATH 84:3
2025-06-27 05:17:14.350 E         - -> Table "TAB" Full Scan
2025-06-27 05:17:14.357 E         - OPEN_COUNTER 1
2025-06-27 05:17:14.364 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:14.370 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:14.377 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.384 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:14.390 E         - FETCH_COUNTER
2025-06-27 05:17:14.395 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:14.402 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:14.408 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.414 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:14.420 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.425 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:14.435 E         - PROFILE_ID 1
2025-06-27 05:17:14.443 E         - STATEMENT_ID
2025-06-27 05:17:14.453 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:14.460 E         - PACKAGE_NAME <null>
2025-06-27 05:17:14.467 E         - ROUTINE_NAME <null>
2025-06-27 05:17:14.473 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:14.479 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:14.485 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:14.491 E         - SQL_TEXT
2025-06-27 05:17:14.498 E         - execute block
2025-06-27 05:17:14.508 E         - as
2025-06-27 05:17:14.516 E         - begin
2025-06-27 05:17:14.523 E         - execute procedure ins;
2025-06-27 05:17:14.531 E         - delete from tab;
2025-06-27 05:17:14.543 E         - end
2025-06-27 05:17:14.551 E         - CURSOR_ID 1
2025-06-27 05:17:14.560 E         - CURSOR_NAME <null>
2025-06-27 05:17:14.568 E         - CURSOR_LINE_NUM
2025-06-27 05:17:14.576 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:14.583 E         - RECORD_SOURCE_ID 1
2025-06-27 05:17:14.590 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-27 05:17:14.601 E         - ACCESS_PATH 84:2
2025-06-27 05:17:14.610 E         - Select Expression (line 5, column 9)
2025-06-27 05:17:14.617 E         - OPEN_COUNTER 1
2025-06-27 05:17:14.624 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:14.630 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:14.635 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.643 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:14.653 E         - FETCH_COUNTER
2025-06-27 05:17:14.664 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:14.674 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:14.683 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.694 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:14.702 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.711 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:14.722 E         - PROFILE_ID 2
2025-06-27 05:17:14.731 E         - STATEMENT_ID
2025-06-27 05:17:14.739 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:14.746 E         - PACKAGE_NAME <null>
2025-06-27 05:17:14.752 E         - ROUTINE_NAME <null>
2025-06-27 05:17:14.758 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:14.763 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:14.771 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:14.782 E         - SQL_TEXT
2025-06-27 05:17:14.790 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-06-27 05:17:14.798 E         - CURSOR_ID 1
2025-06-27 05:17:14.809 E         - CURSOR_NAME <null>
2025-06-27 05:17:14.819 E         - CURSOR_LINE_NUM
2025-06-27 05:17:14.826 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:14.834 E         - RECORD_SOURCE_ID 2
2025-06-27 05:17:14.845 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-27 05:17:14.854 E         - ACCESS_PATH 84:5
2025-06-27 05:17:14.860 E         - -> Table "RDB$DATABASE" Full Scan
2025-06-27 05:17:14.867 E         - OPEN_COUNTER 0
2025-06-27 05:17:14.873 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:14.878 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:14.887 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.893 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:14.898 E         - FETCH_COUNTER
2025-06-27 05:17:14.906 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:14.914 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:14.920 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.927 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:14.931 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:14.936 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:14.941 E         - PROFILE_ID 2
2025-06-27 05:17:14.945 E         - STATEMENT_ID
2025-06-27 05:17:14.950 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:14.954 E         - PACKAGE_NAME <null>
2025-06-27 05:17:14.959 E         - ROUTINE_NAME <null>
2025-06-27 05:17:14.964 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:14.970 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:14.977 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:14.983 E         - SQL_TEXT
2025-06-27 05:17:14.991 E         - select rdb$profiler.start_session('profile session 2') from rdb$database
2025-06-27 05:17:14.997 E         - CURSOR_ID 1
2025-06-27 05:17:15.004 E         - CURSOR_NAME <null>
2025-06-27 05:17:15.011 E         - CURSOR_LINE_NUM
2025-06-27 05:17:15.025 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:15.035 E         - RECORD_SOURCE_ID 1
2025-06-27 05:17:15.044 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-27 05:17:15.051 E         - ACCESS_PATH 84:4
2025-06-27 05:17:15.058 E         - Select Expression
2025-06-27 05:17:15.064 E         - OPEN_COUNTER 0
2025-06-27 05:17:15.070 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:15.076 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:15.082 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.088 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:15.095 E         - FETCH_COUNTER
2025-06-27 05:17:15.100 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:15.106 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:15.112 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.118 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:15.124 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.130 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:15.136 E         - PROFILE_ID 2
2025-06-27 05:17:15.142 E         - STATEMENT_ID
2025-06-27 05:17:15.152 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:15.161 E         - PACKAGE_NAME <null>
2025-06-27 05:17:15.167 E         - ROUTINE_NAME <null>
2025-06-27 05:17:15.173 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:15.182 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:15.188 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:15.195 E         - SQL_TEXT
2025-06-27 05:17:15.201 E         - select mod(id, 5),
2025-06-27 05:17:15.206 E         - sum(val)
2025-06-27 05:17:15.211 E         - from tab
2025-06-27 05:17:15.217 E         - where id <= 50
2025-06-27 05:17:15.223 E         - group by mod(id, 5)
2025-06-27 05:17:15.229 E         - order by sum(val)
2025-06-27 05:17:15.235 E         - CURSOR_ID 1
2025-06-27 05:17:15.242 E         - CURSOR_NAME <null>
2025-06-27 05:17:15.254 E         - CURSOR_LINE_NUM
2025-06-27 05:17:15.265 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:15.277 E         - RECORD_SOURCE_ID 2
2025-06-27 05:17:15.286 E         - PARENT_RECORD_SOURCE_ID 1
2025-06-27 05:17:15.293 E         - ACCESS_PATH 84:7
2025-06-27 05:17:15.300 E         - -> Sort (record length: 44, key length: 12)
2025-06-27 05:17:15.306 E         - OPEN_COUNTER 1
2025-06-27 05:17:15.312 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:15.318 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:15.324 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.332 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:15.338 E         - FETCH_COUNTER
2025-06-27 05:17:15.350 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:15.359 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:15.366 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.374 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:15.380 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.386 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:15.392 E         - PROFILE_ID 2
2025-06-27 05:17:15.401 E         - STATEMENT_ID
2025-06-27 05:17:15.413 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:15.424 E         - PACKAGE_NAME <null>
2025-06-27 05:17:15.436 E         - ROUTINE_NAME <null>
2025-06-27 05:17:15.441 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:15.446 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:15.451 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:15.455 E         - SQL_TEXT
2025-06-27 05:17:15.460 E         - select mod(id, 5),
2025-06-27 05:17:15.465 E         - sum(val)
2025-06-27 05:17:15.470 E         - from tab
2025-06-27 05:17:15.476 E         - where id <= 50
2025-06-27 05:17:15.481 E         - group by mod(id, 5)
2025-06-27 05:17:15.485 E         - order by sum(val)
2025-06-27 05:17:15.490 E         - CURSOR_ID 1
2025-06-27 05:17:15.495 E         - CURSOR_NAME <null>
2025-06-27 05:17:15.500 E         - CURSOR_LINE_NUM
2025-06-27 05:17:15.505 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:15.511 E         - RECORD_SOURCE_ID 3
2025-06-27 05:17:15.516 E         - PARENT_RECORD_SOURCE_ID 2
2025-06-27 05:17:15.522 E         - ACCESS_PATH 84:8
2025-06-27 05:17:15.532 E         - -> Aggregate
2025-06-27 05:17:15.540 E         - OPEN_COUNTER 1
2025-06-27 05:17:15.547 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:15.553 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:15.559 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.565 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:15.571 E         - FETCH_COUNTER
2025-06-27 05:17:15.580 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:15.590 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:15.597 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.604 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:15.610 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.615 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:15.621 E         - PROFILE_ID 2
2025-06-27 05:17:15.627 E         - STATEMENT_ID
2025-06-27 05:17:15.634 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:15.642 E         - PACKAGE_NAME <null>
2025-06-27 05:17:15.651 E         - ROUTINE_NAME <null>
2025-06-27 05:17:15.657 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:15.664 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:15.671 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:15.679 E         - SQL_TEXT
2025-06-27 05:17:15.689 E         - select mod(id, 5),
2025-06-27 05:17:15.698 E         - sum(val)
2025-06-27 05:17:15.704 E         - from tab
2025-06-27 05:17:15.710 E         - where id <= 50
2025-06-27 05:17:15.715 E         - group by mod(id, 5)
2025-06-27 05:17:15.721 E         - order by sum(val)
2025-06-27 05:17:15.726 E         - CURSOR_ID 1
2025-06-27 05:17:15.730 E         - CURSOR_NAME <null>
2025-06-27 05:17:15.735 E         - CURSOR_LINE_NUM
2025-06-27 05:17:15.743 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:15.752 E         - RECORD_SOURCE_ID 4
2025-06-27 05:17:15.760 E         - PARENT_RECORD_SOURCE_ID 3
2025-06-27 05:17:15.768 E         - ACCESS_PATH 84:9
2025-06-27 05:17:15.774 E         - -> Sort (record length: 44, key length: 8)
2025-06-27 05:17:15.782 E         - OPEN_COUNTER 1
2025-06-27 05:17:15.793 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:15.802 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:15.810 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.817 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:15.823 E         - FETCH_COUNTER
2025-06-27 05:17:15.829 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:15.834 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:15.842 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.850 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:15.857 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:15.863 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:15.869 E         - PROFILE_ID 2
2025-06-27 05:17:15.875 E         - STATEMENT_ID
2025-06-27 05:17:15.886 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:15.895 E         - PACKAGE_NAME <null>
2025-06-27 05:17:15.904 E         - ROUTINE_NAME <null>
2025-06-27 05:17:15.912 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:15.917 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:15.923 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:15.929 E         - SQL_TEXT
2025-06-27 05:17:15.938 E         - select mod(id, 5),
2025-06-27 05:17:15.949 E         - sum(val)
2025-06-27 05:17:15.960 E         - from tab
2025-06-27 05:17:15.968 E         - where id <= 50
2025-06-27 05:17:15.975 E         - group by mod(id, 5)
2025-06-27 05:17:15.981 E         - order by sum(val)
2025-06-27 05:17:15.986 E         - CURSOR_ID 1
2025-06-27 05:17:15.991 E         - CURSOR_NAME <null>
2025-06-27 05:17:15.996 E         - CURSOR_LINE_NUM
2025-06-27 05:17:16.000 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:16.005 E         - RECORD_SOURCE_ID 5
2025-06-27 05:17:16.011 E         - PARENT_RECORD_SOURCE_ID 4
2025-06-27 05:17:16.017 E         - ACCESS_PATH 84:a
2025-06-27 05:17:16.022 E         - -> Filter
2025-06-27 05:17:16.030 E         - OPEN_COUNTER 1
2025-06-27 05:17:16.037 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:16.044 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:16.051 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.057 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:16.063 E         - FETCH_COUNTER
2025-06-27 05:17:16.071 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:16.082 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:16.090 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.097 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:16.102 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.107 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:16.112 E         - PROFILE_ID 2
2025-06-27 05:17:16.117 E         - STATEMENT_ID
2025-06-27 05:17:16.122 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:16.127 E         - PACKAGE_NAME <null>
2025-06-27 05:17:16.133 E         - ROUTINE_NAME <null>
2025-06-27 05:17:16.138 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:16.148 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:16.158 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:16.166 E         - SQL_TEXT
2025-06-27 05:17:16.173 E         - select mod(id, 5),
2025-06-27 05:17:16.182 E         - sum(val)
2025-06-27 05:17:16.187 E         - from tab
2025-06-27 05:17:16.193 E         - where id <= 50
2025-06-27 05:17:16.199 E         - group by mod(id, 5)
2025-06-27 05:17:16.206 E         - order by sum(val)
2025-06-27 05:17:16.217 E         - CURSOR_ID 1
2025-06-27 05:17:16.226 E         - CURSOR_NAME <null>
2025-06-27 05:17:16.234 E         - CURSOR_LINE_NUM
2025-06-27 05:17:16.239 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:16.245 E         - RECORD_SOURCE_ID 6
2025-06-27 05:17:16.253 E         - PARENT_RECORD_SOURCE_ID 5
2025-06-27 05:17:16.260 E         - ACCESS_PATH 84:b
2025-06-27 05:17:16.266 E         - -> Table "TAB" Full Scan
2025-06-27 05:17:16.273 E         - OPEN_COUNTER 1
2025-06-27 05:17:16.277 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:16.282 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:16.287 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.293 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:16.299 E         - FETCH_COUNTER
2025-06-27 05:17:16.304 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:16.309 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:16.314 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.319 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:16.324 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.330 E         - MSG --- [ 3: plg$prof_record_source_stats_view ] ---
2025-06-27 05:17:16.336 E         - PROFILE_ID 2
2025-06-27 05:17:16.342 E         - STATEMENT_ID
2025-06-27 05:17:16.350 E         - STATEMENT_TYPE BLOCK
2025-06-27 05:17:16.359 E         - PACKAGE_NAME <null>
2025-06-27 05:17:16.369 E         - ROUTINE_NAME <null>
2025-06-27 05:17:16.378 E         - PARENT_STATEMENT_ID
2025-06-27 05:17:16.385 E         - PARENT_STATEMENT_TYPE <null>
2025-06-27 05:17:16.391 E         - PARENT_ROUTINE_NAME <null>
2025-06-27 05:17:16.397 E         - SQL_TEXT
2025-06-27 05:17:16.403 E         - select mod(id, 5),
2025-06-27 05:17:16.409 E         - sum(val)
2025-06-27 05:17:16.416 E         - from tab
2025-06-27 05:17:16.423 E         - where id <= 50
2025-06-27 05:17:16.429 E         - group by mod(id, 5)
2025-06-27 05:17:16.436 E         - order by sum(val)
2025-06-27 05:17:16.443 E         - CURSOR_ID 1
2025-06-27 05:17:16.449 E         - CURSOR_NAME <null>
2025-06-27 05:17:16.456 E         - CURSOR_LINE_NUM
2025-06-27 05:17:16.466 E         - CURSOR_COLUMN_NUM
2025-06-27 05:17:16.477 E         - RECORD_SOURCE_ID 1
2025-06-27 05:17:16.489 E         - PARENT_RECORD_SOURCE_ID <null>
2025-06-27 05:17:16.499 E         - ACCESS_PATH 84:6
2025-06-27 05:17:16.512 E         - Select Expression
2025-06-27 05:17:16.523 E         - OPEN_COUNTER 1
2025-06-27 05:17:16.533 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:16.545 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:16.554 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.561 E         - OPEN_AVG_ELAPSED_TIME
2025-06-27 05:17:16.568 E         - FETCH_COUNTER
2025-06-27 05:17:16.573 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:16.578 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:16.584 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.593 E         - FETCH_AVG_ELAPSED_TIME
2025-06-27 05:17:16.606 E         - OPEN_FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.617 E         - Records affected: 12
2025-06-27 05:17:16.625 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-27 05:17:16.634 E         - PROFILE_ID 1
2025-06-27 05:17:16.640 E         - REQUEST_ID
2025-06-27 05:17:16.647 E         - STATEMENT_ID
2025-06-27 05:17:16.655 E         - CALLER_REQUEST_ID
2025-06-27 05:17:16.662 E         - START_TIMESTAMP
2025-06-27 05:17:16.667 E         - FINISH_TIMESTAMP
2025-06-27 05:17:16.672 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.676 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-27 05:17:16.681 E         - PROFILE_ID 1
2025-06-27 05:17:16.686 E         - REQUEST_ID
2025-06-27 05:17:16.691 E         - STATEMENT_ID
2025-06-27 05:17:16.696 E         - CALLER_REQUEST_ID
2025-06-27 05:17:16.701 E         - START_TIMESTAMP
2025-06-27 05:17:16.707 E         - FINISH_TIMESTAMP
2025-06-27 05:17:16.712 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.721 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-27 05:17:16.728 E         - PROFILE_ID 1
2025-06-27 05:17:16.739 E         - REQUEST_ID
2025-06-27 05:17:16.751 E         - STATEMENT_ID
2025-06-27 05:17:16.763 E         - CALLER_REQUEST_ID
2025-06-27 05:17:16.771 E         - START_TIMESTAMP
2025-06-27 05:17:16.779 E         - FINISH_TIMESTAMP
2025-06-27 05:17:16.787 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.800 E         - MSG --- [ 4: plg$prof_requests ] ---
2025-06-27 05:17:16.811 E         - PROFILE_ID 1
2025-06-27 05:17:16.822 E         - REQUEST_ID
2025-06-27 05:17:16.833 E         - STATEMENT_ID
2025-06-27 05:17:16.843 E         - CALLER_REQUEST_ID
2025-06-27 05:17:16.852 E         - START_TIMESTAMP
2025-06-27 05:17:16.865 E         - FINISH_TIMESTAMP
2025-06-27 05:17:16.875 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.884 E         - Records affected: 4
2025-06-27 05:17:16.892 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:16.899 E         - PROFILE_ID 1
2025-06-27 05:17:16.905 E         - REQUEST_ID
2025-06-27 05:17:16.911 E         - LINE_NUM
2025-06-27 05:17:16.920 E         - COLUMN_NUM
2025-06-27 05:17:16.926 E         - STATEMENT_ID
2025-06-27 05:17:16.932 E         - COUNTER 1
2025-06-27 05:17:16.937 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:16.943 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:16.948 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:16.954 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:16.960 E         - PROFILE_ID 1
2025-06-27 05:17:16.965 E         - REQUEST_ID
2025-06-27 05:17:16.975 E         - LINE_NUM
2025-06-27 05:17:16.983 E         - COLUMN_NUM
2025-06-27 05:17:16.989 E         - STATEMENT_ID
2025-06-27 05:17:16.994 E         - COUNTER 1
2025-06-27 05:17:16.999 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:17.005 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:17.010 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.016 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:17.022 E         - PROFILE_ID 1
2025-06-27 05:17:17.027 E         - REQUEST_ID
2025-06-27 05:17:17.035 E         - LINE_NUM
2025-06-27 05:17:17.045 E         - COLUMN_NUM
2025-06-27 05:17:17.053 E         - STATEMENT_ID
2025-06-27 05:17:17.060 E         - COUNTER 1
2025-06-27 05:17:17.066 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:17.075 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:17.086 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.096 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:17.105 E         - PROFILE_ID 1
2025-06-27 05:17:17.112 E         - REQUEST_ID
2025-06-27 05:17:17.119 E         - LINE_NUM
2025-06-27 05:17:17.126 E         - COLUMN_NUM
2025-06-27 05:17:17.131 E         - STATEMENT_ID
2025-06-27 05:17:17.137 E         - COUNTER 1001
2025-06-27 05:17:17.150 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:17.161 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:17.173 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.185 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:17.194 E         - PROFILE_ID 1
2025-06-27 05:17:17.206 E         - REQUEST_ID
2025-06-27 05:17:17.216 E         - LINE_NUM
2025-06-27 05:17:17.224 E         - COLUMN_NUM
2025-06-27 05:17:17.235 E         - STATEMENT_ID
2025-06-27 05:17:17.242 E         - COUNTER 1000
2025-06-27 05:17:17.248 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:17.255 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:17.263 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.274 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:17.288 E         - PROFILE_ID 1
2025-06-27 05:17:17.299 E         - REQUEST_ID
2025-06-27 05:17:17.306 E         - LINE_NUM
2025-06-27 05:17:17.312 E         - COLUMN_NUM
2025-06-27 05:17:17.320 E         - STATEMENT_ID
2025-06-27 05:17:17.329 E         - COUNTER 500
2025-06-27 05:17:17.336 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:17.341 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:17.352 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.363 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:17.373 E         - PROFILE_ID 1
2025-06-27 05:17:17.385 E         - REQUEST_ID
2025-06-27 05:17:17.393 E         - LINE_NUM
2025-06-27 05:17:17.401 E         - COLUMN_NUM
2025-06-27 05:17:17.408 E         - STATEMENT_ID
2025-06-27 05:17:17.415 E         - COUNTER 1000
2025-06-27 05:17:17.421 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:17.427 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:17.433 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.439 E         - MSG --- [ 5: plg$prof_psql_stats join plg$prof_sessions ] ---
2025-06-27 05:17:17.445 E         - PROFILE_ID 1
2025-06-27 05:17:17.451 E         - REQUEST_ID
2025-06-27 05:17:17.457 E         - LINE_NUM
2025-06-27 05:17:17.463 E         - COLUMN_NUM
2025-06-27 05:17:17.471 E         - STATEMENT_ID
2025-06-27 05:17:17.480 E         - COUNTER 500
2025-06-27 05:17:17.490 E         - MIN_ELAPSED_TIME
2025-06-27 05:17:17.499 E         - MAX_ELAPSED_TIME
2025-06-27 05:17:17.507 E         - TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.514 E         - Records affected: 8
2025-06-27 05:17:17.525 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:17.535 E         - PROFILE_ID 2
2025-06-27 05:17:17.543 E         - REQUEST_ID
2025-06-27 05:17:17.549 E         - CURSOR_ID 1
2025-06-27 05:17:17.556 E         - RECORD_SOURCE_ID 1
2025-06-27 05:17:17.562 E         - STATEMENT_ID
2025-06-27 05:17:17.570 E         - OPEN_COUNTER 0
2025-06-27 05:17:17.578 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:17.587 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:17.598 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.606 E         - FETCH_COUNTER
2025-06-27 05:17:17.612 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:17.618 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:17.625 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.631 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:17.638 E         - PROFILE_ID 2
2025-06-27 05:17:17.644 E         - REQUEST_ID
2025-06-27 05:17:17.651 E         - CURSOR_ID 1
2025-06-27 05:17:17.658 E         - RECORD_SOURCE_ID 2
2025-06-27 05:17:17.666 E         - STATEMENT_ID
2025-06-27 05:17:17.673 E         - OPEN_COUNTER 0
2025-06-27 05:17:17.681 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:17.686 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:17.692 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.702 E         - FETCH_COUNTER
2025-06-27 05:17:17.709 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:17.715 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:17.722 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.730 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:17.737 E         - PROFILE_ID 2
2025-06-27 05:17:17.743 E         - REQUEST_ID
2025-06-27 05:17:17.750 E         - CURSOR_ID 1
2025-06-27 05:17:17.757 E         - RECORD_SOURCE_ID 1
2025-06-27 05:17:17.763 E         - STATEMENT_ID
2025-06-27 05:17:17.769 E         - OPEN_COUNTER 1
2025-06-27 05:17:17.779 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:17.787 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:17.794 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.805 E         - FETCH_COUNTER
2025-06-27 05:17:17.816 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:17.825 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:17.832 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.839 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:17.848 E         - PROFILE_ID 2
2025-06-27 05:17:17.859 E         - REQUEST_ID
2025-06-27 05:17:17.869 E         - CURSOR_ID 1
2025-06-27 05:17:17.878 E         - RECORD_SOURCE_ID 2
2025-06-27 05:17:17.883 E         - STATEMENT_ID
2025-06-27 05:17:17.890 E         - OPEN_COUNTER 1
2025-06-27 05:17:17.897 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:17.903 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:17.910 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.917 E         - FETCH_COUNTER
2025-06-27 05:17:17.924 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:17.931 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:17.939 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:17.947 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:17.957 E         - PROFILE_ID 2
2025-06-27 05:17:17.965 E         - REQUEST_ID
2025-06-27 05:17:17.971 E         - CURSOR_ID 1
2025-06-27 05:17:17.977 E         - RECORD_SOURCE_ID 3
2025-06-27 05:17:17.983 E         - STATEMENT_ID
2025-06-27 05:17:17.988 E         - OPEN_COUNTER 1
2025-06-27 05:17:17.994 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:18.003 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:18.012 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.023 E         - FETCH_COUNTER
2025-06-27 05:17:18.032 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:18.039 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:18.045 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.051 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:18.057 E         - PROFILE_ID 2
2025-06-27 05:17:18.062 E         - REQUEST_ID
2025-06-27 05:17:18.068 E         - CURSOR_ID 1
2025-06-27 05:17:18.074 E         - RECORD_SOURCE_ID 4
2025-06-27 05:17:18.081 E         - STATEMENT_ID
2025-06-27 05:17:18.087 E         - OPEN_COUNTER 1
2025-06-27 05:17:18.094 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:18.105 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:18.113 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.120 E         - FETCH_COUNTER
2025-06-27 05:17:18.126 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:18.131 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:18.137 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.143 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:18.150 E         - PROFILE_ID 2
2025-06-27 05:17:18.158 E         - REQUEST_ID
2025-06-27 05:17:18.166 E         - CURSOR_ID 1
2025-06-27 05:17:18.172 E         - RECORD_SOURCE_ID 5
2025-06-27 05:17:18.179 E         - STATEMENT_ID
2025-06-27 05:17:18.187 E         - OPEN_COUNTER 1
2025-06-27 05:17:18.196 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:18.203 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:18.209 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.215 E         - FETCH_COUNTER
2025-06-27 05:17:18.220 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:18.225 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:18.231 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.237 E         - MSG --- [ 6: plg$prof_record_source_stats ] ---
2025-06-27 05:17:18.242 E         - PROFILE_ID 2
2025-06-27 05:17:18.248 E         - REQUEST_ID
2025-06-27 05:17:18.254 E         - CURSOR_ID 1
2025-06-27 05:17:18.264 E         - RECORD_SOURCE_ID 6
2025-06-27 05:17:18.273 E         - STATEMENT_ID
2025-06-27 05:17:18.282 E         - OPEN_COUNTER 1
2025-06-27 05:17:18.290 E         - OPEN_MIN_ELAPSED_TIME
2025-06-27 05:17:18.298 E         - OPEN_MAX_ELAPSED_TIME
2025-06-27 05:17:18.309 E         - OPEN_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.318 E         - FETCH_COUNTER
2025-06-27 05:17:18.328 E         - FETCH_MIN_ELAPSED_TIME
2025-06-27 05:17:18.336 E         - FETCH_MAX_ELAPSED_TIME
2025-06-27 05:17:18.345 E         - FETCH_TOTAL_ELAPSED_TIME
2025-06-27 05:17:18.352 E         - Records affected: 8
2025-06-27 05:17:18.359
2025-06-27 05:17:18.365 tests/bugs/gh_7086_test.py:1795: AssertionError
2025-06-27 05:17:18.371 ---------------------------- Captured stdout setup -----------------------------
2025-06-27 05:17:18.377 Creating db: localhost:/var/tmp/qa_2024/test_11491/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.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
2 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
3 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
4 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
5 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
6 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
7 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
8 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
9 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
10 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
11 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
12 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
13 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
14 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
15 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
16 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
17 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
18 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
19 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
20 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
21 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
22 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
23 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
24 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
25 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
26 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
27 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
28 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
29 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
30 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
31 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
32 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
33 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
34 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
35 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
36 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
37 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
38 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
39 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
40 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
41 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
42 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
43 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
44 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
45 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
46 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
47 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
48 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
49 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
50 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
51 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
52 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
53 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
54 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
55 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
56 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
57 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
58 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
59 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
60 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
61 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
62 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
63 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
64 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
65 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
66 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
67 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
68 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
69 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
70 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
71 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
72 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
73 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
74 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
75 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
76 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
77 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
78 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
79 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
80 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
81 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
82 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
83 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
84 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
85 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
86 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
87 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
88 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
89 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
90 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
91 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
92 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
93 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
94 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
95 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
96 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
97 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
98 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
99 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
100 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
101 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
102 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
103 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
104 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
105 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
106 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
107 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
108 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
109 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
110 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
111 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
112 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
113 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
114 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
115 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
116 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
117 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
118 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
119 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
120 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
121 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
122 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
123 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
124 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
125 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
126 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
127 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
128 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
129 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
130 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
131 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
132 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
133 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
134 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
135 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
136 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
137 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
138 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
139 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
140 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
141 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
142 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
143 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
144 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
145 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
146 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
147 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
148 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
149 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
150 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
151 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
152 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
153 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
154 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
155 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
156 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
157 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
158 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
159 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
160 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
161 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
162 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
163 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
164 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
165 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
166 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
167 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
168 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
169 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
170 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
171 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
172 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
173 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
174 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
175 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
176 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
177 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
178 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
179 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
180 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
181 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
182 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
183 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
184 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
185 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
186 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
187 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
188 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):