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   
  - EXPECTED: gbak total statistics for writes NOT LESS than ratio DB_FILE_SIZE / PAGE_SIZE
  + UNEXPECTED: gbak_total_writes=1001 -- LESS than restored_file_size/PAGE_SIZE=2638.0

LOG DETAILS:

2025-02-06 11:45:14.160
2025-02-06 11:45:14.160 act = <firebird.qa.plugin.Action object at [hex]>
2025-02-06 11:45:14.160 tmp_fbk = WindowsPath('H:/QA/temp/qa2024.tmp/fbqa/test_11703/tmp_gh_8391.restored.fbk')
2025-02-06 11:45:14.160 tmp_log = WindowsPath('H:/QA/temp/qa2024.tmp/fbqa/test_11703/tmp_gh_8391.restored.log')
2025-02-06 11:45:14.160 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-02-06 11:45:14.160
2025-02-06 11:45:14.160     @pytest.mark.version('>=4.0.6')
2025-02-06 11:45:14.160     def test_1(act: Action, tmp_fbk: Path, tmp_log: Path, capsys):
2025-02-06 11:45:14.160
2025-02-06 11:45:14.160         if act.get_server_architecture() != 'SuperServer':
2025-02-06 11:45:14.160             pytest.skip('Applies only to SuperServer')
2025-02-06 11:45:14.160
2025-02-06 11:45:14.160         # Scan line-by-line through databases.conf, find line starting with REQUIRED_ALIAS and extract name of file that
2025-02-06 11:45:14.160         # must be created in the $(dir_sampleDb)/qa/ folder.
2025-02-06 11:45:14.160         # NOTE: we have to SKIP lines which are commented out, i.e. if they starts with '#':
2025-02-06 11:45:14.160         p_required_alias_ptn =  re.compile( '^(?!#)((^|\\s+)' + REQUIRED_ALIAS + ')\\s*=\\s*\\$\\(dir_sampleDb\\)/qa/', re.IGNORECASE )
2025-02-06 11:45:14.160         fname_in_dbconf = None
2025-02-06 11:45:14.160
2025-02-06 11:45:14.161         with open(act.home_dir/'databases.conf', 'r') as f:
2025-02-06 11:45:14.161             for line in f:
2025-02-06 11:45:14.161                 if p_required_alias_ptn.search(line):
2025-02-06 11:45:14.161                     # If databases.conf contains line like this:
2025-02-06 11:45:14.161                     #     tmp_8391_alias = $(dir_sampleDb)/qa/tmp_qa_8391.fdb
2025-02-06 11:45:14.161                     # - then we extract filename: 'tmp_qa_8391.fdb' (see below):
2025-02-06 11:45:14.161                     fname_in_dbconf = Path(line.split('=')[1].strip()).name
2025-02-06 11:45:14.161                     break
2025-02-06 11:45:14.161
2025-02-06 11:45:14.161         # if 'fname_in_dbconf' remains undefined here then propably REQUIRED_ALIAS not equals to specified in the databases.conf!
2025-02-06 11:45:14.161         #
2025-02-06 11:45:14.161         assert fname_in_dbconf
2025-02-06 11:45:14.161
2025-02-06 11:45:14.161         test_sql = f"""
2025-02-06 11:45:14.161             set list on;
2025-02-06 11:45:14.161             create database '{REQUIRED_ALIAS}' user {act.db.user} password '{act.db.password}' page_size {PAGE_SIZE};
2025-02-06 11:45:14.161             commit;
2025-02-06 11:45:14.161             recreate sequence g;
2025-02-06 11:45:14.161             recreate table test(id int, b blob);
2025-02-06 11:45:14.162
2025-02-06 11:45:14.162             set autoterm on;
2025-02-06 11:45:14.162             execute block as
2025-02-06 11:45:14.162                 declare n int;
2025-02-06 11:45:14.162             begin
2025-02-06 11:45:14.162                 insert into test(id, b) values(gen_id(g,1), gen_uuid());
2025-02-06 11:45:14.162                 insert into test(id, b)
2025-02-06 11:45:14.162                 values(
2025-02-06 11:45:14.162                         gen_id(g,1)
2025-02-06 11:45:14.162                         ,(select list(gen_uuid()) as s from rdb$types,rdb$types)
2025-02-06 11:45:14.162                       );
2025-02-06 11:45:14.162
2025-02-06 11:45:14.162                 insert into test(id, b)
2025-02-06 11:45:14.162                 values(
2025-02-06 11:45:14.162                         gen_id(g,1)
2025-02-06 11:45:14.162                         ,(select list(gen_uuid()) as s from (select 1 x from rdb$types,rdb$types,rdb$types rows 800000))
2025-02-06 11:45:14.162                       );
2025-02-06 11:45:14.162             end
2025-02-06 11:45:14.162             ;
2025-02-06 11:45:14.162             commit;
2025-02-06 11:45:14.163             select mon$database_name, mon$page_buffers from mon$database;
2025-02-06 11:45:14.163         """
2025-02-06 11:45:14.163
2025-02-06 11:45:14.163         test_fdb_file = 'UNDEFINED'
2025-02-06 11:45:14.163         act.isql(switches=['-q'], input = test_sql, connect_db = False, credentials = False, combine_output = True, io_enc = locale.getpreferredencoding())
2025-02-06 11:45:14.163         for line in act.stdout.splitlines():
2025-02-06 11:45:14.163             if line.startswith('mon$database_name'.upper()):
2025-02-06 11:45:14.163                 test_fdb_file = line.split()[1]
2025-02-06 11:45:14.163             if line.startswith('mon$page_buffers'.upper()):
2025-02-06 11:45:14.163                 test_fdb_buffers = int(line.split()[1])
2025-02-06 11:45:14.163
2025-02-06 11:45:14.163         assert test_fdb_buffers == 128
2025-02-06 11:45:14.163         act.reset()
2025-02-06 11:45:14.163
2025-02-06 11:45:14.163         act.gbak(switches=['-b', act.db.dsn, str(tmp_fbk)], combine_output = True, io_enc = locale.getpreferredencoding())
2025-02-06 11:45:14.163         assert act.clean_stdout == ''
2025-02-06 11:45:14.163         act.reset()
2025-02-06 11:45:14.164
2025-02-06 11:45:14.164         act.gbak(switches=['-rep', '-v', '-st', 'w', str(tmp_fbk), REQUIRED_ALIAS], combine_output = True, io_enc = locale.getpreferredencoding())
2025-02-06 11:45:14.164
2025-02-06 11:45:14.164         # gbak: NNNN total statistics
2025-02-06 11:45:14.164         gbak_write_total_stat_ptn = re.compile( r'gbak(:)?\s+\d+\s+total\s+statistics', re.IGNORECASE )
2025-02-06 11:45:14.164
2025-02-06 11:45:14.164         EXPECTED_MSG = 'EXPECTED: gbak total statistics for writes NOT LESS than ratio DB_FILE_SIZE / PAGE_SIZE'
2025-02-06 11:45:14.164         for line in act.stdout.splitlines():
2025-02-06 11:45:14.164             if gbak_write_total_stat_ptn.search(line):
2025-02-06 11:45:14.164                 gbak_total_writes = int(line.split()[1])
2025-02-06 11:45:14.164                 restored_file_size = os.stat(test_fdb_file).st_size
2025-02-06 11:45:14.164                 if gbak_total_writes >= restored_file_size / PAGE_SIZE:
2025-02-06 11:45:14.164                     print(EXPECTED_MSG)
2025-02-06 11:45:14.164                 else:
2025-02-06 11:45:14.164                     print(f'UNEXPECTED: {gbak_total_writes=} -- LESS than {restored_file_size/PAGE_SIZE=}')
2025-02-06 11:45:14.164
2025-02-06 11:45:14.164         act.expected_stdout = EXPECTED_MSG
2025-02-06 11:45:14.164         act.stdout = capsys.readouterr().out
2025-02-06 11:45:14.164 >       assert act.clean_stdout == act.clean_expected_stdout
2025-02-06 11:45:14.165 E       assert
2025-02-06 11:45:14.165 E         - EXPECTED: gbak total statistics for writes NOT LESS than ratio DB_FILE_SIZE / PAGE_SIZE
2025-02-06 11:45:14.165 E         + UNEXPECTED: gbak_total_writes=1001 -- LESS than restored_file_size/PAGE_SIZE=2638.0
2025-02-06 11:45:14.165
2025-02-06 11:45:14.165 tests\bugs\gh_8391_test.py:136: AssertionError
3 #text
act = <firebird.qa.plugin.Action pytest object at [hex]>
tmp_fbk = WindowsPath('H:/QA/temp/qa2024.tmp/fbqa/test_11703/tmp_gh_8391.restored.fbk')
tmp_log = WindowsPath('H:/QA/temp/qa2024.tmp/fbqa/test_11703/tmp_gh_8391.restored.log')
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    @pytest.mark.version('>=4.0.6')
    def test_1(act: Action, tmp_fbk: Path, tmp_log: Path, capsys):
    
        if act.get_server_architecture() != 'SuperServer':
            pytest.skip('Applies only to SuperServer')
    
        # Scan line-by-line through databases.conf, find line starting with REQUIRED_ALIAS and extract name of file that
        # must be created in the $(dir_sampleDb)/qa/ folder.
        # NOTE: we have to SKIP lines which are commented out, i.e. if they starts with '#':
        p_required_alias_ptn =  re.compile( '^(?!#)((^|\\s+)' + REQUIRED_ALIAS + ')\\s*=\\s*\\$\\(dir_sampleDb\\)/qa/', re.IGNORECASE )
        fname_in_dbconf = None
    
        with open(act.home_dir/'databases.conf', 'r') as f:
            for line in f:
                if p_required_alias_ptn.search(line):
                    # If databases.conf contains line like this:
                    #     tmp_8391_alias = $(dir_sampleDb)/qa/tmp_qa_8391.fdb
                    # - then we extract filename: 'tmp_qa_8391.fdb' (see below):
                    fname_in_dbconf = Path(line.split('=')[1].strip()).name
                    break
    
        # if 'fname_in_dbconf' remains undefined here then propably REQUIRED_ALIAS not equals to specified in the databases.conf!
        #
        assert fname_in_dbconf
    
        test_sql = f"""
            set list on;
            create database '{REQUIRED_ALIAS}' user {act.db.user} password '{act.db.password}' page_size {PAGE_SIZE};
            commit;
            recreate sequence g;
            recreate table test(id int, b blob);
    
            set autoterm on;
            execute block as
                declare n int;
            begin
                insert into test(id, b) values(gen_id(g,1), gen_uuid());
                insert into test(id, b)
                values(
                        gen_id(g,1)
                        ,(select list(gen_uuid()) as s from rdb$types,rdb$types)
                      );
    
                insert into test(id, b)
                values(
                        gen_id(g,1)
                        ,(select list(gen_uuid()) as s from (select 1 x from rdb$types,rdb$types,rdb$types rows 800000))
                      );
            end
            ;
            commit;
            select mon$database_name, mon$page_buffers from mon$database;
        """
    
        test_fdb_file = 'UNDEFINED'
        act.isql(switches=['-q'], input = test_sql, connect_db = False, credentials = False, combine_output = True, io_enc = locale.getpreferredencoding())
        for line in act.stdout.splitlines():
            if line.startswith('mon$database_name'.upper()):
                test_fdb_file = line.split()[1]
            if line.startswith('mon$page_buffers'.upper()):
                test_fdb_buffers = int(line.split()[1])
    
        assert test_fdb_buffers == 128
        act.reset()
    
        act.gbak(switches=['-b', act.db.dsn, str(tmp_fbk)], combine_output = True, io_enc = locale.getpreferredencoding())
        assert act.clean_stdout == ''
        act.reset()
    
        act.gbak(switches=['-rep', '-v', '-st', 'w', str(tmp_fbk), REQUIRED_ALIAS], combine_output = True, io_enc = locale.getpreferredencoding())
    
        # gbak: NNNN total statistics
        gbak_write_total_stat_ptn = re.compile( r'gbak(:)?\s+\d+\s+total\s+statistics', re.IGNORECASE )
    
        EXPECTED_MSG = 'EXPECTED: gbak total statistics for writes NOT LESS than ratio DB_FILE_SIZE / PAGE_SIZE'
        for line in act.stdout.splitlines():
            if gbak_write_total_stat_ptn.search(line):
                gbak_total_writes = int(line.split()[1])
                restored_file_size = os.stat(test_fdb_file).st_size
                if gbak_total_writes >= restored_file_size / PAGE_SIZE:
                    print(EXPECTED_MSG)
                else:
                    print(f'UNEXPECTED: {gbak_total_writes=} -- LESS than {restored_file_size/PAGE_SIZE=}')
    
        act.expected_stdout = EXPECTED_MSG
        act.stdout = capsys.readouterr().out
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E         - EXPECTED: gbak total statistics for writes NOT LESS than ratio DB_FILE_SIZE / PAGE_SIZE
E         + UNEXPECTED: gbak_total_writes=1001 -- LESS than restored_file_size/PAGE_SIZE=2638.0

tests\bugs\gh_8391_test.py:136: 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 S P 7 2686 2025.06.29 11:07:35.837 2025.06.29 11:07:35.844 2025.06.29 10:06:39.592 2025.06.29 10:06:42.278
2 5.0.3.1657 2025.06.26 dcb8a S P 6 2730 2025.06.27 11:08:15.819 2025.06.27 11:08:15.825 2025.06.27 10:07:17.400 2025.06.27 10:07:20.130
3 5.0.3.1657 2025.06.20 8b4d2 S P 6 2671 2025.06.26 11:22:43.794 2025.06.26 11:22:43.800 2025.06.26 10:21:34.204 2025.06.26 10:21:36.875
4 5.0.3.1657 2025.06.19 4bd4c S P 7 2539 2025.06.20 05:26:58.073 2025.06.20 05:26:58.080 2025.06.20 04:25:52.552 2025.06.20 04:25:55.091
5 5.0.3.1657 2025.06.11 dae6f S P 7 2665 2025.06.19 10:58:25.320 2025.06.19 10:58:25.327 2025.06.19 09:57:16.088 2025.06.19 09:57:18.753
6 5.0.3.1657 2025.06.10 dbc92 S P 7 2803 2025.06.11 08:44:35.295 2025.06.11 08:44:35.302 2025.06.11 07:43:12.949 2025.06.11 07:43:15.752
7 5.0.3.1656 2025.06.05 00512 S P 7 2618 2025.06.10 10:00:05.420 2025.06.10 10:00:05.427 2025.06.10 08:58:17.994 2025.06.10 08:58:20.612
8 5.0.3.1656 2025.05.20 c4b11 S P 7 2630 2025.06.03 09:46:58.389 2025.06.03 09:46:58.396 2025.06.03 08:46:21.895 2025.06.03 08:46:24.525
9 5.0.3.1652 2025.05.13 f51c6 S P 6 2675 2025.05.21 06:27:58.090 2025.05.21 06:27:58.096 2025.05.21 05:27:37.610 2025.05.21 05:27:40.285
10 5.0.3.1651 2025.05.08 ee9d2 S F 7 2929 2025.05.13 06:40:37.268 2025.05.13 06:40:37.275 2025.05.13 05:21:51.373 2025.05.13 05:21:54.302
11 5.0.3.1651 2025.05.04 3d914 S F 7 3080 2025.05.09 04:29:40.193 2025.05.09 04:29:40.200 2025.05.09 03:10:49.053 2025.05.09 03:10:52.133
12 5.0.3.1651 2025.04.30 141ef S F 6 3020 2025.05.02 04:37:17.206 2025.05.02 04:37:17.212 2025.05.02 03:18:42.457 2025.05.02 03:18:45.477
13 5.0.3.1650 2025.04.30 6253f S F 7 3050 2025.05.01 04:36:19.950 2025.05.01 04:36:19.957 2025.05.01 03:17:38.698 2025.05.01 03:17:41.748
14 5.0.3.1650 2025.04.28 4cbff S F 7 2969 2025.04.30 04:35:21.584 2025.04.30 04:35:21.591 2025.04.30 03:16:51.787 2025.04.30 03:16:54.756
15 5.0.3.1649 2025.04.21 5b2d0 S F 6 2894 2025.04.26 10:09:16.860 2025.04.26 10:09:16.866 2025.04.26 08:49:51.882 2025.04.26 08:49:54.776
16 5.0.3.1648 2025.04.18 2f4c5 S P 7 2593 2025.04.20 04:20:30.942 2025.04.20 04:20:30.949 2025.04.20 03:19:09.189 2025.04.20 03:19:11.782
17 5.0.3.1635 2025.04.03 f6bd1 S F 7 3042 2025.04.18 06:48:11.799 2025.04.18 06:48:11.806 2025.04.18 05:29:02.024 2025.04.18 05:29:05.066
18 5.0.3.1635 2025.03.31 22ec6 S F 7 3127 2025.04.03 09:54:00.920 2025.04.03 09:54:00.927 2025.04.03 08:34:32.228 2025.04.03 08:34:35.355
19 5.0.3.1633 2025.03.28 3123a S F 7 3309 2025.03.31 09:52:30.151 2025.03.31 09:52:30.158 2025.03.31 08:33:08.109 2025.03.31 08:33:11.418
20 5.0.3.1633 2025.03.27 e0fb8 S F 7 3026 2025.03.28 10:24:08.963 2025.03.28 10:24:08.970 2025.03.28 09:01:02.714 2025.03.28 09:01:05.740
21 5.0.3.1631 2025.03.25 bda65 S P 6 2748 2025.03.27 10:04:40.312 2025.03.27 10:04:40.318 2025.03.27 08:59:36.060 2025.03.27 08:59:38.808
22 5.0.3.1631 2025.03.21 1925b S P 7 2678 2025.03.25 06:38:42.622 2025.03.25 06:38:42.629 2025.03.25 05:33:29.356 2025.03.25 05:33:32.034
23 5.0.3.1629 2025.03.18 506d7 S P 6 2718 2025.03.20 09:39:00.082 2025.03.20 09:39:00.088 2025.03.20 08:33:36.384 2025.03.20 08:33:39.102
24 5.0.3.1628 2025.03.14 16d05 S P 7 2747 2025.03.18 09:33:07.938 2025.03.18 09:33:07.945 2025.03.18 08:29:18.198 2025.03.18 08:29:20.945
25 5.0.3.1627 2025.02.26 4e218 S P 7 2569 2025.03.13 09:52:25.815 2025.03.13 09:52:25.822 2025.03.13 08:46:50.591 2025.03.13 08:46:53.160
26 5.0.3.1624 2025.02.25 dc3b2 S P 7 2415 2025.02.26 15:24:41.115 2025.02.26 15:24:41.122 2025.02.26 14:19:47.468 2025.02.26 14:19:49.883
27 5.0.2.1615 2025.02.20 4a726 S P 7 2587 2025.02.25 08:39:15.029 2025.02.25 08:39:15.036 2025.02.25 07:17:32.847 2025.02.25 07:17:35.434
28 5.0.2.1615 2025.02.14 9cb76 S P 7 2793 2025.02.15 04:06:53.750 2025.02.15 04:06:53.757 2025.02.15 03:03:48.663 2025.02.15 03:03:51.456
29 5.0.2.1577 2025.02.07 f50a2 S F 7 2644 2025.02.14 06:19:31.333 2025.02.14 06:19:31.340 2025.02.14 05:17:37.234 2025.02.14 05:17:39.878
30 5.0.2.1577 2024.12.24 3c80e S F 6 2641 2025.02.06 09:33:03.621 2025.02.06 09:33:03.627 2025.02.06 08:31:12.324 2025.02.06 08:31:14.965

Elapsed time, ms. Chart for last 30 runs:

Last commits information (all timestamps in UTC):