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-07-03 16:08:03.611
2025-07-03 16:08:03.611 act = <firebird.qa.plugin.Action object at [hex]>
2025-07-03 16:08:03.611 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-07-03 16:08:03.611
2025-07-03 16:08:03.611     @pytest.mark.version('>=5.0.2')
2025-07-03 16:08:03.611     def test_1(act: Action, capsys):
2025-07-03 16:08:03.611
2025-07-03 16:08:03.611         test_sql = """
2025-07-03 16:08:03.611             select count(*) from test1 a
2025-07-03 16:08:03.611             where
2025-07-03 16:08:03.611                 a.id in (
2025-07-03 16:08:03.611                     select b.pid from test2 b
2025-07-03 16:08:03.611                     where
2025-07-03 16:08:03.611                         b.id in (
2025-07-03 16:08:03.611                             select c.pid from test3 c
2025-07-03 16:08:03.611                             where name like '%ABC%'
2025-07-03 16:08:03.612                         )
2025-07-03 16:08:03.612                 );
2025-07-03 16:08:03.612         """
2025-07-03 16:08:03.612
2025-07-03 16:08:03.612         srv_cfg = driver_config.register_server(name = f'srv_cfg_aae2ae32', config = '')
2025-07-03 16:08:03.612         db_cfg_name = f'db_cfg_aae2ae32'
2025-07-03 16:08:03.612         db_cfg_object = driver_config.register_database(name = db_cfg_name)
2025-07-03 16:08:03.612         db_cfg_object.server.value = srv_cfg.name
2025-07-03 16:08:03.612         db_cfg_object.database.value = str(act.db.db_path)
2025-07-03 16:08:03.612         if act.is_version('<6'):
2025-07-03 16:08:03.612             db_cfg_object.config.value = f"""
2025-07-03 16:08:03.612                 SubQueryConversion = true
2025-07-03 16:08:03.612             """
2025-07-03 16:08:03.612
2025-07-03 16:08:03.612         with connect(db_cfg_name, user = act.db.user, password = act.db.password) as con:
2025-07-03 16:08:03.612             ps, rs = None, None
2025-07-03 16:08:03.612             try:
2025-07-03 16:08:03.612                 cur = con.cursor()
2025-07-03 16:08:03.612                 ps = cur.prepare(test_sql)
2025-07-03 16:08:03.612
2025-07-03 16:08:03.612                 # Print explained plan with padding eash line by dots in order to see indentations:
2025-07-03 16:08:03.613                 print( '\n'.join([replace_leading(s) for s in ps.detailed_plan.split('\n')]) )
2025-07-03 16:08:03.613
2025-07-03 16:08:03.613                 # ::: NB ::: 'ps' returns data, i.e. this is SELECTABLE expression.
2025-07-03 16:08:03.613                 # We have to store result of cur.execute(<psInstance>) in order to
2025-07-03 16:08:03.613                 # close it explicitly.
2025-07-03 16:08:03.613                 # Otherwise AV can occur during Python garbage collection and this
2025-07-03 16:08:03.613                 # causes pytest to hang on its final point.
2025-07-03 16:08:03.613                 # Explained by hvlad, email 26.10.24 17:42
2025-07-03 16:08:03.613                 rs = cur.execute(ps)
2025-07-03 16:08:03.613                 for r in rs:
2025-07-03 16:08:03.613                     print(r[0])
2025-07-03 16:08:03.613             except DatabaseError as e:
2025-07-03 16:08:03.613                 print(e.__str__())
2025-07-03 16:08:03.613                 print(e.gds_codes)
2025-07-03 16:08:03.613             finally:
2025-07-03 16:08:03.613                 if rs:
2025-07-03 16:08:03.613                     rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
2025-07-03 16:08:03.614                 if ps:
2025-07-03 16:08:03.614                     ps.free()
2025-07-03 16:08:03.614
2025-07-03 16:08:03.614         act.expected_stdout = f"""
2025-07-03 16:08:03.614             Select Expression
2025-07-03 16:08:03.614             ....-> Aggregate
2025-07-03 16:08:03.614             ........-> Filter
2025-07-03 16:08:03.614             ............-> Hash Join (semi)
2025-07-03 16:08:03.614             ................-> Table "TEST1" as "A" Full Scan
2025-07-03 16:08:03.614             ................-> Record Buffer (record length: 82)
2025-07-03 16:08:03.614             ....................-> Filter
2025-07-03 16:08:03.614             ........................-> Hash Join (semi)
2025-07-03 16:08:03.614             ............................-> Table "TEST2" as "B" Full Scan
2025-07-03 16:08:03.614             ............................-> Record Buffer (record length: 57)
2025-07-03 16:08:03.614             ................................-> Filter
2025-07-03 16:08:03.614             ....................................-> Table "TEST3" as "C" Full Scan
2025-07-03 16:08:03.614             10
2025-07-03 16:08:03.614         """
2025-07-03 16:08:03.614         act.stdout = capsys.readouterr().out
2025-07-03 16:08:03.615 >       assert act.clean_stdout == act.clean_expected_stdout
2025-07-03 16:08:03.615 E       assert
2025-07-03 16:08:03.615 E           Select Expression
2025-07-03 16:08:03.615 E           ....-> Aggregate
2025-07-03 16:08:03.615 E           ........-> Filter
2025-07-03 16:08:03.615 E           ............-> Hash Join (semi)
2025-07-03 16:08:03.615 E         - ................-> Table "TEST1" as "A" Full Scan
2025-07-03 16:08:03.615 E         + ................-> Table "PUBLIC"."TEST1" as "A" Full Scan
2025-07-03 16:08:03.615 E           ................-> Record Buffer (record length: NN)
2025-07-03 16:08:03.615 E           ....................-> Filter
2025-07-03 16:08:03.615 E           ........................-> Hash Join (semi)
2025-07-03 16:08:03.615 E         - ............................-> Table "TEST2" as "B" Full Scan
2025-07-03 16:08:03.615 E         + ............................-> Table "PUBLIC"."TEST2" as "B" Full Scan
2025-07-03 16:08:03.615 E           ............................-> Record Buffer (record length: NN)
2025-07-03 16:08:03.615 E           ................................-> Filter
2025-07-03 16:08:03.615 E         - ....................................-> Table "TEST3" as "C" Full Scan
2025-07-03 16:08:03.615 E         + ....................................-> Table "PUBLIC"."TEST3" as "C" Full Scan
2025-07-03 16:08:03.616 E           10
2025-07-03 16:08:03.616
2025-07-03 16:08:03.616 tests\functional\tabloid\test_aae2ae32.py:157: AssertionError
2025-07-03 16:08:03.616 ---------------------------- Captured stdout setup ----------------------------
2025-07-03 16:08:03.616 Creating db: localhost:H:\QA\temp\qa2024.tmp\fbqa\test_12434\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.892 2025.07.03 af84a F F 941 481 2025.07.03 13:02:40.067 2025.07.03 13:02:41.008 2025.07.03 11:17:42.863 2025.07.03 11:17:43.344
2 6.0.0.892 2025.07.02 10f7d F F 949 483 2025.07.03 03:35:33.223 2025.07.03 03:35:34.172 2025.07.03 01:47:42.213 2025.07.03 01:47:42.696
3 6.0.0.889 2025.07.02 4b4e6 F F 943 535 2025.07.02 11:31:00.904 2025.07.02 11:31:01.847 2025.07.02 09:45:59.506 2025.07.02 09:46:00.041
4 6.0.0.889 2025.07.01 969ac F F 958 523 2025.07.02 03:37:42.995 2025.07.02 03:37:43.953 2025.07.02 01:49:56.697 2025.07.02 01:49:57.220
5 6.0.0.881 2025.06.27 7035d F F 930 485 2025.07.01 03:31:04.297 2025.07.01 03:31:05.227 2025.07.01 01:45:47.646 2025.07.01 01:45:48.131
6 6.0.0.877 2025.06.26 8e38f F F 964 502 2025.06.27 03:31:54.051 2025.06.27 03:31:55.015 2025.06.27 01:46:03.788 2025.06.27 01:46:04.290
7 6.0.0.876 2025.06.25 b1bec F F 944 476 2025.06.26 03:37:09.415 2025.06.26 03:37:10.359 2025.06.26 01:51:36.506 2025.06.26 01:51:36.982
8 6.0.0.863 2025.06.24 c3c20 F F 955 490 2025.06.25 08:21:32.134 2025.06.25 08:21:33.089 2025.06.25 01:45:38.252 2025.06.25 01:45:38.742
9 6.0.0.858 2025.06.24 cbbbf F F 945 474 2025.06.24 18:03:48.811 2025.06.24 18:03:49.756 2025.06.24 16:17:32.917 2025.06.24 16:17:33.391
10 6.0.0.858 2025.06.23 d377c F F 1007 481 2025.06.24 09:15:52.782 2025.06.24 09:15:53.789 2025.06.24 07:29:41.218 2025.06.24 07:29:41.699
11 6.0.0.854 2025.06.23 10b58 F F 941 489 2025.06.23 15:56:43.638 2025.06.23 15:56:44.579 2025.06.23 14:09:35.109 2025.06.23 14:09:35.598
12 6.0.0.849 2025.06.20 7b79c F F 951 474 2025.06.21 03:34:59.307 2025.06.21 03:35:00.258 2025.06.21 01:46:11.591 2025.06.21 01:46:12.065
13 6.0.0.848 2025.06.19 c483c F F 941 492 2025.06.20 03:34:43.093 2025.06.20 03:34:44.034 2025.06.20 01:45:57.811 2025.06.20 01:45:58.303
14 6.0.0.845 2025.06.18 20191 F F 1030 488 2025.06.19 03:34:07.154 2025.06.19 03:34:08.184 2025.06.19 01:45:37.674 2025.06.19 01:45:38.162
15 6.0.0.843 2025.06.16 995f4 F F 930 485 2025.06.18 03:33:53.792 2025.06.18 03:33:54.722 2025.06.18 01:45:12.459 2025.06.18 01:45:12.944
16 6.0.0.840 2025.06.14 29bca F F 954 484 2025.06.15 03:45:02.869 2025.06.15 03:45:03.823 2025.06.15 01:51:15.406 2025.06.15 01:51:15.890
17 6.0.0.838 2025.06.13 0e28a F F 984 523 2025.06.14 03:43:14.827 2025.06.14 03:43:15.811 2025.06.14 01:49:32.537 2025.06.14 01:49:33.060
18 6.0.0.834 2025.06.11 e889f F F 981 480 2025.06.12 03:38:56.223 2025.06.12 03:38:57.204 2025.06.12 01:48:34.599 2025.06.12 01:48:35.079
19 6.0.0.800 2025.06.10 1f226 P P 885 431 2025.06.11 02:23:28.046 2025.06.11 02:23:28.931 2025.06.11 01:11:31.053 2025.06.11 01:11:31.484
20 6.0.0.799 2025.06.07 be644 P P 908 442 2025.06.10 02:23:19.418 2025.06.10 02:23:20.326 2025.06.10 01:10:59.078 2025.06.10 01:10:59.520
21 6.0.0.797 2025.06.06 303e8 P P 904 444 2025.06.07 02:21:42.462 2025.06.07 02:21:43.366 2025.06.07 01:10:28.047 2025.06.07 01:10:28.491
22 6.0.0.795 2025.05.29 7a71a P P 939 431 2025.06.06 02:21:09.664 2025.06.06 02:21:10.603 2025.06.06 01:10:04.189 2025.06.06 01:10:04.620
23 6.0.0.792 2025.05.28 ee5a8 P P 900 440 2025.05.29 02:19:23.989 2025.05.29 02:19:24.889 2025.05.29 01:09:37.526 2025.05.29 01:09:37.966
24 6.0.0.791 2025.05.27 02db8 P P 894 431 2025.05.28 02:19:51.765 2025.05.28 02:19:52.659 2025.05.28 01:09:36.994 2025.05.28 01:09:37.425
25 6.0.0.789 2025.05.21 64051 P P 888 435 2025.05.25 02:19:33.257 2025.05.25 02:19:34.145 2025.05.25 01:09:47.050 2025.05.25 01:09:47.485
26 6.0.0.787 2025.05.20 230ad P P 890 429 2025.05.21 02:18:27.666 2025.05.21 02:18:28.556 2025.05.21 01:08:39.049 2025.05.21 01:08:39.478
27 6.0.0.783 2025.05.12 37320 P P 887 435 2025.05.19 02:18:03.781 2025.05.19 02:18:04.668 2025.05.19 01:08:56.247 2025.05.19 01:08:56.682
28 6.0.0.779 2025.05.11 136fa P P 903 438 2025.05.12 02:20:26.385 2025.05.12 02:20:27.288 2025.05.12 01:10:09.776 2025.05.12 01:10:10.214
29 6.0.0.778 2025.05.07 d735e P P 907 675 2025.05.11 02:19:50.977 2025.05.11 02:19:51.884 2025.05.11 01:09:42.925 2025.05.11 01:09:43.600
30 6.0.0.776 2025.05.06 007cd P P 932 442 2025.05.07 02:19:04.494 2025.05.07 02:19:05.426 2025.05.07 01:09:15.079 2025.05.07 01:09:15.521
31 6.0.0.770 2025.05.05 82c4a P P 887 447 2025.05.06 02:19:31.879 2025.05.06 02:19:32.766 2025.05.06 01:09:53.532 2025.05.06 01:09:53.979
32 6.0.0.767 2025.05.01 cdd29 P P 889 470 2025.05.02 02:19:56.678 2025.05.02 02:19:57.567 2025.05.02 01:10:20.877 2025.05.02 01:10:21.347
33 6.0.0.762 2025.04.30 5cb15 P P 893 433 2025.05.01 02:18:41.256 2025.05.01 02:18:42.149 2025.05.01 01:09:25.627 2025.05.01 01:09:26.060
34 6.0.0.755 2025.04.29 739c6 P P 878 433 2025.04.30 02:18:26.028 2025.04.30 02:18:26.906 2025.04.30 01:09:18.682 2025.04.30 01:09:19.115
35 6.0.0.753 2025.04.27 29ab3 P P 895 433 2025.04.29 02:18:35.663 2025.04.29 02:18:36.558 2025.04.29 01:09:28.616 2025.04.29 01:09:29.049
36 6.0.0.745 2025.04.21 78ad8 P P 897 470 2025.04.26 02:20:27.919 2025.04.26 02:20:28.816 2025.04.26 01:10:01.817 2025.04.26 01:10:02.287
37 6.0.0.744 2025.04.19 e883a P P 911 442 2025.04.20 02:19:43.396 2025.04.20 02:19:44.307 2025.04.20 01:09:36.472 2025.04.20 01:09:36.914
38 6.0.0.742 2025.04.17 abc3b P P 895 445 2025.04.19 02:19:15.777 2025.04.19 02:19:16.672 2025.04.19 01:09:21.560 2025.04.19 01:09:22.005
39 6.0.0.737 2025.04.16 fe52b P P 884 429 2025.04.17 02:19:34.725 2025.04.17 02:19:35.609 2025.04.17 01:09:48.103 2025.04.17 01:09:48.532

Elapsed time, ms. Chart for last 39 runs:

Last commits information (all timestamps in UTC):