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
  + ....-> Nested Loop Join (semi)
  - ....-> Filter
  - ........-> Hash Join (semi)
  - ............-> Filter
  + ........-> Filter
  - ................-> Hash Join (inner)
  + ............-> Hash Join (inner)
  + ................-> Nested Loop Join (outer)
    ....................-> Nested Loop Join (outer)
  - ........................-> Nested Loop Join (outer)
  - ............................-> Table "T1" as "V A" Full Scan
  + ........................-> Table "PUBLIC"."T1" as "PUBLIC"."V" "A" Full Scan
  - ............................-> Filter
  - ................................-> Table "T2" as "V B" Full Scan
    ........................-> Filter
  - ............................-> Table "T3" as "V C" Full Scan
  + ............................-> Table "PUBLIC"."T2" as "PUBLIC"."V" "B" Full Scan
  + ....................-> Filter
  + ........................-> Table "PUBLIC"."T3" as "PUBLIC"."V" "C" Full Scan
  - ....................-> Record Buffer (record length: NN)
  + ................-> Record Buffer (record length: NN)
  - ........................-> Table "T4" as "D" Full Scan
  + ....................-> Table "PUBLIC"."T4" as "D" Full Scan
  - ............-> Record Buffer (record length: NN)
  + ........-> Filter
  + ............-> Filter (preliminary)
  - ................-> Table "T5" as "E" Full Scan
  + ................-> Table "PUBLIC"."T5" as "E" Full Scan
    1 1 1

LOG DETAILS:

2025-06-21 05:35:21.428
2025-06-21 05:35:21.433 act = <firebird.qa.plugin.Action object at [hex]>
2025-06-21 05:35:21.439 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-06-21 05:35:21.444
2025-06-21 05:35:21.450 @pytest.mark.version('>=5.0.2')
2025-06-21 05:35:21.459 def test_1(act: Action, capsys):
2025-06-21 05:35:21.467
2025-06-21 05:35:21.473 test_sql = """
2025-06-21 05:35:21.479 select v.a_id, v.b_id, v.c_id
2025-06-21 05:35:21.484 from v
2025-06-21 05:35:21.490 join t4 d on v.c_id = d.id
2025-06-21 05:35:21.495 where exists (
2025-06-21 05:35:21.501 select 1
2025-06-21 05:35:21.508 from t5 e where e.id = d.id
2025-06-21 05:35:21.515 )
2025-06-21 05:35:21.521 """
2025-06-21 05:35:21.528
2025-06-21 05:35:21.535 srv_cfg = driver_config.register_server(name = f'srv_cfg_8223', config = '')
2025-06-21 05:35:21.542 db_cfg_name = f'db_cfg_8223'
2025-06-21 05:35:21.549 db_cfg_object = driver_config.register_database(name = db_cfg_name)
2025-06-21 05:35:21.555 db_cfg_object.server.value = srv_cfg.name
2025-06-21 05:35:21.562 db_cfg_object.database.value = str(act.db.db_path)
2025-06-21 05:35:21.568 if act.is_version('<6'):
2025-06-21 05:35:21.573 db_cfg_object.config.value = f"""
2025-06-21 05:35:21.578 SubQueryConversion = true
2025-06-21 05:35:21.589 """
2025-06-21 05:35:21.598
2025-06-21 05:35:21.605 with connect(db_cfg_name, user = act.db.user, password = act.db.password) as con:
2025-06-21 05:35:21.611 ps, rs = None, None
2025-06-21 05:35:21.617 try:
2025-06-21 05:35:21.623 cur = con.cursor()
2025-06-21 05:35:21.631 ps = cur.prepare(test_sql)
2025-06-21 05:35:21.642
2025-06-21 05:35:21.650 # Print explained plan with padding eash line by dots in order to see indentations:
2025-06-21 05:35:21.657 print( '\n'.join([replace_leading(s) for s in ps.detailed_plan.split('\n')]) )
2025-06-21 05:35:21.666
2025-06-21 05:35:21.677 # ::: NB ::: 'ps' returns data, i.e. this is SELECTABLE expression.
2025-06-21 05:35:21.688 # We have to store result of cur.execute(<psInstance>) in order to
2025-06-21 05:35:21.697 # close it explicitly.
2025-06-21 05:35:21.707 # Otherwise AV can occur during Python garbage collection and this
2025-06-21 05:35:21.720 # causes pytest to hang on its final point.
2025-06-21 05:35:21.731 # Explained by hvlad, email 26.10.24 17:42
2025-06-21 05:35:21.741 rs = cur.execute(ps)
2025-06-21 05:35:21.749 for r in rs:
2025-06-21 05:35:21.759 print(r[0], r[1], r[2])
2025-06-21 05:35:21.769 except DatabaseError as e:
2025-06-21 05:35:21.778 print(e.__str__())
2025-06-21 05:35:21.785 print(e.gds_codes)
2025-06-21 05:35:21.791 finally:
2025-06-21 05:35:21.810 if rs:
2025-06-21 05:35:21.820 rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
2025-06-21 05:35:21.828 if ps:
2025-06-21 05:35:21.835 ps.free()
2025-06-21 05:35:21.841
2025-06-21 05:35:21.845
2025-06-21 05:35:21.851 act.expected_stdout = f"""
2025-06-21 05:35:21.857 Select Expression
2025-06-21 05:35:21.863 ....-> Filter
2025-06-21 05:35:21.869 ........-> Hash Join (semi)
2025-06-21 05:35:21.876 ............-> Filter
2025-06-21 05:35:21.883 ................-> Hash Join (inner)
2025-06-21 05:35:21.888 ....................-> Nested Loop Join (outer)
2025-06-21 05:35:21.894 ........................-> Nested Loop Join (outer)
2025-06-21 05:35:21.900 ............................-> Table "T1" as "V A" Full Scan
2025-06-21 05:35:21.906 ............................-> Filter
2025-06-21 05:35:21.916 ................................-> Table "T2" as "V B" Full Scan
2025-06-21 05:35:21.925 ........................-> Filter
2025-06-21 05:35:21.932 ............................-> Table "T3" as "V C" Full Scan
2025-06-21 05:35:21.939 ....................-> Record Buffer (record length: 25)
2025-06-21 05:35:21.945 ........................-> Table "T4" as "D" Full Scan
2025-06-21 05:35:21.951 ............-> Record Buffer (record length: 25)
2025-06-21 05:35:21.957 ................-> Table "T5" as "E" Full Scan
2025-06-21 05:35:21.963 1 1 1
2025-06-21 05:35:21.969 """
2025-06-21 05:35:21.974 act.stdout = capsys.readouterr().out
2025-06-21 05:35:21.983 >       assert act.clean_stdout == act.clean_expected_stdout
2025-06-21 05:35:21.990 E       assert
2025-06-21 05:35:21.997 E           Select Expression
2025-06-21 05:35:22.004 E         + ....-> Nested Loop Join (semi)
2025-06-21 05:35:22.017 E         - ....-> Filter
2025-06-21 05:35:22.028 E         - ........-> Hash Join (semi)
2025-06-21 05:35:22.038 E         - ............-> Filter
2025-06-21 05:35:22.060 E         + ........-> Filter
2025-06-21 05:35:22.069 E         - ................-> Hash Join (inner)
2025-06-21 05:35:22.083 E         + ............-> Hash Join (inner)
2025-06-21 05:35:22.088 E         + ................-> Nested Loop Join (outer)
2025-06-21 05:35:22.092 E           ....................-> Nested Loop Join (outer)
2025-06-21 05:35:22.097 E         - ........................-> Nested Loop Join (outer)
2025-06-21 05:35:22.103 E         - ............................-> Table "T1" as "V A" Full Scan
2025-06-21 05:35:22.113 E         + ........................-> Table "PUBLIC"."T1" as "PUBLIC"."V" "A" Full Scan
2025-06-21 05:35:22.122 E         - ............................-> Filter
2025-06-21 05:35:22.127 E         - ................................-> Table "T2" as "V B" Full Scan
2025-06-21 05:35:22.131 E           ........................-> Filter
2025-06-21 05:35:22.136 E         - ............................-> Table "T3" as "V C" Full Scan
2025-06-21 05:35:22.145 E         + ............................-> Table "PUBLIC"."T2" as "PUBLIC"."V" "B" Full Scan
2025-06-21 05:35:22.154 E         + ....................-> Filter
2025-06-21 05:35:22.159 E         + ........................-> Table "PUBLIC"."T3" as "PUBLIC"."V" "C" Full Scan
2025-06-21 05:35:22.163 E         - ....................-> Record Buffer (record length: NN)
2025-06-21 05:35:22.172 E         + ................-> Record Buffer (record length: NN)
2025-06-21 05:35:22.177 E         - ........................-> Table "T4" as "D" Full Scan
2025-06-21 05:35:22.187 E         + ....................-> Table "PUBLIC"."T4" as "D" Full Scan
2025-06-21 05:35:22.202 E         - ............-> Record Buffer (record length: NN)
2025-06-21 05:35:22.210 E         + ........-> Filter
2025-06-21 05:35:22.218 E         + ............-> Filter (preliminary)
2025-06-21 05:35:22.224 E         - ................-> Table "T5" as "E" Full Scan
2025-06-21 05:35:22.231 E         + ................-> Table "PUBLIC"."T5" as "E" Full Scan
2025-06-21 05:35:22.243 E           1 1 1
2025-06-21 05:35:22.250
2025-06-21 05:35:22.257 tests/bugs/gh_8223_test.py:152: AssertionError
2025-06-21 05:35:22.265 ---------------------------- Captured stdout setup -----------------------------
2025-06-21 05:35:22.272 Creating db: localhost:/var/tmp/qa_2024/test_11703/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 v.a_id, v.b_id, v.c_id
            from v
            join t4 d on v.c_id = d.id
            where exists (
                select 1
                from t5 e where e.id = d.id
            )
        """
    
        srv_cfg = driver_config.register_server(name = f'srv_cfg_8223', config = '')
        db_cfg_name = f'db_cfg_8223'
        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], r[1], r[2])
            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
            ....-> Filter
            ........-> Hash Join (semi)
            ............-> Filter
            ................-> Hash Join (inner)
            ....................-> Nested Loop Join (outer)
            ........................-> Nested Loop Join (outer)
            ............................-> Table "T1" as "V A" Full Scan
            ............................-> Filter
            ................................-> Table "T2" as "V B" Full Scan
            ........................-> Filter
            ............................-> Table "T3" as "V C" Full Scan
            ....................-> Record Buffer (record length: 25)
            ........................-> Table "T4" as "D" Full Scan
            ............-> Record Buffer (record length: 25)
            ................-> Table "T5" as "E" Full Scan
            1 1 1
        """
        act.stdout = capsys.readouterr().out
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E           Select Expression
E         + ....-> Nested Loop Join (semi)
E         - ....-> Filter
E         - ........-> Hash Join (semi)
E         - ............-> Filter
E         + ........-> Filter
E         - ................-> Hash Join (inner)
E         + ............-> Hash Join (inner)
E         + ................-> Nested Loop Join (outer)
E           ....................-> Nested Loop Join (outer)
E         - ........................-> Nested Loop Join (outer)
E         - ............................-> Table "T1" as "V A" Full Scan
E         + ........................-> Table "PUBLIC"."T1" as "PUBLIC"."V" "A" Full Scan
E         - ............................-> Filter
E         - ................................-> Table "T2" as "V B" Full Scan
E           ........................-> Filter
E         - ............................-> Table "T3" as "V C" Full Scan
E         + ............................-> Table "PUBLIC"."T2" as "PUBLIC"."V" "B" Full Scan
E         + ....................-> Filter
E         + ........................-> Table "PUBLIC"."T3" as "PUBLIC"."V" "C" Full Scan
E         - ....................-> Record Buffer (record length: NN)
E         + ................-> Record Buffer (record length: NN)
E         - ........................-> Table "T4" as "D" Full Scan
E         + ....................-> Table "PUBLIC"."T4" as "D" Full Scan
E         - ............-> Record Buffer (record length: NN)
E         + ........-> Filter
E         + ............-> Filter (preliminary)
E         - ................-> Table "T5" as "E" Full Scan
E         + ................-> Table "PUBLIC"."T5" as "E" Full Scan
E           1 1 1

tests/bugs/gh_8223_test.py:152: 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.889 2025.07.01 969ac F F 693 410 2025.07.02 02:14:16.562 2025.07.02 02:14:17.255 2025.07.01 23:24:28.166 2025.07.01 23:24:28.576
2 6.0.0.884 2025.06.30 f7e5f F F 715 697 2025.07.01 02:14:32.316 2025.07.01 02:14:33.031 2025.06.30 23:33:39.201 2025.06.30 23:33:39.898
3 6.0.0.881 2025.06.27 7035d F F 849 577 2025.06.30 02:04:50.266 2025.06.30 02:04:51.115 2025.06.29 23:20:48.194 2025.06.29 23:20:48.771
4 6.0.0.877 2025.06.26 8e38f F F 683 671 2025.06.27 01:43:48.677 2025.06.27 01:43:49.360 2025.06.26 23:11:43.647 2025.06.26 23:11:44.318
5 6.0.0.876 2025.06.25 b1bec F F 779 600 2025.06.26 01:47:39.272 2025.06.26 01:47:40.051 2025.06.25 23:13:39.481 2025.06.25 23:13:40.081
6 6.0.0.863 2025.06.24 c3c20 F F 823 604 2025.06.25 01:47:56.729 2025.06.25 01:47:57.552 2025.06.24 23:13:26.474 2025.06.24 23:13:27.078
7 6.0.0.858 2025.06.23 8d6f7 F F 733 618 2025.06.24 01:48:18.937 2025.06.24 01:48:19.670 2025.06.23 23:13:33.572 2025.06.23 23:13:34.190
8 6.0.0.849 2025.06.20 7b79c F F 663 373 2025.06.21 01:59:51.388 2025.06.21 01:59:52.051 2025.06.20 23:22:42.406 2025.06.20 23:22:42.779
9 6.0.0.848 2025.06.19 c483c F F 663 423 2025.06.20 01:56:12.186 2025.06.20 01:56:12.849 2025.06.19 23:19:29.858 2025.06.19 23:19:30.281
10 6.0.0.845 2025.06.18 22b12 F F 858 608 2025.06.19 02:04:51.349 2025.06.19 02:04:52.207 2025.06.18 23:22:43.751 2025.06.18 23:22:44.359
11 6.0.0.843 2025.06.16 995f4 F F 749 426 2025.06.18 02:03:06.775 2025.06.18 02:03:07.524 2025.06.17 23:24:30.862 2025.06.17 23:24:31.288
12 6.0.0.840 2025.06.14 29bca F F 733 733 2025.06.16 01:54:55.386 2025.06.16 01:54:56.119 2025.06.15 23:16:58.858 2025.06.15 23:16:59.591
13 6.0.0.838 2025.06.13 0e28a F F 758 684 2025.06.14 02:07:58.563 2025.06.14 02:07:59.321 2025.06.13 23:24:29.370 2025.06.13 23:24:30.054
14 6.0.0.835 2025.06.12 2cf29 F F 713 463 2025.06.13 02:07:53.543 2025.06.13 02:07:54.256 2025.06.12 23:28:35.627 2025.06.12 23:28:36.090
15 6.0.0.834 2025.06.11 e889f F F 701 640 2025.06.12 02:03:07.769 2025.06.12 02:03:08.470 2025.06.11 23:24:47.974 2025.06.11 23:24:48.614
16 6.0.0.800 2025.06.10 1f226 F F 721 548 2025.06.11 00:31:20.881 2025.06.11 00:31:21.602 2025.06.10 22:23:49.687 2025.06.10 22:23:50.235
17 6.0.0.799 2025.06.07 be644 F F 1172 698 2025.06.10 00:33:32.022 2025.06.10 00:33:33.194 2025.06.09 22:23:29.333 2025.06.09 22:23:30.031
18 6.0.0.797 2025.06.06 303e8 F F 1281 688 2025.06.07 00:36:46.610 2025.06.07 00:36:47.891 2025.06.06 22:23:02.915 2025.06.06 22:23:03.603
19 6.0.0.795 2025.05.29 7a71a F F 613 766 2025.06.06 00:31:10.370 2025.06.06 00:31:10.983 2025.06.05 22:22:09.271 2025.06.05 22:22:10.037
20 6.0.0.792 2025.05.28 b4327 F F 760 840 2025.05.29 00:45:26.227 2025.05.29 00:45:26.987 2025.05.28 22:25:18.385 2025.05.28 22:25:19.225
21 6.0.0.791 2025.05.27 02db8 F F 702 772 2025.05.28 00:43:30.577 2025.05.28 00:43:31.279 2025.05.27 22:24:21.443 2025.05.27 22:24:22.215
22 6.0.0.789 2025.05.21 64051 F F 1188 806 2025.05.25 00:35:47.682 2025.05.25 00:35:48.870 2025.05.24 22:23:26.827 2025.05.24 22:23:27.633
23 6.0.0.787 2025.05.20 230ad F F 746 894 2025.05.21 00:33:10.962 2025.05.21 00:33:11.708 2025.05.20 22:21:51.421 2025.05.20 22:21:52.315
24 6.0.0.783 2025.05.12 37320 F F 782 537 2025.05.19 12:05:53.437 2025.05.19 12:05:54.219 2025.05.19 10:10:03.877 2025.05.19 10:10:04.414
25 6.0.0.779 2025.05.11 136fa F F 688 658 2025.05.12 00:27:58.837 2025.05.12 00:27:59.525 2025.05.11 22:21:18.081 2025.05.11 22:21:18.739
26 6.0.0.778 2025.05.07 d735e F F 682 761 2025.05.08 00:30:03.096 2025.05.08 00:30:03.778 2025.05.07 22:20:00.107 2025.05.07 22:20:00.868
27 6.0.0.776 2025.05.06 007cd F F 723 585 2025.05.07 00:24:24.075 2025.05.07 00:24:24.798 2025.05.06 22:19:50.980 2025.05.06 22:19:51.565
28 6.0.0.770 2025.05.05 82c4a F F 712 765 2025.05.06 00:23:39.115 2025.05.06 00:23:39.827 2025.05.05 22:18:55.033 2025.05.05 22:18:55.798
29 6.0.0.767 2025.05.01 cdd29 F F 637 728 2025.05.02 00:20:24.278 2025.05.02 00:20:24.915 2025.05.01 22:18:10.323 2025.05.01 22:18:11.051
30 6.0.0.762 2025.04.30 5cb15 F F 745 388 2025.05.01 00:16:32.290 2025.05.01 00:16:33.035 2025.04.30 22:17:03.570 2025.04.30 22:17:03.958
31 6.0.0.755 2025.04.29 739c6 F F 1209 845 2025.04.30 00:20:10.270 2025.04.30 00:20:11.479 2025.04.29 22:18:13.291 2025.04.29 22:18:14.136
32 6.0.0.753 2025.04.27 29ab3 F F 1107 381 2025.04.28 00:21:41.751 2025.04.28 00:21:42.858 2025.04.27 22:17:33.914 2025.04.27 22:17:34.295
33 6.0.0.745 2025.04.21 78ad8 F F 713 610 2025.04.26 00:18:18.673 2025.04.26 00:18:19.386 2025.04.25 22:19:26.063 2025.04.25 22:19:26.673
34 6.0.0.744 2025.04.19 e883a F F 1204 639 2025.04.20 00:20:24.120 2025.04.20 00:20:25.324 2025.04.19 22:18:38.384 2025.04.19 22:18:39.023
35 6.0.0.742 2025.04.17 abc3b F F 709 730 2025.04.19 00:22:23.240 2025.04.19 00:22:23.949 2025.04.18 22:19:00.207 2025.04.18 22:19:00.937
36 6.0.0.737 2025.04.16 fe52b F F 1163 1202 2025.04.17 00:18:03.555 2025.04.17 00:18:04.718 2025.04.16 22:19:02.002 2025.04.16 22:19:03.204

Elapsed time, ms. Chart for last 36 runs:

Last commits information (all timestamps in UTC):