[stub, to be replaced]

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

    AssertionError: assert
      - Problem(s) detected, check run_errors_map:
      - repl_tx_not_found_err :
      - UNEXPECTED outcome: pattern 'Error:\s+Transaction\s+\d+\s+(is\s+)?not\s+found' must not occur in log but was ENCOUNTERED there for 21 seconds.
      - replication log diff:
      -    0 ---
      -    1 +++
      -    2 @@ -4751,3 +4751,82 @@
      -    3  IBASE-CLIENT (replica) Thu May  1 07:45:20 2025
      -    4  	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -    5  	VERBOSE: No new segments found, suspending
      -    6 +
      -    7 +IBASE-CLIENT (replica) Thu May  1 07:45:23 2025
      -    8 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -    9 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
      -   10 +
      -   11 +IBASE-CLIENT (replica) Thu May  1 07:45:23 2025
      -   12 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   13 +	VERBOSE: No new segments found, suspending
      -   14 +
      -   15 +IBASE-CLIENT (replica) Thu May  1 07:45:26 2025
      -   16 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   17 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
      -   18 +
      -   19 +IBASE-CLIENT (replica) Thu May  1 07:45:26 2025
      -   20 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   21 +	VERBOSE: No new segments found, suspending
      -   22 +
      -   23 +IBASE-CLIENT (replica) Thu May  1 07:45:29 2025
      -   24 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   25 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
      -   26 +
      -   27 +IBASE-CLIENT (replica) Thu May  1 07:45:29 2025
      -   28 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   29 +	VERBOSE: No new segments found, suspending
      -   30 +
      -   31 +IBASE-CLIENT (replica) Thu May  1 07:45:32 2025
      -   32 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   33 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
      -   34 +
      -   35 +IBASE-CLIENT (replica) Thu May  1 07:45:32 2025
      -   36 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   37 +	VERBOSE: No new segments found, suspending
      -   38 +
      -   39 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
      -   40 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   41 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
      -   42 +
      -   43 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
      -   44 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   45 +	ERROR: connection shutdown
      -   46 +	Database is shutdown.
      -   47 +	At segment 6, offset 48
      -   48 +
      -   49 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
      -   50 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   51 +	VERBOSE: Disconnecting and suspending
      -   52 +
      -   53 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   54 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   55 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
      -   56 +
      -   57 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   58 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   59 +	WARNING: Database sequence has been changed from 0 to 5, preparing for replication reset
      -   60 +
      -   61 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   62 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   63 +	VERBOSE: Segment 4 (15729380 bytes) is scanned in 0.003s, preserving (OAT: 36 in segment 4)
      -   64 +
      -   65 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   66 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   67 +	VERBOSE: Segment 5 (646 bytes) is scanned in 0.008s, preserving (OAT: 36 in segment 4)
      -   68 +
      -   69 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   70 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   71 +	WARNING: Resetting replication to continue from segment 6 (new OAT: 36 in segment 4)
      -   72 +
      -   73 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   74 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   75 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
      -   76 +
      -   77 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   78 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   79 +	ERROR: Transaction 36 is not found
      -   80 +	At segment 6, offset 48
      -   81 +
      -   82 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
      -   83 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
      -   84 +	VERBOSE: Disconnecting and suspending
      - ----------------------------------------

    LOG DETAILS:

    2025-05-01 07:54:16.926
    2025-05-01 07:54:16.926 act_db_main = <firebird.qa.plugin.Action object at [hex]>
    2025-05-01 07:54:16.926 act_db_repl = <firebird.qa.plugin.Action object at [hex]>
    2025-05-01 07:54:16.926 db_nbk0 = WindowsPath('H:/QA/temp/qa2024.tmp/fbqa/test_12245/gh_8324_tmp.nbk0')
    2025-05-01 07:54:16.926 capsys = <_pytest.capture.CaptureFixture object at [hex]>
    2025-05-01 07:54:16.926
    2025-05-01 07:54:16.927     @pytest.mark.replication
    2025-05-01 07:54:16.927     @pytest.mark.version('>=4.0.6')
    2025-05-01 07:54:16.927     def test_1(act_db_main: Action,  act_db_repl: Action, db_nbk0: Path, capsys):
    2025-05-01 07:54:16.927
    2025-05-01 07:54:16.927         FLD_WIDTH = 500
    2025-05-01 07:54:16.927         ADD_ROWS_INIT = 100
    2025-05-01 07:54:16.927         ADD_ROWS_IN_OAT = 30000
    2025-05-01 07:54:16.927         TEST2_VALUE = -2147483648
    2025-05-01 07:54:16.927
    2025-05-01 07:54:16.927         # Map for storing mnemonas and details for every FAILED step:
    2025-05-01 07:54:16.927         run_errors_map = {}
    2025-05-01 07:54:16.927
    2025-05-01 07:54:16.927         # Obtain full path + filename for DB_MAIN and DB_REPL aliases.
    2025-05-01 07:54:16.927         # NOTE: we must NOT use 'a.db.db_path' for ALIASED databases!
    2025-05-01 07:54:16.927         # It will return '.' rather than full path+filename.
    2025-05-01 07:54:16.927         # Use only con.info.name for that!
    2025-05-01 07:54:16.927         #
    2025-05-01 07:54:16.927         db_info = {}
    2025-05-01 07:54:16.927         for a in (act_db_main, act_db_repl):
    2025-05-01 07:54:16.927             with a.db.connect() as con:
    2025-05-01 07:54:16.927                 db_info[a,  'db_full_path'] = con.info.name
    2025-05-01 07:54:16.928
    2025-05-01 07:54:16.928         sql_init = f"""
    2025-05-01 07:54:16.928             set bail on;
    2025-05-01 07:54:16.928             set wng off;
    2025-05-01 07:54:16.928             recreate table test (
    2025-05-01 07:54:16.928                 id int generated by default as identity constraint test_pk primary key
    2025-05-01 07:54:16.928                 ,dts timestamp default 'now'
    2025-05-01 07:54:16.928                 ,trn bigint default current_transaction
    2025-05-01 07:54:16.928                 ,s varchar({FLD_WIDTH}) unique using index test_f01_unq
    2025-05-01 07:54:16.928             );
    2025-05-01 07:54:16.928
    2025-05-01 07:54:16.928             recreate table test2 (
    2025-05-01 07:54:16.928                 id int generated by default as identity constraint test2_pk primary key
    2025-05-01 07:54:16.928                 ,dts timestamp default 'now'
    2025-05-01 07:54:16.928                 ,trn bigint default current_transaction
    2025-05-01 07:54:16.928                 ,s varchar({FLD_WIDTH}) unique using index test2_f01_unq
    2025-05-01 07:54:16.928             );
    2025-05-01 07:54:16.928             commit;
    2025-05-01 07:54:16.928
    2025-05-01 07:54:16.928             insert into test(s) select lpad( '', {FLD_WIDTH}, uuid_to_char(gen_uuid()) ) from rdb$types rows {ADD_ROWS_INIT};
    2025-05-01 07:54:16.928             commit;
    2025-05-01 07:54:16.929
    2025-05-01 07:54:16.929             recreate table t_completed(id int primary key);
    2025-05-01 07:54:16.929             commit;
    2025-05-01 07:54:16.929         """
    2025-05-01 07:54:16.929         act_db_main.isql(switches=['-q'], input = sql_init, combine_output = True)
    2025-05-01 07:54:16.929         run_errors_map['out_prep_ddl'] = act_db_main.clean_stdout
    2025-05-01 07:54:16.929         act_db_main.reset()
    2025-05-01 07:54:16.929
    2025-05-01 07:54:16.929         if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.929             # Some problem raised during init_sql execution
    2025-05-01 07:54:16.929             pass
    2025-05-01 07:54:16.929         else:
    2025-05-01 07:54:16.929             # Query to be used for check that all DB objects present in replica (after last DML statement completed on master DB):
    2025-05-01 07:54:16.929             ddl_ready_query = "select 1 from rdb$relations where rdb$relation_name = upper('t_completed')"
    2025-05-01 07:54:16.929             #####################################################################
    2025-05-01 07:54:16.929             ###  WAIT UNTIL REPLICA GET SEGMENT(S) WITH INITIAL DDL AND DATA  ###
    2025-05-01 07:54:16.929             #####################################################################
    2025-05-01 07:54:16.929             watch_replica( act_db_repl, MAX_TIME_FOR_WAIT_DATA_IN_REPLICA, ddl_ready_query)
    2025-05-01 07:54:16.929
    2025-05-01 07:54:16.929             # Must be EMPTY:
    2025-05-01 07:54:16.930             run_errors_map['out_repl_ddl'] = capsys.readouterr().out
    2025-05-01 07:54:16.930
    2025-05-01 07:54:16.930         if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.930             # Some problem raised with delivering DDL changes to replica
    2025-05-01 07:54:16.930             pass
    2025-05-01 07:54:16.930         else:
    2025-05-01 07:54:16.930
    2025-05-01 07:54:16.930             with act_db_main.db.connect() as con:
    2025-05-01 07:54:16.930                 preserved_segment_no = -1
    2025-05-01 07:54:16.930
    2025-05-01 07:54:16.930                 tp_oat = tpb(isolation = Isolation.SNAPSHOT, lock_timeout = 0)
    2025-05-01 07:54:16.930                 tx_oat = con.transaction_manager(tp_oat)
    2025-05-01 07:54:16.930                 cur_oat = tx_oat.cursor()
    2025-05-01 07:54:16.930
    2025-05-01 07:54:16.930                 tx_oat.begin()
    2025-05-01 07:54:16.930                 replold_lines = get_repl_log(act_db_main)
    2025-05-01 07:54:16.930
    2025-05-01 07:54:16.930                 try:
    2025-05-01 07:54:16.930                     cur_oat.execute(f"insert /* trace_tag OAT */ into test(s) select lpad('', {FLD_WIDTH}, uuid_to_char(gen_uuid())) from rdb$types,rdb$types rows {ADD_ROWS_IN_OAT}")
    2025-05-01 07:54:16.930                     cur_oat.execute('select max(id) from test')
    2025-05-01 07:54:16.930                     cur_oat.fetchone()
    2025-05-01 07:54:16.931                 except DatabaseError as e:
    2025-05-01 07:54:16.931                     run_errors_map['main_oat_init_err'] = e.__str__()
    2025-05-01 07:54:16.931
    2025-05-01 07:54:16.931                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.931                     # Some problem was in just executed OAT-statement
    2025-05-01 07:54:16.931                     pass
    2025-05-01 07:54:16.931                 else:
    2025-05-01 07:54:16.931                     ##############################################################
    2025-05-01 07:54:16.931                     ###  CHECK REPL.LOG: WAITING FOR "PRESERVING OAT" MESSAGE  ###
    2025-05-01 07:54:16.931                     ##############################################################
    2025-05-01 07:54:16.931                     # VERBOSE: Segment 2 (11534562 bytes) is replicated in 0.934s, preserving (OAT: 10 in segment 2)
    2025-05-01 07:54:16.931                     pattern_to_check = re.compile( r'preserving \(oat:\s+\d+\s+in\s+segment\s+\d+', re.IGNORECASE )
    2025-05-01 07:54:16.931                     run_errors_map['repl_preserve_oat_err'] = watch_repl_log_pattern( act_db_main, pattern_to_check, replold_lines, MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG)
    2025-05-01 07:54:16.931
    2025-05-01 07:54:16.931                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.931                     # Timeout expired: message "Segment ... preserving (OAT: ... in segment ...)" did not appeared
    2025-05-01 07:54:16.931                     # in replication log for <MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG> seconds.
    2025-05-01 07:54:16.931                     pass
    2025-05-01 07:54:16.931                 else:
    2025-05-01 07:54:16.931
    2025-05-01 07:54:16.932                     ###############################################
    2025-05-01 07:54:16.932                     ###  MASTER: RUN DML BEFORE 'NBACKUP -B 0'  ###
    2025-05-01 07:54:16.932                     ###############################################
    2025-05-01 07:54:16.932                     # tp_wrk = tpb(isolation = Isolation.READ_COMMITTED_READ_CONSISTENCY, lock_timeout = 3) # ?!?! check trace  !!!
    2025-05-01 07:54:16.932                     tp_bef = tpb(isolation = Isolation.READ_COMMITTED, lock_timeout = 3)
    2025-05-01 07:54:16.932                     tx_bef = con.transaction_manager(tp_bef)
    2025-05-01 07:54:16.932                     cur_bef = tx_bef.cursor()
    2025-05-01 07:54:16.932                     try:
    2025-05-01 07:54:16.932                         tx_bef.begin()
    2025-05-01 07:54:16.932                         cur_bef.execute(f"insert /* trace_tag before creating nbk-0 */ into test2(id) values(?) returning rdb$get_context('SYSTEM', 'REPLICATION_SEQUENCE')", (TEST2_VALUE,))
    2025-05-01 07:54:16.932
    2025-05-01 07:54:16.932                         # If returned value of rdb$get_context('SYSTEM', 'REPLICATION_SEQUENCE') is <N> then
    2025-05-01 07:54:16.932                         # message in replication log contains this number PLUS 1, e.g. (for REPLICATION_SEQUENCE = 1):
    2025-05-01 07:54:16.932                         # "Segment 2 (11534562 bytes) is replicated in 0.934s, preserving (OAT: 10 in segment 2)"
    2025-05-01 07:54:16.932                         # We store this result in order to check further content of replication log that this
    2025-05-01 07:54:16.932                         # segment was eventuially deleted (this will mean SUCCESSFUL finish of test):
    2025-05-01 07:54:16.932                         #
    2025-05-01 07:54:16.932                         preserved_segment_no = int(cur_bef.fetchone()[0]) + 1
    2025-05-01 07:54:16.932                         tx_bef.commit()
    2025-05-01 07:54:16.932                     except DatabaseError as e:
    2025-05-01 07:54:16.933                         run_errors_map['main_dml_afte_nbk0_err'] = e.__str__()
    2025-05-01 07:54:16.933
    2025-05-01 07:54:16.933                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.933                     # Some problem was in just executed statement
    2025-05-01 07:54:16.933                     pass
    2025-05-01 07:54:16.933                 else:
    2025-05-01 07:54:16.933                     ##############################################
    2025-05-01 07:54:16.933                     ###  WAIT UNTIL REPLICA DB BECOMES ACTUAL  ###
    2025-05-01 07:54:16.933                     ##############################################
    2025-05-01 07:54:16.933                     # ( a: Action, max_allowed_time_for_wait, ddl_ready_query = '', isql_check_script = '', replica_expected_out = ''):
    2025-05-01 07:54:16.933                     chk_bef_sql = f'set heading off;select count(*) from test2 where id = {TEST2_VALUE};'
    2025-05-01 07:54:16.933                     watch_replica( act_db_repl, MAX_TIME_FOR_WAIT_DATA_IN_REPLICA, ddl_ready_query = '', isql_check_script = chk_bef_sql, replica_expected_out = '1' )
    2025-05-01 07:54:16.933
    2025-05-01 07:54:16.933                     # Must be EMPTY:
    2025-05-01 07:54:16.933                     run_errors_map['repl_chk_addi_data_err'] = capsys.readouterr().out
    2025-05-01 07:54:16.933
    2025-05-01 07:54:16.933                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.933                     # Timeout expired: expected data did not appear in replica DB for <MAX_TIME_FOR_WAIT_DATA_IN_REPLICA> seconds.
    2025-05-01 07:54:16.933                     pass
    2025-05-01 07:54:16.933                 else:
    2025-05-01 07:54:16.934                     ################################################
    2025-05-01 07:54:16.934                     ###  REPLICA: CHANGE STATE TO FULL SHUTDOWN  ###
    2025-05-01 07:54:16.934                     ################################################
    2025-05-01 07:54:16.934                     act_db_repl.gfix(switches=['-shut', 'full', '-force', '0', act_db_repl.db.dsn], io_enc = locale.getpreferredencoding(), combine_output = True )
    2025-05-01 07:54:16.934                     run_errors_map['repl_full_shutdown_err'] = act_db_repl.stdout
    2025-05-01 07:54:16.934                     act_db_repl.reset()
    2025-05-01 07:54:16.934
    2025-05-01 07:54:16.934                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.934                     pass
    2025-05-01 07:54:16.934                 else:
    2025-05-01 07:54:16.934                     ##########################################
    2025-05-01 07:54:16.934                     ###  M A S T E R:    M A K E   N B K 0  ##
    2025-05-01 07:54:16.934                     ##########################################
    2025-05-01 07:54:16.934                     # DO NOT use 'combine_output = True' here: nbackup produces non-empty output when successfully completes.
    2025-05-01 07:54:16.934                     act_db_main.nbackup( switches = ['-b', '0', act_db_main.db.dsn, db_nbk0], io_enc = locale.getpreferredencoding(), combine_output = False )
    2025-05-01 07:54:16.934                     run_errors_map['main_create_nbk0_err'] = act_db_main.stderr
    2025-05-01 07:54:16.934                     act_db_main.reset()
    2025-05-01 07:54:16.934
    2025-05-01 07:54:16.934                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.934                     # Some errors occurres during 'nbackup -b 0 db_main_alias ...'
    2025-05-01 07:54:16.935                     pass
    2025-05-01 07:54:16.935                 else:
    2025-05-01 07:54:16.935                     ##############################################################################################
    2025-05-01 07:54:16.935                     ###   NBK0: FIXUP, SET AS REPLICA, CHANGE STATE TO FULL SHUTDOWN,  MOVE TO OLD  'DB_REPL'  ###
    2025-05-01 07:54:16.935                     ##############################################################################################
    2025-05-01 07:54:16.935                     try:
    2025-05-01 07:54:16.935                         act_db_repl.nbackup(switches = ['-SEQ', '-F', str(db_nbk0)], combine_output = True, io_enc = locale.getpreferredencoding())
    2025-05-01 07:54:16.935                         # act_db_main.svcmgr(switches=['action_nfix', 'dbname', str(db_nbk0)], io_enc = locale.getpreferredencoding())
    2025-05-01 07:54:16.935                         with act_db_main.connect_server() as srv:
    2025-05-01 07:54:16.935                             #srv.database.nfix_database(database = db_nbk0) --> "Internal error when using clumplet API: attempt to store data in dataless clumplet" // see also: core_5085_test.py
    2025-05-01 07:54:16.935                             srv.database.set_replica_mode(database = db_nbk0, mode = ReplicaMode.READ_ONLY)
    2025-05-01 07:54:16.935                             srv.database.shutdown(database = db_nbk0, mode = ShutdownMode.FULL, method = ShutdownMethod.FORCED, timeout = 0)
    2025-05-01 07:54:16.935                     except DatabaseError as e:
    2025-05-01 07:54:16.935                         run_errors_map['nbk0_make_new_replica_err'] = e.__str__()
    2025-05-01 07:54:16.935
    2025-05-01 07:54:16.935                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.935                     pass
    2025-05-01 07:54:16.935                 else:
    2025-05-01 07:54:16.935
    2025-05-01 07:54:16.936                     ##################################
    2025-05-01 07:54:16.936                     ###   OVERWRITE  OLD  REPLICA  ###
    2025-05-01 07:54:16.936                     ##################################
    2025-05-01 07:54:16.936                     shutil.move(db_nbk0, db_info[act_db_repl,'db_full_path'])
    2025-05-01 07:54:16.936
    2025-05-01 07:54:16.936                     ##################################
    2025-05-01 07:54:16.936                     ###   REPLICA:  BRING  ONLINE  ###
    2025-05-01 07:54:16.936                     ##################################
    2025-05-01 07:54:16.936                     act_db_repl.gfix(switches=['-online', act_db_repl.db.dsn], io_enc = locale.getpreferredencoding(), combine_output = True )
    2025-05-01 07:54:16.936                     run_errors_map['repl_bring_online_err']  = act_db_repl.stdout
    2025-05-01 07:54:16.936                     act_db_repl.reset()
    2025-05-01 07:54:16.936
    2025-05-01 07:54:16.936                 replold_lines = get_repl_log(act_db_main)
    2025-05-01 07:54:16.936                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.936                     pass
    2025-05-01 07:54:16.936                 else:
    2025-05-01 07:54:16.936                     ##############################################
    2025-05-01 07:54:16.936                     ###  MASTER: FINAL ACTION WITHIN TX = OAT  ###
    2025-05-01 07:54:16.936                     ##############################################
    2025-05-01 07:54:16.936                     try:
    2025-05-01 07:54:16.937                         tx_oat.commit()
    2025-05-01 07:54:16.937                     except DatabaseError as e:
    2025-05-01 07:54:16.937                         run_errors_map['main_oat_fini_err'] = e.__str__()
    2025-05-01 07:54:16.937
    2025-05-01 07:54:16.937                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.937                     pass
    2025-05-01 07:54:16.937                 else:
    2025-05-01 07:54:16.937
    2025-05-01 07:54:16.937                     ############################################################################
    2025-05-01 07:54:16.937                     ###  CHECK REPL.LOG: WAITING FOR "Transaction <N> is not found" MESSAGE  ###
    2025-05-01 07:54:16.937                     ############################################################################
    2025-05-01 07:54:16.937                     # Before fix: "ERROR: Transaction 13 is not found" appeared in the repl log at thios point.
    2025-05-01 07:54:16.937                     pattern_to_check = re.compile( r'Error:\s+Transaction\s+\d+\s+(is\s+)?not\s+found', re.IGNORECASE )
    2025-05-01 07:54:16.937                     run_errors_map['repl_tx_not_found_err'] = watch_repl_log_pattern( act_db_main, pattern_to_check, replold_lines, MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG, consider_found_as_unexpected = True)
    2025-05-01 07:54:16.937
    2025-05-01 07:54:16.937                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.937                     pass
    2025-05-01 07:54:16.938                 else:
    2025-05-01 07:54:16.938                     ##############################################
    2025-05-01 07:54:16.938                     ###  WAIT UNTIL REPLICA DB BECOMES ACTUAL  ###
    2025-05-01 07:54:16.938                     ##############################################
    2025-05-01 07:54:16.938                     # ( a: Action, max_allowed_time_for_wait, ddl_ready_query = '', isql_check_script = '', replica_expected_out = ''):
    2025-05-01 07:54:16.938                     chk_oat_sql = 'set heading off;select max(id) from test;'
    2025-05-01 07:54:16.938                     watch_replica( act_db_repl, MAX_TIME_FOR_WAIT_DATA_IN_REPLICA, ddl_ready_query = '', isql_check_script = chk_oat_sql, replica_expected_out = str(ADD_ROWS_INIT+ADD_ROWS_IN_OAT) )
    2025-05-01 07:54:16.938                     # Must be EMPTY:
    2025-05-01 07:54:16.938                     run_errors_map['repl_chk_fini_err'] = capsys.readouterr().out
    2025-05-01 07:54:16.938
    2025-05-01 07:54:16.938                 if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.938                     pass
    2025-05-01 07:54:16.938                 else:
    2025-05-01 07:54:16.938                     #######################################################################################
    2025-05-01 07:54:16.938                     ###  CHECK REPL.LOG: WAITING FOR "DELETING SEGMENT {} AS NO LONGER NEEDED" MESSAGE  ###
    2025-05-01 07:54:16.938                     #######################################################################################
    2025-05-01 07:54:16.938                     # VERBOSE: Deleting segment 2 as no longer needed
    2025-05-01 07:54:16.938                     # NB: before fix message was: "VERBOSE: Deleting segment 2 due to fast forward"
    2025-05-01 07:54:16.938                     pattern_to_check = re.compile( r'VERBOSE:\s+Deleting\s+segment\s+%d\s+as\s+no\s+longer\s+needed' % preserved_segment_no, re.IGNORECASE )
    2025-05-01 07:54:16.939                     run_errors_map['repl_deleted_oat_segm'] = watch_repl_log_pattern( act_db_main, pattern_to_check, replold_lines, MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG)
    2025-05-01 07:54:16.939
    2025-05-01 07:54:16.939         if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.939             # We had a problem in some of previous steps.
    2025-05-01 07:54:16.939             # First, we have to RECREATE both master and slave databases
    2025-05-01 07:54:16.939             # (otherwise further execution of this test or other replication-related tests most likely will fail):
    2025-05-01 07:54:16.939             run_errors_map['out_reset'] = reset_replication(act_db_main, act_db_repl, db_info[act_db_main,'db_full_path'], db_info[act_db_repl,'db_full_path'])
    2025-05-01 07:54:16.939         else:
    2025-05-01 07:54:16.939             drop_db_objects(act_db_main, act_db_repl, capsys)
    2025-05-01 07:54:16.939             # Must be EMPTY:
    2025-05-01 07:54:16.939             run_errors_map['out_drop'] = capsys.readouterr().out
    2025-05-01 07:54:16.939
    2025-05-01 07:54:16.939         if max(v.strip() for v in run_errors_map.values()):
    2025-05-01 07:54:16.939             print(f'Problem(s) detected, check run_errors_map:')
    2025-05-01 07:54:16.939             for k,v in run_errors_map.items():
    2025-05-01 07:54:16.939                 if v.strip():
    2025-05-01 07:54:16.939                     print(k,':')
    2025-05-01 07:54:16.939                     print(v.strip())
    2025-05-01 07:54:16.939                     print('-' * 40)
    2025-05-01 07:54:16.939
    2025-05-01 07:54:16.940 >       assert '' == capsys.readouterr().out
    2025-05-01 07:54:16.940 E       AssertionError: assert
    2025-05-01 07:54:16.940 E         - Problem(s) detected, check run_errors_map:
    2025-05-01 07:54:16.940 E         - repl_tx_not_found_err :
    2025-05-01 07:54:16.940 E         - UNEXPECTED outcome: pattern 'Error:\s+Transaction\s+\d+\s+(is\s+)?not\s+found' must not occur in log but was ENCOUNTERED there for 21 seconds.
    2025-05-01 07:54:16.940 E         - replication log diff:
    2025-05-01 07:54:16.940 E         -    0 ---
    2025-05-01 07:54:16.940 E         -    1 +++
    2025-05-01 07:54:16.940 E         -    2 @@ -4751,3 +4751,82 @@
    2025-05-01 07:54:16.940 E         -    3  IBASE-CLIENT (replica) Thu May  1 07:45:20 2025
    2025-05-01 07:54:16.940 E         -    4  	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.940 E         -    5  	VERBOSE: No new segments found, suspending
    2025-05-01 07:54:16.940 E         -    6 +
    2025-05-01 07:54:16.940 E         -    7 +IBASE-CLIENT (replica) Thu May  1 07:45:23 2025
    2025-05-01 07:54:16.940 E         -    8 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.940 E         -    9 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    2025-05-01 07:54:16.940 E         -   10 +
    2025-05-01 07:54:16.940 E         -   11 +IBASE-CLIENT (replica) Thu May  1 07:45:23 2025
    2025-05-01 07:54:16.941 E         -   12 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.941 E         -   13 +	VERBOSE: No new segments found, suspending
    2025-05-01 07:54:16.941 E         -   14 +
    2025-05-01 07:54:16.941 E         -   15 +IBASE-CLIENT (replica) Thu May  1 07:45:26 2025
    2025-05-01 07:54:16.941 E         -   16 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.941 E         -   17 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    2025-05-01 07:54:16.941 E         -   18 +
    2025-05-01 07:54:16.941 E         -   19 +IBASE-CLIENT (replica) Thu May  1 07:45:26 2025
    2025-05-01 07:54:16.941 E         -   20 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.941 E         -   21 +	VERBOSE: No new segments found, suspending
    2025-05-01 07:54:16.941 E         -   22 +
    2025-05-01 07:54:16.941 E         -   23 +IBASE-CLIENT (replica) Thu May  1 07:45:29 2025
    2025-05-01 07:54:16.941 E         -   24 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.941 E         -   25 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    2025-05-01 07:54:16.941 E         -   26 +
    2025-05-01 07:54:16.941 E         -   27 +IBASE-CLIENT (replica) Thu May  1 07:45:29 2025
    2025-05-01 07:54:16.941 E         -   28 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.941 E         -   29 +	VERBOSE: No new segments found, suspending
    2025-05-01 07:54:16.941 E         -   30 +
    2025-05-01 07:54:16.942 E         -   31 +IBASE-CLIENT (replica) Thu May  1 07:45:32 2025
    2025-05-01 07:54:16.942 E         -   32 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.942 E         -   33 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    2025-05-01 07:54:16.942 E         -   34 +
    2025-05-01 07:54:16.942 E         -   35 +IBASE-CLIENT (replica) Thu May  1 07:45:32 2025
    2025-05-01 07:54:16.942 E         -   36 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.942 E         -   37 +	VERBOSE: No new segments found, suspending
    2025-05-01 07:54:16.942 E         -   38 +
    2025-05-01 07:54:16.942 E         -   39 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
    2025-05-01 07:54:16.942 E         -   40 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.942 E         -   41 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
    2025-05-01 07:54:16.942 E         -   42 +
    2025-05-01 07:54:16.942 E         -   43 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
    2025-05-01 07:54:16.942 E         -   44 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.942 E         -   45 +	ERROR: connection shutdown
    2025-05-01 07:54:16.942 E         -   46 +	Database is shutdown.
    2025-05-01 07:54:16.942 E         -   47 +	At segment 6, offset 48
    2025-05-01 07:54:16.943 E         -   48 +
    2025-05-01 07:54:16.943 E         -   49 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
    2025-05-01 07:54:16.943 E         -   50 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.943 E         -   51 +	VERBOSE: Disconnecting and suspending
    2025-05-01 07:54:16.943 E         -   52 +
    2025-05-01 07:54:16.943 E         -   53 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.943 E         -   54 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.943 E         -   55 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
    2025-05-01 07:54:16.943 E         -   56 +
    2025-05-01 07:54:16.943 E         -   57 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.943 E         -   58 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.943 E         -   59 +	WARNING: Database sequence has been changed from 0 to 5, preparing for replication reset
    2025-05-01 07:54:16.943 E         -   60 +
    2025-05-01 07:54:16.943 E         -   61 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.943 E         -   62 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.943 E         -   63 +	VERBOSE: Segment 4 (15729380 bytes) is scanned in 0.003s, preserving (OAT: 36 in segment 4)
    2025-05-01 07:54:16.943 E         -   64 +
    2025-05-01 07:54:16.943 E         -   65 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.943 E         -   66 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.943 E         -   67 +	VERBOSE: Segment 5 (646 bytes) is scanned in 0.008s, preserving (OAT: 36 in segment 4)
    2025-05-01 07:54:16.944 E         -   68 +
    2025-05-01 07:54:16.944 E         -   69 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.944 E         -   70 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.944 E         -   71 +	WARNING: Resetting replication to continue from segment 6 (new OAT: 36 in segment 4)
    2025-05-01 07:54:16.944 E         -   72 +
    2025-05-01 07:54:16.944 E         -   73 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.944 E         -   74 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.944 E         -   75 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
    2025-05-01 07:54:16.944 E         -   76 +
    2025-05-01 07:54:16.944 E         -   77 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.944 E         -   78 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.944 E         -   79 +	ERROR: Transaction 36 is not found
    2025-05-01 07:54:16.944 E         -   80 +	At segment 6, offset 48
    2025-05-01 07:54:16.944 E         -   81 +
    2025-05-01 07:54:16.944 E         -   82 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    2025-05-01 07:54:16.944 E         -   83 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    2025-05-01 07:54:16.944 E         -   84 +	VERBOSE: Disconnecting and suspending
    2025-05-01 07:54:16.944 E         - ----------------------------------------
    2025-05-01 07:54:16.945
    2025-05-01 07:54:16.945 tests\functional\replication\test_make_async_reinit_reliable.py:689: AssertionError

3 #text

    act_db_main = <firebird.qa.plugin.Action pytest object at [hex]>
    act_db_repl = <firebird.qa.plugin.Action pytest object at [hex]>
    db_nbk0 = WindowsPath('H:/QA/temp/qa2024.tmp/fbqa/test_12245/gh_8324_tmp.nbk0')
    capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

        @pytest.mark.replication
        @pytest.mark.version('>=4.0.6')
        def test_1(act_db_main: Action,  act_db_repl: Action, db_nbk0: Path, capsys):

            FLD_WIDTH = 500
            ADD_ROWS_INIT = 100
            ADD_ROWS_IN_OAT = 30000
            TEST2_VALUE = -2147483648

            # Map for storing mnemonas and details for every FAILED step:
            run_errors_map = {}

            # Obtain full path + filename for DB_MAIN and DB_REPL aliases.
            # NOTE: we must NOT use 'a.db.db_path' for ALIASED databases!
            # It will return '.' rather than full path+filename.
            # Use only con.info.name for that!
            #
            db_info = {}
            for a in (act_db_main, act_db_repl):
                with a.db.connect() as con:
                    db_info[a,  'db_full_path'] = con.info.name

            sql_init = f"""
                set bail on;
                set wng off;
                recreate table test (
                    id int generated by default as identity constraint test_pk primary key
                    ,dts timestamp default 'now'
                    ,trn bigint default current_transaction
                    ,s varchar({FLD_WIDTH}) unique using index test_f01_unq
                );

                recreate table test2 (
                    id int generated by default as identity constraint test2_pk primary key
                    ,dts timestamp default 'now'
                    ,trn bigint default current_transaction
                    ,s varchar({FLD_WIDTH}) unique using index test2_f01_unq
                );
                commit;

                insert into test(s) select lpad( '', {FLD_WIDTH}, uuid_to_char(gen_uuid()) ) from rdb$types rows {ADD_ROWS_INIT};
                commit;

                recreate table t_completed(id int primary key);
                commit;
            """
            act_db_main.isql(switches=['-q'], input = sql_init, combine_output = True)
            run_errors_map['out_prep_ddl'] = act_db_main.clean_stdout
            act_db_main.reset()

            if max(v.strip() for v in run_errors_map.values()):
                # Some problem raised during init_sql execution
                pass
            else:
                # Query to be used for check that all DB objects present in replica (after last DML statement completed on master DB):
                ddl_ready_query = "select 1 from rdb$relations where rdb$relation_name = upper('t_completed')"
                #####################################################################
                ###  WAIT UNTIL REPLICA GET SEGMENT(S) WITH INITIAL DDL AND DATA  ###
                #####################################################################
                watch_replica( act_db_repl, MAX_TIME_FOR_WAIT_DATA_IN_REPLICA, ddl_ready_query)

                # Must be EMPTY:
                run_errors_map['out_repl_ddl'] = capsys.readouterr().out

            if max(v.strip() for v in run_errors_map.values()):
                # Some problem raised with delivering DDL changes to replica
                pass
            else:

                with act_db_main.db.connect() as con:
                    preserved_segment_no = -1

                    tp_oat = tpb(isolation = Isolation.SNAPSHOT, lock_timeout = 0)
                    tx_oat = con.transaction_manager(tp_oat)
                    cur_oat = tx_oat.cursor()

                    tx_oat.begin()
                    replold_lines = get_repl_log(act_db_main)

                    try:
                        cur_oat.execute(f"insert /* trace_tag OAT */ into test(s) select lpad('', {FLD_WIDTH}, uuid_to_char(gen_uuid())) from rdb$types,rdb$types rows {ADD_ROWS_IN_OAT}")
                        cur_oat.execute('select max(id) from test')
                        cur_oat.fetchone()
                    except DatabaseError as e:
                        run_errors_map['main_oat_init_err'] = e.__str__()

                    if max(v.strip() for v in run_errors_map.values()):
                        # Some problem was in just executed OAT-statement
                        pass
                    else:
                        ##############################################################
                        ###  CHECK REPL.LOG: WAITING FOR "PRESERVING OAT" MESSAGE  ###
                        ##############################################################
                        # VERBOSE: Segment 2 (11534562 bytes) is replicated in 0.934s, preserving (OAT: 10 in segment 2)
                        pattern_to_check = re.compile( r'preserving \(oat:\s+\d+\s+in\s+segment\s+\d+', re.IGNORECASE )
                        run_errors_map['repl_preserve_oat_err'] = watch_repl_log_pattern( act_db_main, pattern_to_check, replold_lines, MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG)

                    if max(v.strip() for v in run_errors_map.values()):
                        # Timeout expired: message "Segment ... preserving (OAT: ... in segment ...)" did not appeared
                        # in replication log for <MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG> seconds.
                        pass
                    else:

                        ###############################################
                        ###  MASTER: RUN DML BEFORE 'NBACKUP -B 0'  ###
                        ###############################################
                        # tp_wrk = tpb(isolation = Isolation.READ_COMMITTED_READ_CONSISTENCY, lock_timeout = 3) # ?!?! check trace  !!!
                        tp_bef = tpb(isolation = Isolation.READ_COMMITTED, lock_timeout = 3)
                        tx_bef = con.transaction_manager(tp_bef)
                        cur_bef = tx_bef.cursor()
                        try:
                            tx_bef.begin()
                            cur_bef.execute(f"insert /* trace_tag before creating nbk-0 */ into test2(id) values(?) returning rdb$get_context('SYSTEM', 'REPLICATION_SEQUENCE')", (TEST2_VALUE,))

                            # If returned value of rdb$get_context('SYSTEM', 'REPLICATION_SEQUENCE') is <N> then
                            # message in replication log contains this number PLUS 1, e.g. (for REPLICATION_SEQUENCE = 1):
                            # "Segment 2 (11534562 bytes) is replicated in 0.934s, preserving (OAT: 10 in segment 2)"
                            # We store this result in order to check further content of replication log that this
                            # segment was eventuially deleted (this will mean SUCCESSFUL finish of test):
                            #
                            preserved_segment_no = int(cur_bef.fetchone()[0]) + 1
                            tx_bef.commit()
                        except DatabaseError as e:
                            run_errors_map['main_dml_afte_nbk0_err'] = e.__str__()

                    if max(v.strip() for v in run_errors_map.values()):
                        # Some problem was in just executed statement
                        pass
                    else:
                        ##############################################
                        ###  WAIT UNTIL REPLICA DB BECOMES ACTUAL  ###
                        ##############################################
                        # ( a: Action, max_allowed_time_for_wait, ddl_ready_query = '', isql_check_script = '', replica_expected_out = ''):
                        chk_bef_sql = f'set heading off;select count(*) from test2 where id = {TEST2_VALUE};'
                        watch_replica( act_db_repl, MAX_TIME_FOR_WAIT_DATA_IN_REPLICA, ddl_ready_query = '', isql_check_script = chk_bef_sql, replica_expected_out = '1' )

                        # Must be EMPTY:
                        run_errors_map['repl_chk_addi_data_err'] = capsys.readouterr().out

                    if max(v.strip() for v in run_errors_map.values()):
                        # Timeout expired: expected data did not appear in replica DB for <MAX_TIME_FOR_WAIT_DATA_IN_REPLICA> seconds.
                        pass
                    else:
                        ################################################
                        ###  REPLICA: CHANGE STATE TO FULL SHUTDOWN  ###
                        ################################################
                        act_db_repl.gfix(switches=['-shut', 'full', '-force', '0', act_db_repl.db.dsn], io_enc = locale.getpreferredencoding(), combine_output = True )
                        run_errors_map['repl_full_shutdown_err'] = act_db_repl.stdout
                        act_db_repl.reset()

                    if max(v.strip() for v in run_errors_map.values()):
                        pass
                    else:
                        ##########################################
                        ###  M A S T E R:    M A K E   N B K 0  ##
                        ##########################################
                        # DO NOT use 'combine_output = True' here: nbackup produces non-empty output when successfully completes.
                        act_db_main.nbackup( switches = ['-b', '0', act_db_main.db.dsn, db_nbk0], io_enc = locale.getpreferredencoding(), combine_output = False )
                        run_errors_map['main_create_nbk0_err'] = act_db_main.stderr
                        act_db_main.reset()

                    if max(v.strip() for v in run_errors_map.values()):
                        # Some errors occurres during 'nbackup -b 0 db_main_alias ...'
                        pass
                    else:
                        ##############################################################################################
                        ###   NBK0: FIXUP, SET AS REPLICA, CHANGE STATE TO FULL SHUTDOWN,  MOVE TO OLD  'DB_REPL'  ###
                        ##############################################################################################
                        try:
                            act_db_repl.nbackup(switches = ['-SEQ', '-F', str(db_nbk0)], combine_output = True, io_enc = locale.getpreferredencoding())
                            # act_db_main.svcmgr(switches=['action_nfix', 'dbname', str(db_nbk0)], io_enc = locale.getpreferredencoding())
                            with act_db_main.connect_server() as srv:
                                #srv.database.nfix_database(database = db_nbk0) --> "Internal error when using clumplet API: attempt to store data in dataless clumplet" // see also: core_5085_test.py
                                srv.database.set_replica_mode(database = db_nbk0, mode = ReplicaMode.READ_ONLY)
                                srv.database.shutdown(database = db_nbk0, mode = ShutdownMode.FULL, method = ShutdownMethod.FORCED, timeout = 0)
                        except DatabaseError as e:
                            run_errors_map['nbk0_make_new_replica_err'] = e.__str__()

                    if max(v.strip() for v in run_errors_map.values()):
                        pass
                    else:

                        ##################################
                        ###   OVERWRITE  OLD  REPLICA  ###
                        ##################################
                        shutil.move(db_nbk0, db_info[act_db_repl,'db_full_path'])

                        ##################################
                        ###   REPLICA:  BRING  ONLINE  ###
                        ##################################
                        act_db_repl.gfix(switches=['-online', act_db_repl.db.dsn], io_enc = locale.getpreferredencoding(), combine_output = True )
                        run_errors_map['repl_bring_online_err']  = act_db_repl.stdout
                        act_db_repl.reset()

                    replold_lines = get_repl_log(act_db_main)
                    if max(v.strip() for v in run_errors_map.values()):
                        pass
                    else:
                        ##############################################
                        ###  MASTER: FINAL ACTION WITHIN TX = OAT  ###
                        ##############################################
                        try:
                            tx_oat.commit()
                        except DatabaseError as e:
                            run_errors_map['main_oat_fini_err'] = e.__str__()

                    if max(v.strip() for v in run_errors_map.values()):
                        pass
                    else:

                        ############################################################################
                        ###  CHECK REPL.LOG: WAITING FOR "Transaction <N> is not found" MESSAGE  ###
                        ############################################################################
                        # Before fix: "ERROR: Transaction 13 is not found" appeared in the repl log at thios point.
                        pattern_to_check = re.compile( r'Error:\s+Transaction\s+\d+\s+(is\s+)?not\s+found', re.IGNORECASE )
                        run_errors_map['repl_tx_not_found_err'] = watch_repl_log_pattern( act_db_main, pattern_to_check, replold_lines, MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG, consider_found_as_unexpected = True)

                    if max(v.strip() for v in run_errors_map.values()):
                        pass
                    else:
                        ##############################################
                        ###  WAIT UNTIL REPLICA DB BECOMES ACTUAL  ###
                        ##############################################
                        # ( a: Action, max_allowed_time_for_wait, ddl_ready_query = '', isql_check_script = '', replica_expected_out = ''):
                        chk_oat_sql = 'set heading off;select max(id) from test;'
                        watch_replica( act_db_repl, MAX_TIME_FOR_WAIT_DATA_IN_REPLICA, ddl_ready_query = '', isql_check_script = chk_oat_sql, replica_expected_out = str(ADD_ROWS_INIT+ADD_ROWS_IN_OAT) )
                        # Must be EMPTY:
                        run_errors_map['repl_chk_fini_err'] = capsys.readouterr().out

                    if max(v.strip() for v in run_errors_map.values()):
                        pass
                    else:
                        #######################################################################################
                        ###  CHECK REPL.LOG: WAITING FOR "DELETING SEGMENT {} AS NO LONGER NEEDED" MESSAGE  ###
                        #######################################################################################
                        # VERBOSE: Deleting segment 2 as no longer needed
                        # NB: before fix message was: "VERBOSE: Deleting segment 2 due to fast forward"
                        pattern_to_check = re.compile( r'VERBOSE:\s+Deleting\s+segment\s+%d\s+as\s+no\s+longer\s+needed' % preserved_segment_no, re.IGNORECASE )
                        run_errors_map['repl_deleted_oat_segm'] = watch_repl_log_pattern( act_db_main, pattern_to_check, replold_lines, MAX_TIME_FOR_WAIT_SEGMENT_IN_LOG)

            if max(v.strip() for v in run_errors_map.values()):
                # We had a problem in some of previous steps.
                # First, we have to RECREATE both master and slave databases
                # (otherwise further execution of this test or other replication-related tests most likely will fail):
                run_errors_map['out_reset'] = reset_replication(act_db_main, act_db_repl, db_info[act_db_main,'db_full_path'], db_info[act_db_repl,'db_full_path'])
            else:
                drop_db_objects(act_db_main, act_db_repl, capsys)
                # Must be EMPTY:
                run_errors_map['out_drop'] = capsys.readouterr().out

            if max(v.strip() for v in run_errors_map.values()):
                print(f'Problem(s) detected, check run_errors_map:')
                for k,v in run_errors_map.items():
                    if v.strip():
                        print(k,':')
                        print(v.strip())
                        print('-' * 40)

    >       assert '' == capsys.readouterr().out
    E       AssertionError: assert
    E         - Problem(s) detected, check run_errors_map:
    E         - repl_tx_not_found_err :
    E         - UNEXPECTED outcome: pattern 'Error:\s+Transaction\s+\d+\s+(is\s+)?not\s+found' must not occur in log but was ENCOUNTERED there for 21 seconds.
    E         - replication log diff:
    E         -    0 ---
    E         -    1 +++
    E         -    2 @@ -4751,3 +4751,82 @@
    E         -    3  IBASE-CLIENT (replica) Thu May  1 07:45:20 2025
    E         -    4  	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -    5  	VERBOSE: No new segments found, suspending
    E         -    6 +
    E         -    7 +IBASE-CLIENT (replica) Thu May  1 07:45:23 2025
    E         -    8 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -    9 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    E         -   10 +
    E         -   11 +IBASE-CLIENT (replica) Thu May  1 07:45:23 2025
    E         -   12 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   13 +	VERBOSE: No new segments found, suspending
    E         -   14 +
    E         -   15 +IBASE-CLIENT (replica) Thu May  1 07:45:26 2025
    E         -   16 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   17 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    E         -   18 +
    E         -   19 +IBASE-CLIENT (replica) Thu May  1 07:45:26 2025
    E         -   20 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   21 +	VERBOSE: No new segments found, suspending
    E         -   22 +
    E         -   23 +IBASE-CLIENT (replica) Thu May  1 07:45:29 2025
    E         -   24 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   25 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    E         -   26 +
    E         -   27 +IBASE-CLIENT (replica) Thu May  1 07:45:29 2025
    E         -   28 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   29 +	VERBOSE: No new segments found, suspending
    E         -   30 +
    E         -   31 +IBASE-CLIENT (replica) Thu May  1 07:45:32 2025
    E         -   32 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   33 +	VERBOSE: Added 2 segment(s) to the queue. Segments from 4 to 5
    E         -   34 +
    E         -   35 +IBASE-CLIENT (replica) Thu May  1 07:45:32 2025
    E         -   36 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   37 +	VERBOSE: No new segments found, suspending
    E         -   38 +
    E         -   39 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
    E         -   40 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   41 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
    E         -   42 +
    E         -   43 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
    E         -   44 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   45 +	ERROR: connection shutdown
    E         -   46 +	Database is shutdown.
    E         -   47 +	At segment 6, offset 48
    E         -   48 +
    E         -   49 +IBASE-CLIENT (replica) Thu May  1 07:45:35 2025
    E         -   50 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   51 +	VERBOSE: Disconnecting and suspending
    E         -   52 +
    E         -   53 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   54 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   55 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
    E         -   56 +
    E         -   57 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   58 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   59 +	WARNING: Database sequence has been changed from 0 to 5, preparing for replication reset
    E         -   60 +
    E         -   61 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   62 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   63 +	VERBOSE: Segment 4 (15729380 bytes) is scanned in 0.003s, preserving (OAT: 36 in segment 4)
    E         -   64 +
    E         -   65 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   66 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   67 +	VERBOSE: Segment 5 (646 bytes) is scanned in 0.008s, preserving (OAT: 36 in segment 4)
    E         -   68 +
    E         -   69 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   70 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   71 +	WARNING: Resetting replication to continue from segment 6 (new OAT: 36 in segment 4)
    E         -   72 +
    E         -   73 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   74 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   75 +	VERBOSE: Added 3 segment(s) to the queue. Segments from 4 to 6
    E         -   76 +
    E         -   77 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   78 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   79 +	ERROR: Transaction 36 is not found
    E         -   80 +	At segment 6, offset 48
    E         -   81 +
    E         -   82 +IBASE-CLIENT (replica) Thu May  1 07:45:42 2025
    E         -   83 +	Database: H:\QA\RUNDAILY-2024\UNPACKED-SNAPSHOT.TMP\EXAMPLES\EMPBUILD\QA_REPLICATION\DB_REPL.FDB
    E         -   84 +	VERBOSE: Disconnecting and suspending
    E         - ----------------------------------------

    tests\functional\replication\test_make_async_reinit_reliable.py:689: 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 | 5.0.3.1674 2025.06.27 3ee5c | F | F | 53875 | 50182 | 2025.06.29 11:16:34.781 | 2025.06.29 11:17:28.656 | 2025.06.29 10:12:52.746 | 2025.06.29 10:13:42.928
2 | 5.0.3.1657 2025.06.26 dcb8a | F | F | 49923 | 52519 | 2025.06.27 11:17:12.386 | 2025.06.27 11:18:02.309 | 2025.06.27 10:13:36.285 | 2025.06.27 10:14:28.804
3 | 5.0.3.1657 2025.06.20 8b4d2 | F | F | 50777 | 53288 | 2025.06.26 11:31:37.550 | 2025.06.26 11:32:28.327 | 2025.06.26 10:27:48.482 | 2025.06.26 10:28:41.770
4 | 5.0.3.1657 2025.06.19 4bd4c | F | F | 50302 | 52629 | 2025.06.20 05:35:47.636 | 2025.06.20 05:36:37.938 | 2025.06.20 04:32:01.288 | 2025.06.20 04:32:53.917
5 | 5.0.3.1657 2025.06.11 dae6f | F | F | 53466 | 51278 | 2025.06.19 11:07:17.995 | 2025.06.19 11:08:11.461 | 2025.06.19 10:03:28.746 | 2025.06.19 10:04:20.024
6 | 5.0.3.1657 2025.06.10 dbc92 | F | F | 50652 | 53252 | 2025.06.11 08:53:30.575 | 2025.06.11 08:54:21.227 | 2025.06.11 07:49:28.786 | 2025.06.11 07:50:22.038
7 | 5.0.3.1656 2025.06.05 00512 | F | F | 53271 | 50323 | 2025.06.10 10:08:48.879 | 2025.06.10 10:09:42.150 | 2025.06.10 09:04:31.078 | 2025.06.10 09:05:21.401
8 | 5.0.3.1656 2025.05.20 c4b11 | F | F | 49771 | 50224 | 2025.06.03 09:55:33.276 | 2025.06.03 09:56:23.047 | 2025.06.03 08:52:29.747 | 2025.06.03 08:53:19.971
9 | 5.0.3.1652 2025.05.13 f51c6 | F | F | 50860 | 53644 | 2025.05.21 06:36:32.203 | 2025.05.21 06:37:23.063 | 2025.05.21 05:33:45.318 | 2025.05.21 05:34:38.962
10 | 5.0.3.1651 2025.05.08 ee9d2 | F | F | 50349 | 2394 | 2025.05.13 06:49:11.891 | 2025.05.13 06:50:02.240 | 2025.05.13 05:44:07.005 | 2025.05.13 05:44:09.399
11 | 5.0.3.1651 2025.05.04 3d914 | F | F | 51281 | 2391 | 2025.05.09 04:38:15.705 | 2025.05.09 04:39:06.986 | 2025.05.09 03:33:05.029 | 2025.05.09 03:33:07.420
12 | 5.0.3.1651 2025.04.30 141ef | F | F | 50859 | 2387 | 2025.05.02 04:45:47.496 | 2025.05.02 04:46:38.355 | 2025.05.02 03:40:57.943 | 2025.05.02 03:41:00.330
13 | 5.0.3.1650 2025.04.30 6253f | F | F | 50807 | 2395 | 2025.05.01 04:44:53.129 | 2025.05.01 04:45:43.936 | 2025.05.01 03:39:54.335 | 2025.05.01 03:39:56.730
14 | 5.0.3.1650 2025.04.28 4cbff | F | F | 50807 | 2198 | 2025.04.30 04:43:52.140 | 2025.04.30 04:44:42.947 | 2025.04.30 03:39:07.625 | 2025.04.30 03:39:09.823
15 | 5.0.3.1649 2025.04.21 5b2d0 | F | F | 52753 | 2422 | 2025.04.26 10:17:56.028 | 2025.04.26 10:18:48.781 | 2025.04.26 09:12:09.708 | 2025.04.26 09:12:12.130
16 | 5.0.3.1648 2025.04.18 2f4c5 | F | F | 49836 | 53263 | 2025.04.20 04:29:12.627 | 2025.04.20 04:30:02.463 | 2025.04.20 03:25:22.623 | 2025.04.20 03:26:15.886
17 | 5.0.3.1635 2025.04.03 f6bd1 | F | F | 52056 | 2391 | 2025.04.18 06:56:53.887 | 2025.04.18 06:57:45.943 | 2025.04.18 05:51:19.112 | 2025.04.18 05:51:21.503
18 | 5.0.3.1635 2025.03.31 22ec6 | F | F | 50861 | 2205 | 2025.04.03 10:02:39.599 | 2025.04.03 10:03:30.460 | 2025.04.03 08:56:43.450 | 2025.04.03 08:56:45.655
19 | 5.0.3.1633 2025.03.28 3123a | F | F | 49736 | 2398 | 2025.03.31 10:01:06.701 | 2025.03.31 10:01:56.437 | 2025.03.31 08:55:12.546 | 2025.03.31 08:55:14.944
20 | 5.0.3.1633 2025.03.27 e0fb8 | F | F | 51556 | 2392 | 2025.03.28 10:33:04.984 | 2025.03.28 10:33:56.540 | 2025.03.28 09:23:12.677 | 2025.03.28 09:23:15.069
21 | 5.0.3.1631 2025.03.25 bda65 | F | F | 50014 | 50393 | 2025.03.27 10:13:38.140 | 2025.03.27 10:14:28.154 | 2025.03.27 09:05:59.324 | 2025.03.27 09:06:49.717
22 | 5.0.3.1631 2025.03.21 1925b | F | F | 54476 | 54471 | 2025.03.25 06:47:40.587 | 2025.03.25 06:48:35.063 | 2025.03.25 05:39:57.524 | 2025.03.25 05:40:51.995
23 | 5.0.3.1629 2025.03.18 506d7 | F | F | 53461 | 50426 | 2025.03.20 09:47:38.886 | 2025.03.20 09:48:32.347 | 2025.03.20 08:39:59.595 | 2025.03.20 08:40:50.021
24 | 5.0.3.1628 2025.03.14 16d05 | F | F | 49856 | 51374 | 2025.03.18 09:41:44.317 | 2025.03.18 09:42:34.173 | 2025.03.18 08:35:31.871 | 2025.03.18 08:36:23.245
25 | 5.0.3.1627 2025.02.26 4e218 | F | F | 50610 | 52927 | 2025.03.13 10:01:29.555 | 2025.03.13 10:02:20.165 | 2025.03.13 08:53:19.877 | 2025.03.13 08:54:12.804
26 | 5.0.3.1624 2025.02.25 dc3b2 | F | F | 50918 | 53414 | 2025.02.26 15:33:33.327 | 2025.02.26 15:34:24.245 | 2025.02.26 14:26:07.788 | 2025.02.26 14:27:01.202
27 | 5.0.2.1615 2025.02.20 4a726 | F | F | 50244 | 2213 | 2025.02.25 08:47:25.120 | 2025.02.25 08:48:15.364 | 2025.02.25 07:39:27.132 | 2025.02.25 07:39:29.345
28 | 5.0.2.1615 2025.02.14 9cb76 | F | F | 50821 | 54560 | 2025.02.15 04:14:57.415 | 2025.02.15 04:15:48.236 | 2025.02.15 03:09:45.624 | 2025.02.15 03:10:40.184
29 | 5.0.2.1577 2025.02.07 f50a2 | F | F | 53798 | 51399 | 2025.02.14 06:27:39.863 | 2025.02.14 06:28:33.661 | 2025.02.14 05:23:36.885 | 2025.02.14 05:24:28.284
30 | 5.0.2.1577 2024.12.24 3c80e | F | F | 53754 | 53443 | 2025.02.06 09:41:09.561 | 2025.02.06 09:42:03.315 | 2025.02.06 08:37:10.993 | 2025.02.06 08:38:04.436
31 | 5.0.2.1576 2024.12.17 646b0 | F | F | 53472 | 49221 | 2024.12.24 09:24:15.990 | 2024.12.24 09:25:09.462 | 2024.12.24 08:20:22.912 | 2024.12.24 08:21:12.133
32 | 5.0.2.1575 2024.12.09 9af52 | F | F | 52888 | 48625 | 2024.12.16 09:21:00.572 | 2024.12.16 09:21:53.460 | 2024.12.16 08:17:15.054 | 2024.12.16 08:18:03.679

#### Elapsed time, ms. Chart for last 32 runs:

Last commits information (all timestamps in UTC):