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   
    Sub-query
    ....-> Filter
  - ........-> Table "CUSTOMER" as "C" Access By ID
  + ........-> Table "PUBLIC"."CUSTOMER" as "C" Access By ID
    ............-> Bitmap
  - ................-> Index "RDB$PRIMARY22" Unique Scan
  + ................-> Index "PUBLIC"."RDB$PRIMARY22" Unique Scan
    Select Expression
    ....-> First N Records
    ........-> Filter
  - ............-> Table "SALES" as "S" Full Scan
  + ............-> Table "PUBLIC"."SALES" as "S" Full Scan
    1
    1
    1
    1
    1

LOG DETAILS:

2025-07-03 05:19:30.277
2025-07-03 05:19:30.291 act = <firebird.qa.plugin.Action object at [hex]>
2025-07-03 05:19:30.300 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-07-03 05:19:30.307
2025-07-03 05:19:30.314 @pytest.mark.version('>=5.0.2')
2025-07-03 05:19:30.320 def test_1(act: Action, capsys):
2025-07-03 05:19:30.326
2025-07-03 05:19:30.332 srv_cfg = driver_config.register_server(name = 'test_srv_gh_8252', config = '')
2025-07-03 05:19:30.338 db_cfg_name = f'db_cfg_8252'
2025-07-03 05:19:30.344 db_cfg_object = driver_config.register_database(name = db_cfg_name)
2025-07-03 05:19:30.350 db_cfg_object.server.value = srv_cfg.name
2025-07-03 05:19:30.356 db_cfg_object.database.value = 'employee'
2025-07-03 05:19:30.363 if act.is_version('<6'):
2025-07-03 05:19:30.368 db_cfg_object.config.value = f"""
2025-07-03 05:19:30.374 SubQueryConversion = true
2025-07-03 05:19:30.387 """
2025-07-03 05:19:30.395
2025-07-03 05:19:30.405 with connect(db_cfg_name, user = act.db.user, password = act.db.password) as con:
2025-07-03 05:19:30.413 cur = con.cursor()
2025-07-03 05:19:30.420 ps = cur.prepare(test_sql)
2025-07-03 05:19:30.427 # Show explained plan:
2025-07-03 05:19:30.433 print( '\n'.join([replace_leading(s) for s in ps.detailed_plan.split('\n')]) )
2025-07-03 05:19:30.439
2025-07-03 05:19:30.446 # ::: NB ::: 'ps' returns data, i.e. this is SELECTABLE expression.
2025-07-03 05:19:30.452 # We have to store result of cur.execute(<psInstance>) in order to
2025-07-03 05:19:30.459 # close it explicitly.
2025-07-03 05:19:30.469 # Otherwise AV can occur during Python garbage collection and this
2025-07-03 05:19:30.476 # causes pytest to hang on its final point.
2025-07-03 05:19:30.482 # Explained by hvlad, email 26.10.24 17:42
2025-07-03 05:19:30.488 rs = cur.execute(ps)
2025-07-03 05:19:30.494 for r in rs:
2025-07-03 05:19:30.501 print(r[0])
2025-07-03 05:19:30.506
2025-07-03 05:19:30.512 rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
2025-07-03 05:19:30.518 ps.free()
2025-07-03 05:19:30.523
2025-07-03 05:19:30.527 con.rollback()
2025-07-03 05:19:30.532
2025-07-03 05:19:30.536 act.expected_stdout = """
2025-07-03 05:19:30.540 Sub-query
2025-07-03 05:19:30.546 ....-> Filter
2025-07-03 05:19:30.552 ........-> Table "CUSTOMER" as "C" Access By ID
2025-07-03 05:19:30.558 ............-> Bitmap
2025-07-03 05:19:30.568 ................-> Index "RDB$PRIMARY22" Unique Scan
2025-07-03 05:19:30.577 Select Expression
2025-07-03 05:19:30.585 ....-> First N Records
2025-07-03 05:19:30.591 ........-> Filter
2025-07-03 05:19:30.597 ............-> Table "SALES" as "S" Full Scan
2025-07-03 05:19:30.609 1
2025-07-03 05:19:30.620 1
2025-07-03 05:19:30.628 1
2025-07-03 05:19:30.634 1
2025-07-03 05:19:30.639 1
2025-07-03 05:19:30.643 """
2025-07-03 05:19:30.648 act.stdout = capsys.readouterr().out
2025-07-03 05:19:30.653 >       assert act.clean_stdout == act.clean_expected_stdout
2025-07-03 05:19:30.657 E       assert
2025-07-03 05:19:30.661 E           Sub-query
2025-07-03 05:19:30.669 E           ....-> Filter
2025-07-03 05:19:30.680 E         - ........-> Table "CUSTOMER" as "C" Access By ID
2025-07-03 05:19:30.688 E         + ........-> Table "PUBLIC"."CUSTOMER" as "C" Access By ID
2025-07-03 05:19:30.700 E           ............-> Bitmap
2025-07-03 05:19:30.712 E         - ................-> Index "RDB$PRIMARY22" Unique Scan
2025-07-03 05:19:30.723 E         + ................-> Index "PUBLIC"."RDB$PRIMARY22" Unique Scan
2025-07-03 05:19:30.737 E           Select Expression
2025-07-03 05:19:30.743 E           ....-> First N Records
2025-07-03 05:19:30.751 E           ........-> Filter
2025-07-03 05:19:30.755 E         - ............-> Table "SALES" as "S" Full Scan
2025-07-03 05:19:30.760 E         + ............-> Table "PUBLIC"."SALES" as "S" Full Scan
2025-07-03 05:19:30.768 E           1
2025-07-03 05:19:30.773 E           1
2025-07-03 05:19:30.777 E           1
2025-07-03 05:19:30.781 E           1
2025-07-03 05:19:30.785 E           1
2025-07-03 05:19:30.790
2025-07-03 05:19:30.794 tests/bugs/gh_8252_test.py:111: AssertionError
2025-07-03 05:19:30.799 ---------------------------- Captured stdout setup -----------------------------
2025-07-03 05:19:30.803 Creating db: localhost:/var/tmp/qa_2024/test_11720/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):
    
        srv_cfg = driver_config.register_server(name = 'test_srv_gh_8252', config = '')
        db_cfg_name = f'db_cfg_8252'
        db_cfg_object = driver_config.register_database(name = db_cfg_name)
        db_cfg_object.server.value = srv_cfg.name
        db_cfg_object.database.value = 'employee'
        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 = cur.prepare(test_sql)
            # Show explained plan:
            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])
    
            rs.close() # <<< EXPLICITLY CLOSING CURSOR RESULTS
            ps.free()
    
            con.rollback()
    
        act.expected_stdout = """
            Sub-query
            ....-> Filter
            ........-> Table "CUSTOMER" as "C" Access By ID
            ............-> Bitmap
            ................-> Index "RDB$PRIMARY22" Unique Scan
            Select Expression
            ....-> First N Records
            ........-> Filter
            ............-> Table "SALES" as "S" Full Scan
            1
            1
            1
            1
            1
        """
        act.stdout = capsys.readouterr().out
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E           Sub-query
E           ....-> Filter
E         - ........-> Table "CUSTOMER" as "C" Access By ID
E         + ........-> Table "PUBLIC"."CUSTOMER" as "C" Access By ID
E           ............-> Bitmap
E         - ................-> Index "RDB$PRIMARY22" Unique Scan
E         + ................-> Index "PUBLIC"."RDB$PRIMARY22" Unique Scan
E           Select Expression
E           ....-> First N Records
E           ........-> Filter
E         - ............-> Table "SALES" as "S" Full Scan
E         + ............-> Table "PUBLIC"."SALES" as "S" Full Scan
E           1
E           1
E           1
E           1
E           1

tests/bugs/gh_8252_test.py:111: 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 510 529 2025.07.03 01:46:24.109 2025.07.03 01:46:24.619 2025.07.02 23:11:49.265 2025.07.02 23:11:49.794
2 6.0.0.889 2025.07.01 969ac F F 518 289 2025.07.02 02:14:23.485 2025.07.02 02:14:24.003 2025.07.01 23:24:31.859 2025.07.01 23:24:32.148
3 6.0.0.884 2025.06.30 f7e5f F F 517 446 2025.07.01 02:14:38.901 2025.07.01 02:14:39.418 2025.06.30 23:33:45.194 2025.06.30 23:33:45.640
4 6.0.0.881 2025.06.27 7035d F F 561 570 2025.06.30 02:04:57.780 2025.06.30 02:04:58.341 2025.06.29 23:20:54.134 2025.06.29 23:20:54.704
5 6.0.0.877 2025.06.26 8e38f F F 513 375 2025.06.27 01:43:55.031 2025.06.27 01:43:55.544 2025.06.26 23:11:49.195 2025.06.26 23:11:49.570
6 6.0.0.876 2025.06.25 b1bec F F 470 426 2025.06.26 01:47:45.933 2025.06.26 01:47:46.403 2025.06.25 23:13:44.942 2025.06.25 23:13:45.368
7 6.0.0.863 2025.06.24 c3c20 F F 477 455 2025.06.25 01:48:03.985 2025.06.25 01:48:04.462 2025.06.24 23:13:31.896 2025.06.24 23:13:32.351
8 6.0.0.858 2025.06.23 8d6f7 F F 620 504 2025.06.24 01:48:25.603 2025.06.24 01:48:26.223 2025.06.23 23:13:39.286 2025.06.23 23:13:39.790
9 6.0.0.849 2025.06.20 7b79c F F 498 444 2025.06.21 01:59:57.938 2025.06.21 01:59:58.436 2025.06.20 23:22:46.806 2025.06.20 23:22:47.250
10 6.0.0.848 2025.06.19 c483c F F 624 276 2025.06.20 01:56:18.984 2025.06.20 01:56:19.608 2025.06.19 23:19:33.338 2025.06.19 23:19:33.614
11 6.0.0.845 2025.06.18 22b12 F F 607 560 2025.06.19 02:04:58.302 2025.06.19 02:04:58.909 2025.06.18 23:22:49.730 2025.06.18 23:22:50.290
12 6.0.0.843 2025.06.16 995f4 F F 523 401 2025.06.18 02:03:13.837 2025.06.18 02:03:14.360 2025.06.17 23:24:35.209 2025.06.17 23:24:35.610
13 6.0.0.840 2025.06.14 29bca F F 511 517 2025.06.16 01:55:02.383 2025.06.16 01:55:02.894 2025.06.15 23:17:04.622 2025.06.15 23:17:05.139
14 6.0.0.838 2025.06.13 0e28a F F 607 474 2025.06.14 02:08:05.722 2025.06.14 02:08:06.329 2025.06.13 23:24:35.381 2025.06.13 23:24:35.855
15 6.0.0.835 2025.06.12 2cf29 F F 525 319 2025.06.13 02:08:00.037 2025.06.13 02:08:00.562 2025.06.12 23:28:40.370 2025.06.12 23:28:40.689
16 6.0.0.834 2025.06.11 e889f F F 557 370 2025.06.12 02:03:14.417 2025.06.12 02:03:14.974 2025.06.11 23:24:53.642 2025.06.11 23:24:54.012
17 6.0.0.800 2025.06.10 1f226 P P 410 498 2025.06.11 00:31:26.992 2025.06.11 00:31:27.402 2025.06.10 22:23:55.051 2025.06.10 22:23:55.549
18 6.0.0.799 2025.06.07 be644 P P 1034 389 2025.06.10 00:33:43.084 2025.06.10 00:33:44.118 2025.06.09 22:23:34.774 2025.06.09 22:23:35.163
19 6.0.0.797 2025.06.06 303e8 P P 906 548 2025.06.07 00:36:57.476 2025.06.07 00:36:58.382 2025.06.06 22:23:08.799 2025.06.06 22:23:09.347
20 6.0.0.795 2025.05.29 7a71a P P 543 525 2025.06.06 00:31:16.043 2025.06.06 00:31:16.586 2025.06.05 22:22:15.170 2025.06.05 22:22:15.695
21 6.0.0.792 2025.05.28 b4327 P P 483 609 2025.05.29 00:45:32.543 2025.05.29 00:45:33.026 2025.05.28 22:25:24.278 2025.05.28 22:25:24.887
22 6.0.0.791 2025.05.27 02db8 P P 518 511 2025.05.28 00:43:38.008 2025.05.28 00:43:38.526 2025.05.27 22:24:27.514 2025.05.27 22:24:28.025
23 6.0.0.789 2025.05.21 64051 P P 977 366 2025.05.25 00:35:58.625 2025.05.25 00:35:59.602 2025.05.24 22:23:33.180 2025.05.24 22:23:33.546
24 6.0.0.787 2025.05.20 230ad P P 528 464 2025.05.21 00:33:17.312 2025.05.21 00:33:17.840 2025.05.20 22:21:57.168 2025.05.20 22:21:57.632
25 6.0.0.783 2025.05.12 37320 P P 606 316 2025.05.19 12:06:00.771 2025.05.19 12:06:01.377 2025.05.19 10:10:08.319 2025.05.19 10:10:08.635
26 6.0.0.779 2025.05.11 136fa P P 476 436 2025.05.12 00:28:04.767 2025.05.12 00:28:05.243 2025.05.11 22:21:23.398 2025.05.11 22:21:23.834
27 6.0.0.778 2025.05.07 d735e P P 508 492 2025.05.08 00:30:09.816 2025.05.08 00:30:10.324 2025.05.07 22:20:06.491 2025.05.07 22:20:06.983
28 6.0.0.776 2025.05.06 007cd P P 579 464 2025.05.07 00:24:31.723 2025.05.07 00:24:32.302 2025.05.06 22:19:56.926 2025.05.06 22:19:57.390
29 6.0.0.770 2025.05.05 82c4a P P 582 485 2025.05.06 00:23:45.605 2025.05.06 00:23:46.187 2025.05.05 22:19:00.591 2025.05.05 22:19:01.076
30 6.0.0.767 2025.05.01 cdd29 P P 446 503 2025.05.02 00:20:30.412 2025.05.02 00:20:30.858 2025.05.01 22:18:15.970 2025.05.01 22:18:16.473
31 6.0.0.762 2025.04.30 5cb15 P P 814 254 2025.05.01 00:16:38.356 2025.05.01 00:16:39.170 2025.04.30 22:17:06.998 2025.04.30 22:17:07.252
32 6.0.0.755 2025.04.29 739c6 P P 864 467 2025.04.30 00:20:20.739 2025.04.30 00:20:21.603 2025.04.29 22:18:18.924 2025.04.29 22:18:19.391
33 6.0.0.753 2025.04.27 29ab3 P P 496 288 2025.04.28 00:21:48.831 2025.04.28 00:21:49.327 2025.04.27 22:17:37.454 2025.04.27 22:17:37.742
34 6.0.0.745 2025.04.21 78ad8 P P 482 457 2025.04.26 00:18:24.995 2025.04.26 00:18:25.477 2025.04.25 22:19:31.702 2025.04.25 22:19:32.159
35 6.0.0.744 2025.04.19 e883a P P 806 472 2025.04.20 00:20:34.876 2025.04.20 00:20:35.682 2025.04.19 22:18:44.098 2025.04.19 22:18:44.570
36 6.0.0.742 2025.04.17 abc3b P P 925 439 2025.04.19 00:22:31.413 2025.04.19 00:22:32.338 2025.04.18 22:19:05.318 2025.04.18 22:19:05.757
37 6.0.0.737 2025.04.16 fe52b P P 833 434 2025.04.17 00:18:14.255 2025.04.17 00:18:15.088 2025.04.16 22:19:08.357 2025.04.16 22:19:08.791

Elapsed time, ms. Chart for last 37 runs:

Last commits information (all timestamps in UTC):