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   
    Select Expression
    ....-> Aggregate
    ........-> Filter
    ............-> Hash Join (semi)
  - ................-> Table "TEST1" as "A" Full Scan
  + ................-> Table "PUBLIC"."TEST1" as "A" Full Scan
    ................-> Record Buffer (record length: NN)
    ....................-> Filter
    ........................-> Hash Join (semi)
  - ............................-> Table "TEST2" as "B" Full Scan
  + ............................-> Table "PUBLIC"."TEST2" as "B" Full Scan
    ............................-> Record Buffer (record length: NN)
    ................................-> Filter
  - ....................................-> Table "TEST3" as "C" Full Scan
  + ....................................-> Table "PUBLIC"."TEST3" as "C" Full Scan
    10

LOG DETAILS:

2025-06-28 05:26:19.454
2025-06-28 05:26:19.460 act = <firebird.qa.plugin.Action object at [hex]>
2025-06-28 05:26:19.466 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-06-28 05:26:19.472
2025-06-28 05:26:19.479 @pytest.mark.version('>=5.0.2')
2025-06-28 05:26:19.487 def test_1(act: Action, capsys):
2025-06-28 05:26:19.497
2025-06-28 05:26:19.505 test_sql = """
2025-06-28 05:26:19.512 select count(*) from test1 a
2025-06-28 05:26:19.517 where
2025-06-28 05:26:19.522 a.id in (
2025-06-28 05:26:19.526 select b.pid from test2 b
2025-06-28 05:26:19.531 where
2025-06-28 05:26:19.536 b.id in (
2025-06-28 05:26:19.540 select c.pid from test3 c
2025-06-28 05:26:19.546 where name like '%ABC%'
2025-06-28 05:26:19.556 )
2025-06-28 05:26:19.565 );
2025-06-28 05:26:19.574 """
2025-06-28 05:26:19.584
2025-06-28 05:26:19.596 srv_cfg = driver_config.register_server(name = f'srv_cfg_aae2ae32', config = '')
2025-06-28 05:26:19.604 db_cfg_name = f'db_cfg_aae2ae32'
2025-06-28 05:26:19.610 db_cfg_object = driver_config.register_database(name = db_cfg_name)
2025-06-28 05:26:19.616 db_cfg_object.server.value = srv_cfg.name
2025-06-28 05:26:19.621 db_cfg_object.database.value = str(act.db.db_path)
2025-06-28 05:26:19.627 if act.is_version('<6'):
2025-06-28 05:26:19.633 db_cfg_object.config.value = f"""
2025-06-28 05:26:19.638 SubQueryConversion = true
2025-06-28 05:26:19.651 """
2025-06-28 05:26:19.663
2025-06-28 05:26:19.673 with connect(db_cfg_name, user = act.db.user, password = act.db.password) as con:
2025-06-28 05:26:19.686 ps, rs = None, None
2025-06-28 05:26:19.697 try:
2025-06-28 05:26:19.709 cur = con.cursor()
2025-06-28 05:26:19.719 ps = cur.prepare(test_sql)
2025-06-28 05:26:19.728
2025-06-28 05:26:19.740 # Print explained plan with padding eash line by dots in order to see indentations:
2025-06-28 05:26:19.749 print( '\n'.join([replace_leading(s) for s in ps.detailed_plan.split('\n')]) )
2025-06-28 05:26:19.756
2025-06-28 05:26:19.763 # ::: NB ::: 'ps' returns data, i.e. this is SELECTABLE expression.
2025-06-28 05:26:19.771 # We have to store result of cur.execute(<psInstance>) in order to
2025-06-28 05:26:19.780 # close it explicitly.
2025-06-28 05:26:19.789 # Otherwise AV can occur during Python garbage collection and this
2025-06-28 05:26:19.796 # causes pytest to hang on its final point.
2025-06-28 05:26:19.808 # Explained by hvlad, email 26.10.24 17:42
2025-06-28 05:26:19.816 rs = cur.execute(ps)
2025-06-28 05:26:19.825 for r in rs:
2025-06-28 05:26:19.832 print(r[0])
2025-06-28 05:26:19.839 except DatabaseError as e:
2025-06-28 05:26:19.847 print(e.__str__())
2025-06-28 05:26:19.853 print(e.gds_codes)
2025-06-28 05:26:19.858 finally:
2025-06-28 05:26:19.865 if rs:
2025-06-28 05:26:19.877 rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
2025-06-28 05:26:19.886 if ps:
2025-06-28 05:26:19.900 ps.free()
2025-06-28 05:26:19.912
2025-06-28 05:26:19.923 act.expected_stdout = f"""
2025-06-28 05:26:19.932 Select Expression
2025-06-28 05:26:19.939 ....-> Aggregate
2025-06-28 05:26:19.945 ........-> Filter
2025-06-28 05:26:19.951 ............-> Hash Join (semi)
2025-06-28 05:26:19.957 ................-> Table "TEST1" as "A" Full Scan
2025-06-28 05:26:19.963 ................-> Record Buffer (record length: 82)
2025-06-28 05:26:19.971 ....................-> Filter
2025-06-28 05:26:19.981 ........................-> Hash Join (semi)
2025-06-28 05:26:19.989 ............................-> Table "TEST2" as "B" Full Scan
2025-06-28 05:26:19.995 ............................-> Record Buffer (record length: 57)
2025-06-28 05:26:20.003 ................................-> Filter
2025-06-28 05:26:20.014 ....................................-> Table "TEST3" as "C" Full Scan
2025-06-28 05:26:20.024 10
2025-06-28 05:26:20.034 """
2025-06-28 05:26:20.043 act.stdout = capsys.readouterr().out
2025-06-28 05:26:20.051 >       assert act.clean_stdout == act.clean_expected_stdout
2025-06-28 05:26:20.064 E       assert
2025-06-28 05:26:20.077 E           Select Expression
2025-06-28 05:26:20.085 E           ....-> Aggregate
2025-06-28 05:26:20.092 E           ........-> Filter
2025-06-28 05:26:20.097 E           ............-> Hash Join (semi)
2025-06-28 05:26:20.103 E         - ................-> Table "TEST1" as "A" Full Scan
2025-06-28 05:26:20.110 E         + ................-> Table "PUBLIC"."TEST1" as "A" Full Scan
2025-06-28 05:26:20.122 E           ................-> Record Buffer (record length: NN)
2025-06-28 05:26:20.131 E           ....................-> Filter
2025-06-28 05:26:20.141 E           ........................-> Hash Join (semi)
2025-06-28 05:26:20.149 E         - ............................-> Table "TEST2" as "B" Full Scan
2025-06-28 05:26:20.156 E         + ............................-> Table "PUBLIC"."TEST2" as "B" Full Scan
2025-06-28 05:26:20.171 E           ............................-> Record Buffer (record length: NN)
2025-06-28 05:26:20.181 E           ................................-> Filter
2025-06-28 05:26:20.190 E         - ....................................-> Table "TEST3" as "C" Full Scan
2025-06-28 05:26:20.201 E         + ....................................-> Table "PUBLIC"."TEST3" as "C" Full Scan
2025-06-28 05:26:20.217 E           10
2025-06-28 05:26:20.224
2025-06-28 05:26:20.231 tests/functional/tabloid/test_aae2ae32.py:157: AssertionError
2025-06-28 05:26:20.237 ---------------------------- Captured stdout setup -----------------------------
2025-06-28 05:26:20.247 Creating db: localhost:/var/tmp/qa_2024/test_12406/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]>
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    @pytest.mark.version('>=5.0.2')
    def test_1(act: Action, capsys):
    
        test_sql = """
            select count(*) from test1 a
            where
                a.id in (
                    select b.pid from test2 b
                    where
                        b.id in (
                            select c.pid from test3 c
                            where name like '%ABC%'
                        )
                );
        """
    
        srv_cfg = driver_config.register_server(name = f'srv_cfg_aae2ae32', config = '')
        db_cfg_name = f'db_cfg_aae2ae32'
        db_cfg_object = driver_config.register_database(name = db_cfg_name)
        db_cfg_object.server.value = srv_cfg.name
        db_cfg_object.database.value = str(act.db.db_path)
        if act.is_version('<6'):
            db_cfg_object.config.value = f"""
                SubQueryConversion = true
            """
    
        with connect(db_cfg_name, user = act.db.user, password = act.db.password) as con:
            ps, rs = None, None
            try:
                cur = con.cursor()
                ps = cur.prepare(test_sql)
    
                # Print explained plan with padding eash line by dots in order to see indentations:
                print( '\n'.join([replace_leading(s) for s in ps.detailed_plan.split('\n')]) )
    
                # ::: NB ::: 'ps' returns data, i.e. this is SELECTABLE expression.
                # We have to store result of cur.execute(<psInstance>) in order to
                # close it explicitly.
                # Otherwise AV can occur during Python garbage collection and this
                # causes pytest to hang on its final point.
                # Explained by hvlad, email 26.10.24 17:42
                rs = cur.execute(ps)
                for r in rs:
                    print(r[0])
            except DatabaseError as e:
                print(e.__str__())
                print(e.gds_codes)
            finally:
                if rs:
                    rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
                if ps:
                    ps.free()
    
        act.expected_stdout = f"""
            Select Expression
            ....-> Aggregate
            ........-> Filter
            ............-> Hash Join (semi)
            ................-> Table "TEST1" as "A" Full Scan
            ................-> Record Buffer (record length: 82)
            ....................-> Filter
            ........................-> Hash Join (semi)
            ............................-> Table "TEST2" as "B" Full Scan
            ............................-> Record Buffer (record length: 57)
            ................................-> Filter
            ....................................-> Table "TEST3" as "C" Full Scan
            10
        """
        act.stdout = capsys.readouterr().out
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E           Select Expression
E           ....-> Aggregate
E           ........-> Filter
E           ............-> Hash Join (semi)
E         - ................-> Table "TEST1" as "A" Full Scan
E         + ................-> Table "PUBLIC"."TEST1" as "A" Full Scan
E           ................-> Record Buffer (record length: NN)
E           ....................-> Filter
E           ........................-> Hash Join (semi)
E         - ............................-> Table "TEST2" as "B" Full Scan
E         + ............................-> Table "PUBLIC"."TEST2" as "B" Full Scan
E           ............................-> Record Buffer (record length: NN)
E           ................................-> Filter
E         - ....................................-> Table "TEST3" as "C" Full Scan
E         + ....................................-> Table "PUBLIC"."TEST3" as "C" Full Scan
E           10

tests/functional/tabloid/test_aae2ae32.py:157: AssertionError
Full history of outcomes and elapsed time, ms:
NN SNAP_INFO CS_outcome SS_outcome CS_run_time SS_run_time CS_run_beg CS_run_end SS_run_beg SS_run_end
1 6.0.0.881 2025.06.27 7035d F F 1032 607 2025.06.28 02:08:05.473 2025.06.28 02:08:06.505 2025.06.27 23:32:48.792 2025.06.27 23:32:49.399
2 6.0.0.877 2025.06.26 8e38f F F 982 687 2025.06.27 02:09:12.746 2025.06.27 02:09:13.728 2025.06.26 23:34:18.466 2025.06.26 23:34:19.153
3 6.0.0.876 2025.06.25 b1bec F F 999 619 2025.06.26 02:13:00.860 2025.06.26 02:13:01.859 2025.06.25 23:36:22.626 2025.06.25 23:36:23.245
4 6.0.0.863 2025.06.24 c3c20 F F 1081 421 2025.06.25 02:13:16.879 2025.06.25 02:13:17.960 2025.06.24 23:36:13.756 2025.06.24 23:36:14.177
5 6.0.0.858 2025.06.23 8d6f7 F F 993 766 2025.06.24 02:13:21.532 2025.06.24 02:13:22.525 2025.06.23 23:36:04.410 2025.06.23 23:36:05.176
6 6.0.0.849 2025.06.20 7b79c F F 918 720 2025.06.21 02:25:05.935 2025.06.21 02:25:06.853 2025.06.20 23:46:11.271 2025.06.20 23:46:11.991
7 6.0.0.848 2025.06.19 c483c F F 1028 721 2025.06.20 02:21:28.040 2025.06.20 02:21:29.068 2025.06.19 23:42:26.937 2025.06.19 23:42:27.658
8 6.0.0.845 2025.06.18 22b12 F F 1038 759 2025.06.19 02:30:12.282 2025.06.19 02:30:13.320 2025.06.18 23:46:24.755 2025.06.18 23:46:25.514
9 6.0.0.843 2025.06.16 995f4 F F 1001 443 2025.06.18 02:28:34.790 2025.06.18 02:28:35.791 2025.06.17 23:48:12.146 2025.06.17 23:48:12.589
10 6.0.0.840 2025.06.14 29bca F F 1036 556 2025.06.16 02:20:18.806 2025.06.16 02:20:19.842 2025.06.15 23:39:49.402 2025.06.15 23:39:49.958
11 6.0.0.838 2025.06.13 0e28a F F 1035 709 2025.06.14 02:34:31.750 2025.06.14 02:34:32.785 2025.06.13 23:48:33.390 2025.06.13 23:48:34.099
12 6.0.0.835 2025.06.12 2cf29 F F 1047 609 2025.06.13 02:33:00.653 2025.06.13 02:33:01.700 2025.06.12 23:51:39.550 2025.06.12 23:51:40.159
13 6.0.0.834 2025.06.11 e889f F F 1003 786 2025.06.12 02:29:04.757 2025.06.12 02:29:05.760 2025.06.11 23:48:11.044 2025.06.11 23:48:11.830
14 6.0.0.800 2025.06.10 1f226 P P 1082 567 2025.06.11 01:00:51.244 2025.06.11 01:00:52.326 2025.06.10 22:49:30.567 2025.06.10 22:49:31.134
15 6.0.0.799 2025.06.07 be644 P P 1087 562 2025.06.10 01:03:15.826 2025.06.10 01:03:16.913 2025.06.09 22:48:55.200 2025.06.09 22:48:55.762
16 6.0.0.797 2025.06.06 303e8 P P 1132 628 2025.06.07 01:07:25.534 2025.06.07 01:07:26.666 2025.06.06 22:48:43.534 2025.06.06 22:48:44.162
17 6.0.0.795 2025.05.29 7a71a P P 1193 688 2025.06.06 01:01:36.454 2025.06.06 01:01:37.647 2025.06.05 22:47:06.662 2025.06.05 22:47:07.350
18 6.0.0.792 2025.05.28 b4327 P P 1080 776 2025.05.29 01:16:51.970 2025.05.29 01:16:53.050 2025.05.28 22:51:22.971 2025.05.28 22:51:23.747
19 6.0.0.791 2025.05.27 02db8 P P 1021 748 2025.05.28 01:14:40.147 2025.05.28 01:14:41.168 2025.05.27 22:50:30.431 2025.05.27 22:50:31.179
20 6.0.0.789 2025.05.21 64051 P P 1087 751 2025.05.25 01:06:39.476 2025.05.25 01:06:40.563 2025.05.24 22:49:10.523 2025.05.24 22:49:11.274
21 6.0.0.787 2025.05.20 230ad P P 1104 742 2025.05.21 01:03:52.835 2025.05.21 01:03:53.939 2025.05.20 22:46:59.164 2025.05.20 22:46:59.906
22 6.0.0.783 2025.05.12 37320 P P 1132 533 2025.05.19 12:35:06.066 2025.05.19 12:35:07.198 2025.05.19 10:35:09.602 2025.05.19 10:35:10.135
23 6.0.0.779 2025.05.11 136fa P P 1160 573 2025.05.12 00:59:01.708 2025.05.12 00:59:02.868 2025.05.11 22:45:45.875 2025.05.11 22:45:46.448
24 6.0.0.778 2025.05.07 d735e P P 1116 614 2025.05.08 00:59:48.192 2025.05.08 00:59:49.308 2025.05.07 22:44:35.625 2025.05.07 22:44:36.239
25 6.0.0.776 2025.05.06 007cd P P 1089 691 2025.05.07 00:55:41.591 2025.05.07 00:55:42.680 2025.05.06 22:44:56.786 2025.05.06 22:44:57.477
26 6.0.0.770 2025.05.05 82c4a P P 1070 612 2025.05.06 00:53:50.725 2025.05.06 00:53:51.795 2025.05.05 22:43:44.762 2025.05.05 22:43:45.374
27 6.0.0.767 2025.05.01 cdd29 P P 1221 663 2025.05.02 00:48:12.605 2025.05.02 00:48:13.826 2025.05.01 22:42:47.715 2025.05.01 22:42:48.378
28 6.0.0.762 2025.04.30 5cb15 P P 1084 698 2025.05.01 00:46:37.104 2025.05.01 00:46:38.188 2025.04.30 22:41:12.215 2025.04.30 22:41:12.913
29 6.0.0.755 2025.04.29 739c6 P P 1085 497 2025.04.30 00:50:49.133 2025.04.30 00:50:50.218 2025.04.29 22:42:50.798 2025.04.29 22:42:51.295
30 6.0.0.753 2025.04.27 29ab3 P P 1072 626 2025.04.28 00:52:56.141 2025.04.28 00:52:57.213 2025.04.27 22:41:50.956 2025.04.27 22:41:51.582
31 6.0.0.745 2025.04.21 78ad8 P P 1082 748 2025.04.26 00:47:56.254 2025.04.26 00:47:57.336 2025.04.25 22:42:58.142 2025.04.25 22:42:58.890
32 6.0.0.744 2025.04.19 e883a P P 1177 711 2025.04.20 00:50:27.566 2025.04.20 00:50:28.743 2025.04.19 22:43:37.779 2025.04.19 22:43:38.490
33 6.0.0.742 2025.04.17 abc3b P P 1049 570 2025.04.19 00:52:59.068 2025.04.19 00:53:00.117 2025.04.18 22:43:42.553 2025.04.18 22:43:43.123
34 6.0.0.737 2025.04.16 fe52b P P 1092 760 2025.04.17 00:48:59.233 2025.04.17 00:49:00.325 2025.04.16 22:43:53.181 2025.04.16 22:43:53.941

Elapsed time, ms. Chart for last 34 runs:

Last commits information (all timestamps in UTC):