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
    ....-> First N Records
    ........-> Filter
    ............-> Hash Join (semi)
    ................-> Refetch
    ....................-> Sort (record length: NN, key length: NN)
  - ........................-> Table "DEPARTMENT" as "D" Full Scan
  + ........................-> Table "PUBLIC"."DEPARTMENT" as "D" Full Scan
    ................-> Record Buffer (record length: NN)
  - ....................-> Table "EMPLOYEE" as "E" Full Scan
  + ....................-> Table "PUBLIC"."EMPLOYEE" as "E" Full Scan
    2 d2

LOG DETAILS:

2025-07-03 05:19:27.318
2025-07-03 05:19:27.330 act = <firebird.qa.plugin.Action object at [hex]>
2025-07-03 05:19:27.339 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-07-03 05:19:27.350
2025-07-03 05:19:27.360 @pytest.mark.version('>=5.0.2')
2025-07-03 05:19:27.368 def test_1(act: Action, capsys):
2025-07-03 05:19:27.374
2025-07-03 05:19:27.379 test_sql = """
2025-07-03 05:19:27.387 select d.dept_no, d.dept_name from department d
2025-07-03 05:19:27.394 where exists(select * from employee e where e.dept_no = d.dept_no)
2025-07-03 05:19:27.399 order by dept_no rows 1
2025-07-03 05:19:27.404 """
2025-07-03 05:19:27.409
2025-07-03 05:19:27.414 srv_cfg = driver_config.register_server(name = f'srv_cfg_8225', config = '')
2025-07-03 05:19:27.418 db_cfg_name = f'db_cfg_8225'
2025-07-03 05:19:27.423 db_cfg_object = driver_config.register_database(name = db_cfg_name)
2025-07-03 05:19:27.428 db_cfg_object.server.value = srv_cfg.name
2025-07-03 05:19:27.434 db_cfg_object.database.value = str(act.db.db_path)
2025-07-03 05:19:27.443 if act.is_version('<6'):
2025-07-03 05:19:27.451 db_cfg_object.config.value = f"""
2025-07-03 05:19:27.458 SubQueryConversion = true
2025-07-03 05:19:27.468 """
2025-07-03 05:19:27.476
2025-07-03 05:19:27.484 with connect(db_cfg_name, user = act.db.user, password = act.db.password) as con:
2025-07-03 05:19:27.490 cur = con.cursor()
2025-07-03 05:19:27.500 ps, rs = None, None
2025-07-03 05:19:27.510 try:
2025-07-03 05:19:27.519 ps = cur.prepare(test_sql)
2025-07-03 05:19:27.531 print( '\n'.join([replace_leading(s) for s in ps.detailed_plan.split('\n')]) )
2025-07-03 05:19:27.539
2025-07-03 05:19:27.549 # ::: NB ::: 'ps' returns data, i.e. this is SELECTABLE expression.
2025-07-03 05:19:27.560 # We have to store result of cur.execute(<psInstance>) in order to
2025-07-03 05:19:27.568 # close it explicitly.
2025-07-03 05:19:27.575 # Otherwise AV can occur during Python garbage collection and this
2025-07-03 05:19:27.580 # causes pytest to hang on its final point.
2025-07-03 05:19:27.586 # Explained by hvlad, email 26.10.24 17:42
2025-07-03 05:19:27.591 rs = cur.execute(ps)
2025-07-03 05:19:27.598 for r in rs:
2025-07-03 05:19:27.607 print(r[0],r[1])
2025-07-03 05:19:27.615
2025-07-03 05:19:27.622 except DatabaseError as e:
2025-07-03 05:19:27.627 print(e.__str__())
2025-07-03 05:19:27.633 print(e.gds_codes)
2025-07-03 05:19:27.640 finally:
2025-07-03 05:19:27.646 if rs:
2025-07-03 05:19:27.653 rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
2025-07-03 05:19:27.659 if ps:
2025-07-03 05:19:27.667 ps.free()
2025-07-03 05:19:27.678
2025-07-03 05:19:27.686 con.rollback()
2025-07-03 05:19:27.691
2025-07-03 05:19:27.698 act.expected_stdout = f"""
2025-07-03 05:19:27.704 Select Expression
2025-07-03 05:19:27.710 ....-> First N Records
2025-07-03 05:19:27.721 ........-> Filter
2025-07-03 05:19:27.733 ............-> Hash Join (semi)
2025-07-03 05:19:27.745 ................-> Refetch
2025-07-03 05:19:27.753 ....................-> Sort (record length: 28, key length: 8)
2025-07-03 05:19:27.759 ........................-> Table "DEPARTMENT" as "D" Full Scan
2025-07-03 05:19:27.766 ................-> Record Buffer (record length: 25)
2025-07-03 05:19:27.773 ....................-> Table "EMPLOYEE" as "E" Full Scan
2025-07-03 05:19:27.780 2 d2
2025-07-03 05:19:27.787 """
2025-07-03 05:19:27.795 act.stdout = capsys.readouterr().out
2025-07-03 05:19:27.805 >       assert act.clean_stdout == act.clean_expected_stdout
2025-07-03 05:19:27.816 E       assert
2025-07-03 05:19:27.826 E           Select Expression
2025-07-03 05:19:27.833 E           ....-> First N Records
2025-07-03 05:19:27.839 E           ........-> Filter
2025-07-03 05:19:27.848 E           ............-> Hash Join (semi)
2025-07-03 05:19:27.856 E           ................-> Refetch
2025-07-03 05:19:27.863 E           ....................-> Sort (record length: NN, key length: NN)
2025-07-03 05:19:27.868 E         - ........................-> Table "DEPARTMENT" as "D" Full Scan
2025-07-03 05:19:27.873 E         + ........................-> Table "PUBLIC"."DEPARTMENT" as "D" Full Scan
2025-07-03 05:19:27.883 E           ................-> Record Buffer (record length: NN)
2025-07-03 05:19:27.889 E         - ....................-> Table "EMPLOYEE" as "E" Full Scan
2025-07-03 05:19:27.895 E         + ....................-> Table "PUBLIC"."EMPLOYEE" as "E" Full Scan
2025-07-03 05:19:27.909 E           2 d2
2025-07-03 05:19:27.914
2025-07-03 05:19:27.921 tests/bugs/gh_8225_test.py:151: AssertionError
2025-07-03 05:19:27.927 ---------------------------- Captured stdout setup -----------------------------
2025-07-03 05:19:27.935 Creating db: localhost:/var/tmp/qa_2024/test_11713/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 d.dept_no, d.dept_name from department d
            where exists(select * from employee e where e.dept_no = d.dept_no)
            order by dept_no rows 1
        """
    
        srv_cfg = driver_config.register_server(name = f'srv_cfg_8225', config = '')
        db_cfg_name = f'db_cfg_8225'
        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:
            cur = con.cursor()
            ps, rs = None, None
            try:
                ps = cur.prepare(test_sql)
                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])
    
            except DatabaseError as e:
                print(e.__str__())
                print(e.gds_codes)
            finally:
                if rs:
                    rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
                if ps:
                    ps.free()
    
            con.rollback()
    
        act.expected_stdout = f"""
            Select Expression
            ....-> First N Records
            ........-> Filter
            ............-> Hash Join (semi)
            ................-> Refetch
            ....................-> Sort (record length: 28, key length: 8)
            ........................-> Table "DEPARTMENT" as "D" Full Scan
            ................-> Record Buffer (record length: 25)
            ....................-> Table "EMPLOYEE" as "E" Full Scan
            2 d2
        """
        act.stdout = capsys.readouterr().out
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E           Select Expression
E           ....-> First N Records
E           ........-> Filter
E           ............-> Hash Join (semi)
E           ................-> Refetch
E           ....................-> Sort (record length: NN, key length: NN)
E         - ........................-> Table "DEPARTMENT" as "D" Full Scan
E         + ........................-> Table "PUBLIC"."DEPARTMENT" as "D" Full Scan
E           ................-> Record Buffer (record length: NN)
E         - ....................-> Table "EMPLOYEE" as "E" Full Scan
E         + ....................-> Table "PUBLIC"."EMPLOYEE" as "E" Full Scan
E           2 d2

tests/bugs/gh_8225_test.py:151: 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 675 671 2025.07.03 01:46:18.155 2025.07.03 01:46:18.830 2025.07.02 23:11:44.166 2025.07.02 23:11:44.837
2 6.0.0.889 2025.07.01 969ac F F 667 407 2025.07.02 02:14:17.255 2025.07.02 02:14:17.922 2025.07.01 23:24:28.576 2025.07.01 23:24:28.983
3 6.0.0.884 2025.06.30 f7e5f F F 737 672 2025.07.01 02:14:33.031 2025.07.01 02:14:33.768 2025.06.30 23:33:39.898 2025.06.30 23:33:40.570
4 6.0.0.881 2025.06.27 7035d F F 676 683 2025.06.30 02:04:51.115 2025.06.30 02:04:51.791 2025.06.29 23:20:48.771 2025.06.29 23:20:49.454
5 6.0.0.877 2025.06.26 8e38f F F 684 612 2025.06.27 01:43:49.360 2025.06.27 01:43:50.044 2025.06.26 23:11:44.318 2025.06.26 23:11:44.930
6 6.0.0.876 2025.06.25 b1bec F F 684 682 2025.06.26 01:47:40.051 2025.06.26 01:47:40.735 2025.06.25 23:13:40.081 2025.06.25 23:13:40.763
7 6.0.0.863 2025.06.24 c3c20 F F 850 548 2025.06.25 01:47:57.552 2025.06.25 01:47:58.402 2025.06.24 23:13:27.078 2025.06.24 23:13:27.626
8 6.0.0.858 2025.06.23 8d6f7 F F 743 688 2025.06.24 01:48:19.670 2025.06.24 01:48:20.413 2025.06.23 23:13:34.190 2025.06.23 23:13:34.878
9 6.0.0.849 2025.06.20 7b79c F F 726 389 2025.06.21 01:59:52.051 2025.06.21 01:59:52.777 2025.06.20 23:22:42.779 2025.06.20 23:22:43.168
10 6.0.0.848 2025.06.19 c483c F F 750 400 2025.06.20 01:56:12.849 2025.06.20 01:56:13.599 2025.06.19 23:19:30.281 2025.06.19 23:19:30.681
11 6.0.0.845 2025.06.18 22b12 F F 709 595 2025.06.19 02:04:52.207 2025.06.19 02:04:52.916 2025.06.18 23:22:44.359 2025.06.18 23:22:44.954
12 6.0.0.843 2025.06.16 995f4 F F 701 422 2025.06.18 02:03:07.524 2025.06.18 02:03:08.225 2025.06.17 23:24:31.288 2025.06.17 23:24:31.710
13 6.0.0.840 2025.06.14 29bca F F 712 456 2025.06.16 01:54:56.119 2025.06.16 01:54:56.831 2025.06.15 23:16:59.591 2025.06.15 23:17:00.047
14 6.0.0.838 2025.06.13 0e28a F F 781 577 2025.06.14 02:07:59.321 2025.06.14 02:08:00.102 2025.06.13 23:24:30.054 2025.06.13 23:24:30.631
15 6.0.0.835 2025.06.12 2cf29 F F 681 575 2025.06.13 02:07:54.256 2025.06.13 02:07:54.937 2025.06.12 23:28:36.090 2025.06.12 23:28:36.665
16 6.0.0.834 2025.06.11 e889f F F 667 720 2025.06.12 02:03:08.470 2025.06.12 02:03:09.137 2025.06.11 23:24:48.614 2025.06.11 23:24:49.334
17 6.0.0.800 2025.06.10 1f226 P P 691 603 2025.06.11 00:31:21.602 2025.06.11 00:31:22.293 2025.06.10 22:23:50.235 2025.06.10 22:23:50.838
18 6.0.0.799 2025.06.07 be644 P P 1188 460 2025.06.10 00:33:33.194 2025.06.10 00:33:34.382 2025.06.09 22:23:30.031 2025.06.09 22:23:30.491
19 6.0.0.797 2025.06.06 303e8 P P 1201 677 2025.06.07 00:36:47.891 2025.06.07 00:36:49.092 2025.06.06 22:23:03.603 2025.06.06 22:23:04.280
20 6.0.0.795 2025.05.29 7a71a P P 632 685 2025.06.06 00:31:10.983 2025.06.06 00:31:11.615 2025.06.05 22:22:10.037 2025.06.05 22:22:10.722
21 6.0.0.792 2025.05.28 b4327 P P 696 698 2025.05.29 00:45:26.987 2025.05.29 00:45:27.683 2025.05.28 22:25:19.225 2025.05.28 22:25:19.923
22 6.0.0.791 2025.05.27 02db8 P P 744 626 2025.05.28 00:43:31.279 2025.05.28 00:43:32.023 2025.05.27 22:24:22.215 2025.05.27 22:24:22.841
23 6.0.0.789 2025.05.21 64051 P P 1247 702 2025.05.25 00:35:48.870 2025.05.25 00:35:50.117 2025.05.24 22:23:27.633 2025.05.24 22:23:28.335
24 6.0.0.787 2025.05.20 230ad P P 639 694 2025.05.21 00:33:11.708 2025.05.21 00:33:12.347 2025.05.20 22:21:52.315 2025.05.20 22:21:53.009
25 6.0.0.783 2025.05.12 37320 P P 771 452 2025.05.19 12:05:54.219 2025.05.19 12:05:54.990 2025.05.19 10:10:04.414 2025.05.19 10:10:04.866
26 6.0.0.779 2025.05.11 136fa P P 622 507 2025.05.12 00:27:59.525 2025.05.12 00:28:00.147 2025.05.11 22:21:18.739 2025.05.11 22:21:19.246
27 6.0.0.778 2025.05.07 d735e P P 737 752 2025.05.08 00:30:03.778 2025.05.08 00:30:04.515 2025.05.07 22:20:00.868 2025.05.07 22:20:01.620
28 6.0.0.776 2025.05.06 007cd P P 649 766 2025.05.07 00:24:24.798 2025.05.07 00:24:25.447 2025.05.06 22:19:51.565 2025.05.06 22:19:52.331
29 6.0.0.770 2025.05.05 82c4a P P 620 620 2025.05.06 00:23:39.827 2025.05.06 00:23:40.447 2025.05.05 22:18:55.798 2025.05.05 22:18:56.418
30 6.0.0.767 2025.05.01 cdd29 P P 651 518 2025.05.02 00:20:24.915 2025.05.02 00:20:25.566 2025.05.01 22:18:11.051 2025.05.01 22:18:11.569
31 6.0.0.762 2025.04.30 5cb15 P P 655 365 2025.05.01 00:16:33.035 2025.05.01 00:16:33.690 2025.04.30 22:17:03.958 2025.04.30 22:17:04.323
32 6.0.0.755 2025.04.29 739c6 P P 1067 722 2025.04.30 00:20:11.479 2025.04.30 00:20:12.546 2025.04.29 22:18:14.136 2025.04.29 22:18:14.858
33 6.0.0.753 2025.04.27 29ab3 P P 1108 365 2025.04.28 00:21:42.858 2025.04.28 00:21:43.966 2025.04.27 22:17:34.295 2025.04.27 22:17:34.660
34 6.0.0.745 2025.04.21 78ad8 P P 713 461 2025.04.26 00:18:19.386 2025.04.26 00:18:20.099 2025.04.25 22:19:26.673 2025.04.25 22:19:27.134
35 6.0.0.744 2025.04.19 e883a P P 1162 575 2025.04.20 00:20:25.324 2025.04.20 00:20:26.486 2025.04.19 22:18:39.023 2025.04.19 22:18:39.598
36 6.0.0.742 2025.04.17 abc3b P P 662 776 2025.04.19 00:22:23.949 2025.04.19 00:22:24.611 2025.04.18 22:19:00.937 2025.04.18 22:19:01.713
37 6.0.0.737 2025.04.16 fe52b P P 1100 722 2025.04.17 00:18:04.718 2025.04.17 00:18:05.818 2025.04.16 22:19:03.204 2025.04.16 22:19:03.926

Elapsed time, ms. Chart for last 37 runs:

Last commits information (all timestamps in UTC):