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

LOG DETAILS:

2025-06-11 05:28:09.633
2025-06-11 05:28:09.633 act = <firebird.qa.plugin.Action object at [hex]>
2025-06-11 05:28:09.633 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-06-11 05:28:09.633
2025-06-11 05:28:09.633     @pytest.mark.version('>=5.0.2')
2025-06-11 05:28:09.633     def test_1(act: Action, capsys):
2025-06-11 05:28:09.633
2025-06-11 05:28:09.633         test_sql = """
2025-06-11 05:28:09.633             select v.a_id, v.b_id, v.c_id
2025-06-11 05:28:09.633             from v
2025-06-11 05:28:09.633             join t4 d on v.c_id = d.id
2025-06-11 05:28:09.633             where exists (
2025-06-11 05:28:09.633                 select 1
2025-06-11 05:28:09.633                 from t5 e where e.id = d.id
2025-06-11 05:28:09.633             )
2025-06-11 05:28:09.633         """
2025-06-11 05:28:09.633
2025-06-11 05:28:09.633         srv_cfg = driver_config.register_server(name = f'srv_cfg_8223', config = '')
2025-06-11 05:28:09.633         db_cfg_name = f'db_cfg_8223'
2025-06-11 05:28:09.633         db_cfg_object = driver_config.register_database(name = db_cfg_name)
2025-06-11 05:28:09.634         db_cfg_object.server.value = srv_cfg.name
2025-06-11 05:28:09.634         db_cfg_object.database.value = str(act.db.db_path)
2025-06-11 05:28:09.634         if act.is_version('<6'):
2025-06-11 05:28:09.634             db_cfg_object.config.value = f"""
2025-06-11 05:28:09.634                 SubQueryConversion = true
2025-06-11 05:28:09.634             """
2025-06-11 05:28:09.634
2025-06-11 05:28:09.634         with connect(db_cfg_name, user = act.db.user, password = act.db.password) as con:
2025-06-11 05:28:09.634             ps, rs = None, None
2025-06-11 05:28:09.634             try:
2025-06-11 05:28:09.634                 cur = con.cursor()
2025-06-11 05:28:09.634                 ps = cur.prepare(test_sql)
2025-06-11 05:28:09.634
2025-06-11 05:28:09.634                 # Print explained plan with padding eash line by dots in order to see indentations:
2025-06-11 05:28:09.634                 print( '\n'.join([replace_leading(s) for s in ps.detailed_plan.split('\n')]) )
2025-06-11 05:28:09.634
2025-06-11 05:28:09.634                 # ::: NB ::: 'ps' returns data, i.e. this is SELECTABLE expression.
2025-06-11 05:28:09.634                 # We have to store result of cur.execute(<psInstance>) in order to
2025-06-11 05:28:09.634                 # close it explicitly.
2025-06-11 05:28:09.635                 # Otherwise AV can occur during Python garbage collection and this
2025-06-11 05:28:09.635                 # causes pytest to hang on its final point.
2025-06-11 05:28:09.635                 # Explained by hvlad, email 26.10.24 17:42
2025-06-11 05:28:09.635                 rs = cur.execute(ps)
2025-06-11 05:28:09.635                 for r in rs:
2025-06-11 05:28:09.635                     print(r[0], r[1], r[2])
2025-06-11 05:28:09.635             except DatabaseError as e:
2025-06-11 05:28:09.635                 print(e.__str__())
2025-06-11 05:28:09.635                 print(e.gds_codes)
2025-06-11 05:28:09.635             finally:
2025-06-11 05:28:09.635                 if rs:
2025-06-11 05:28:09.635                     rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
2025-06-11 05:28:09.635                 if ps:
2025-06-11 05:28:09.635                     ps.free()
2025-06-11 05:28:09.635
2025-06-11 05:28:09.635
2025-06-11 05:28:09.635         act.expected_stdout = f"""
2025-06-11 05:28:09.635             Select Expression
2025-06-11 05:28:09.635             ....-> Filter
2025-06-11 05:28:09.636             ........-> Hash Join (semi)
2025-06-11 05:28:09.636             ............-> Filter
2025-06-11 05:28:09.636             ................-> Hash Join (inner)
2025-06-11 05:28:09.636             ....................-> Nested Loop Join (outer)
2025-06-11 05:28:09.636             ........................-> Nested Loop Join (outer)
2025-06-11 05:28:09.636             ............................-> Table "T1" as "V A" Full Scan
2025-06-11 05:28:09.636             ............................-> Filter
2025-06-11 05:28:09.636             ................................-> Table "T2" as "V B" Full Scan
2025-06-11 05:28:09.636             ........................-> Filter
2025-06-11 05:28:09.636             ............................-> Table "T3" as "V C" Full Scan
2025-06-11 05:28:09.636             ....................-> Record Buffer (record length: 25)
2025-06-11 05:28:09.636             ........................-> Table "T4" as "D" Full Scan
2025-06-11 05:28:09.636             ............-> Record Buffer (record length: 25)
2025-06-11 05:28:09.636             ................-> Table "T5" as "E" Full Scan
2025-06-11 05:28:09.636             1 1 1
2025-06-11 05:28:09.636         """
2025-06-11 05:28:09.636         act.stdout = capsys.readouterr().out
2025-06-11 05:28:09.636 >       assert act.clean_stdout == act.clean_expected_stdout
2025-06-11 05:28:09.636 E       assert
2025-06-11 05:28:09.637 E           Select Expression
2025-06-11 05:28:09.637 E         + ....-> Nested Loop Join (semi)
2025-06-11 05:28:09.637 E         - ....-> Filter
2025-06-11 05:28:09.637 E         - ........-> Hash Join (semi)
2025-06-11 05:28:09.637 E         - ............-> Filter
2025-06-11 05:28:09.637 E         + ........-> Filter
2025-06-11 05:28:09.637 E         - ................-> Hash Join (inner)
2025-06-11 05:28:09.637 E         + ............-> Hash Join (inner)
2025-06-11 05:28:09.637 E         + ................-> Nested Loop Join (outer)
2025-06-11 05:28:09.637 E           ....................-> Nested Loop Join (outer)
2025-06-11 05:28:09.637 E         - ........................-> Nested Loop Join (outer)
2025-06-11 05:28:09.637 E         - ............................-> Table "T1" as "V A" Full Scan
2025-06-11 05:28:09.637 E         + ........................-> Table "T1" as "V A" Full Scan
2025-06-11 05:28:09.637 E         - ............................-> Filter
2025-06-11 05:28:09.637 E         - ................................-> Table "T2" as "V B" Full Scan
2025-06-11 05:28:09.637 E           ........................-> Filter
2025-06-11 05:28:09.637 E         - ............................-> Table "T3" as "V C" Full Scan
2025-06-11 05:28:09.638 E         + ............................-> Table "T2" as "V B" Full Scan
2025-06-11 05:28:09.638 E         + ....................-> Filter
2025-06-11 05:28:09.638 E         + ........................-> Table "T3" as "V C" Full Scan
2025-06-11 05:28:09.638 E         - ....................-> Record Buffer (record length: NN)
2025-06-11 05:28:09.638 E         + ................-> Record Buffer (record length: NN)
2025-06-11 05:28:09.638 E         - ........................-> Table "T4" as "D" Full Scan
2025-06-11 05:28:09.638 E         + ....................-> Table "T4" as "D" Full Scan
2025-06-11 05:28:09.638 E         - ............-> Record Buffer (record length: NN)
2025-06-11 05:28:09.638 E         + ........-> Filter
2025-06-11 05:28:09.638 E         + ............-> Filter (preliminary)
2025-06-11 05:28:09.638 E           ................-> Table "T5" as "E" Full Scan
2025-06-11 05:28:09.638 E           1 1 1
2025-06-11 05:28:09.638
2025-06-11 05:28:09.638 tests\bugs\gh_8223_test.py:152: AssertionError
2025-06-11 05:28:09.638 ---------------------------- Captured stdout setup ----------------------------
2025-06-11 05:28:09.638 Creating db: localhost:H:\QA\temp\qa2024.tmp\fbqa\test_11724\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 "T1" as "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 "T2" as "V B" Full Scan
E         + ....................-> Filter
E         + ........................-> Table "T3" as "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 "T4" as "D" Full Scan
E         - ............-> Record Buffer (record length: NN)
E         + ........-> Filter
E         + ............-> Filter (preliminary)
E           ................-> Table "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.892 2025.07.02 10f7d F F 665 461 2025.07.03 03:15:03.716 2025.07.03 03:15:04.381 2025.07.03 01:30:26.100 2025.07.03 01:30:26.561
2 6.0.0.889 2025.07.02 4b4e6 F F 658 461 2025.07.02 11:12:35.820 2025.07.02 11:12:36.478 2025.07.02 09:31:01.070 2025.07.02 09:31:01.531
3 6.0.0.889 2025.07.01 969ac F F 661 449 2025.07.02 03:18:10.974 2025.07.02 03:18:11.635 2025.07.02 01:33:18.591 2025.07.02 01:33:19.040
4 6.0.0.881 2025.06.27 7035d F F 666 466 2025.07.01 03:12:00.148 2025.07.01 03:12:00.814 2025.07.01 01:30:10.060 2025.07.01 01:30:10.526
5 6.0.0.877 2025.06.26 8e38f F F 668 466 2025.06.27 03:13:21.744 2025.06.27 03:13:22.412 2025.06.27 01:30:55.518 2025.06.27 01:30:55.984
6 6.0.0.876 2025.06.25 b1bec F F 669 453 2025.06.26 03:18:40.196 2025.06.26 03:18:40.865 2025.06.26 01:36:34.438 2025.06.26 01:36:34.891
7 6.0.0.863 2025.06.24 c3c20 F F 693 463 2025.06.25 08:02:49.628 2025.06.25 08:02:50.321 2025.06.25 01:30:35.902 2025.06.25 01:30:36.365
8 6.0.0.858 2025.06.24 cbbbf F F 684 464 2025.06.24 17:45:21.904 2025.06.24 17:45:22.588 2025.06.24 16:02:33.705 2025.06.24 16:02:34.169
9 6.0.0.858 2025.06.23 d377c F F 679 460 2025.06.24 08:57:23.572 2025.06.24 08:57:24.251 2025.06.24 07:14:56.097 2025.06.24 07:14:56.557
10 6.0.0.854 2025.06.23 10b58 F F 652 464 2025.06.23 15:38:15.741 2025.06.23 15:38:16.393 2025.06.23 13:54:28.825 2025.06.23 13:54:29.289
11 6.0.0.849 2025.06.20 7b79c F F 672 462 2025.06.21 03:16:34.528 2025.06.21 03:16:35.200 2025.06.21 01:31:08.394 2025.06.21 01:31:08.856
12 6.0.0.848 2025.06.19 c483c F F 661 465 2025.06.20 03:16:12.098 2025.06.20 03:16:12.759 2025.06.20 01:30:53.684 2025.06.20 01:30:54.149
13 6.0.0.845 2025.06.18 20191 F F 665 488 2025.06.19 03:15:50.148 2025.06.19 03:15:50.813 2025.06.19 01:30:41.083 2025.06.19 01:30:41.571
14 6.0.0.843 2025.06.16 995f4 F F 662 462 2025.06.18 03:15:37.454 2025.06.18 03:15:38.116 2025.06.18 01:30:23.268 2025.06.18 01:30:23.730
15 6.0.0.840 2025.06.14 29bca F F 697 452 2025.06.15 03:24:07.528 2025.06.15 03:24:08.225 2025.06.15 01:33:26.538 2025.06.15 01:33:26.990
16 6.0.0.838 2025.06.13 0e28a F F 699 456 2025.06.14 03:21:51.137 2025.06.14 03:21:51.836 2025.06.14 01:31:45.780 2025.06.14 01:31:46.236
17 6.0.0.834 2025.06.11 e889f F F 664 453 2025.06.12 03:19:23.244 2025.06.12 03:19:23.908 2025.06.12 01:32:17.154 2025.06.12 01:32:17.607
18 6.0.0.800 2025.06.10 1f226 F F 643 676 2025.06.11 02:04:21.418 2025.06.11 02:04:22.061 2025.06.11 00:55:32.703 2025.06.11 00:55:33.379
19 6.0.0.799 2025.06.07 be644 F F 642 433 2025.06.10 02:03:59.971 2025.06.10 02:04:00.613 2025.06.10 00:55:10.124 2025.06.10 00:55:10.557
20 6.0.0.797 2025.06.06 303e8 F F 627 426 2025.06.07 02:02:48.652 2025.06.07 02:02:49.279 2025.06.07 00:54:58.203 2025.06.07 00:54:58.629
21 6.0.0.795 2025.05.29 7a71a F F 627 437 2025.06.06 02:02:38.992 2025.06.06 02:02:39.619 2025.06.06 00:54:56.162 2025.06.06 00:54:56.599
22 6.0.0.792 2025.05.28 ee5a8 F F 630 436 2025.05.29 02:01:44.860 2025.05.29 02:01:45.490 2025.05.29 00:55:02.500 2025.05.29 00:55:02.936
23 6.0.0.791 2025.05.27 02db8 F F 612 436 2025.05.28 02:02:13.824 2025.05.28 02:02:14.436 2025.05.28 00:54:45.409 2025.05.28 00:54:45.845
24 6.0.0.789 2025.05.21 64051 F F 611 430 2025.05.25 02:01:56.801 2025.05.25 02:01:57.412 2025.05.25 00:55:10.969 2025.05.25 00:55:11.399
25 6.0.0.787 2025.05.20 230ad F F 613 435 2025.05.21 02:00:52.855 2025.05.21 02:00:53.468 2025.05.21 00:54:20.422 2025.05.21 00:54:20.857
26 6.0.0.783 2025.05.12 37320 F F 622 463 2025.05.19 02:00:39.340 2025.05.19 02:00:39.962 2025.05.19 00:54:27.532 2025.05.19 00:54:27.995
27 6.0.0.779 2025.05.11 136fa F F 630 438 2025.05.12 02:02:47.596 2025.05.12 02:02:48.226 2025.05.12 00:55:05.249 2025.05.12 00:55:05.687
28 6.0.0.778 2025.05.07 d735e F F 619 459 2025.05.11 02:02:12.183 2025.05.11 02:02:12.802 2025.05.11 00:55:18.941 2025.05.11 00:55:19.400
29 6.0.0.776 2025.05.06 007cd F F 611 433 2025.05.07 02:01:26.321 2025.05.07 02:01:26.932 2025.05.07 00:54:56.372 2025.05.07 00:54:56.805
30 6.0.0.770 2025.05.05 82c4a F F 609 433 2025.05.06 02:01:45.020 2025.05.06 02:01:45.629 2025.05.06 00:55:02.873 2025.05.06 00:55:03.306
31 6.0.0.767 2025.05.01 cdd29 F F 624 423 2025.05.02 02:02:21.261 2025.05.02 02:02:21.885 2025.05.02 00:55:53.335 2025.05.02 00:55:53.758
32 6.0.0.762 2025.04.30 5cb15 F F 638 426 2025.05.01 02:00:48.058 2025.05.01 02:00:48.696 2025.05.01 00:55:14.528 2025.05.01 00:55:14.954
33 6.0.0.755 2025.04.29 739c6 F F 642 418 2025.04.30 02:01:01.289 2025.04.30 02:01:01.931 2025.04.30 00:54:57.000 2025.04.30 00:54:57.418
34 6.0.0.753 2025.04.27 29ab3 F F 622 460 2025.04.29 02:01:11.763 2025.04.29 02:01:12.385 2025.04.29 00:55:05.210 2025.04.29 00:55:05.670
35 6.0.0.745 2025.04.21 78ad8 F F 614 434 2025.04.26 02:02:37.433 2025.04.26 02:02:38.047 2025.04.26 00:55:21.954 2025.04.26 00:55:22.388
36 6.0.0.744 2025.04.19 e883a F F 633 435 2025.04.20 02:02:04.261 2025.04.20 02:02:04.894 2025.04.20 00:55:14.683 2025.04.20 00:55:15.118
37 6.0.0.742 2025.04.17 abc3b F F 629 427 2025.04.19 02:01:32.309 2025.04.19 02:01:32.938 2025.04.19 00:54:49.187 2025.04.19 00:54:49.614
38 6.0.0.737 2025.04.16 fe52b F F 612 573 2025.04.17 02:01:56.099 2025.04.17 02:01:56.711 2025.04.17 00:55:02.517 2025.04.17 00:55:03.090

Elapsed time, ms. Chart for last 38 runs:

Last commits information (all timestamps in UTC):