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   
    ISQL process terminated.
  - Memory differences median acceptable.
  + Memory LEAK detected. Median of differences: 10240.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
  + 21376
  + 16384
  + 14592
  + 15488
  + 14848
  + 13184
  + 10368
  + 1972
  + 10112
  + 9984
  + 8192
  + 7552
  + 8832
  + 7936

LOG DETAILS:

2025-02-25 12:45:20.511
2025-02-25 12:45:20.519 act = <firebird.qa.plugin.Action object at [hex]>
2025-02-25 12:45:20.526 tmp_sql = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.sql')
2025-02-25 12:45:20.533 tmp_log = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.log')
2025-02-25 12:45:20.543 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-02-25 12:45:20.553
2025-02-25 12:45:20.560 @pytest.mark.version('>=4.0.5')
2025-02-25 12:45:20.566 def test_1(act: Action, tmp_sql: Path, tmp_log: Path, capsys):
2025-02-25 12:45:20.571
2025-02-25 12:45:20.577 test_sql = f"""
2025-02-25 12:45:20.583 recreate table tmplog(srv_pid int);
2025-02-25 12:45:20.590 insert into tmplog(srv_pid)
2025-02-25 12:45:20.603 select mon$server_pid as p
2025-02-25 12:45:20.617 from mon$attachments
2025-02-25 12:45:20.627 where mon$attachment_id = current_connection
2025-02-25 12:45:20.641 ;
2025-02-25 12:45:20.651 commit;
2025-02-25 12:45:20.660 SET STATEMENT TIMEOUT 7200;
2025-02-25 12:45:20.670 set term ^;
2025-02-25 12:45:20.684 execute block as
2025-02-25 12:45:20.696 declare res double precision;
2025-02-25 12:45:20.704 begin
2025-02-25 12:45:20.712 while (1=1) do
2025-02-25 12:45:20.720 begin
2025-02-25 12:45:20.729 execute statement 'select ' || rand() || ' from rdb$database' into res;
2025-02-25 12:45:20.742 end
2025-02-25 12:45:20.753 end
2025-02-25 12:45:20.761 ^
2025-02-25 12:45:20.773 """
2025-02-25 12:45:20.788 with open(tmp_sql, 'w') as f:
2025-02-25 12:45:20.800 f.write(test_sql)
2025-02-25 12:45:20.809
2025-02-25 12:45:20.817 memo_rss_list = []
2025-02-25 12:45:20.824 with act.db.connect() as con:
2025-02-25 12:45:20.830 with open(tmp_log, 'w') as f:
2025-02-25 12:45:20.837 try:
2025-02-25 12:45:20.849 p_handed_isql = subprocess.Popen( [act.vars['isql'], '-i', str(tmp_sql),
2025-02-25 12:45:20.863 '-user', act.db.user,
2025-02-25 12:45:20.875 '-password', act.db.password, act.db.dsn],
2025-02-25 12:45:20.889 stdout = f,
2025-02-25 12:45:20.899 stderr = subprocess.STDOUT
2025-02-25 12:45:20.912 )
2025-02-25 12:45:20.925
2025-02-25 12:45:20.941 # Let ISQL time to establish connection and start infinite loop with ES:
2025-02-25 12:45:20.956 time.sleep(MAX_WAIT_FOR_ISQL_BEGIN_WORK)
2025-02-25 12:45:20.967
2025-02-25 12:45:20.981 cur = con.cursor()
2025-02-25 12:45:20.993 cur.execute('select srv_pid from tmplog')
2025-02-25 12:45:21.006 fb_srv = psutil.Process( int(cur.fetchone()[0]) )
2025-02-25 12:45:21.020
2025-02-25 12:45:21.033 for i in range(N_CNT):
2025-02-25 12:45:21.044 memo_rss_list.append(int(fb_srv.memory_info().rss / 1024))
2025-02-25 12:45:21.052 time.sleep(1)
2025-02-25 12:45:21.060
2025-02-25 12:45:21.073 finally:
2025-02-25 12:45:21.083 p_handed_isql.terminate()
2025-02-25 12:45:21.097
2025-02-25 12:45:21.111 p_handed_isql.wait(MAX_WAIT_FOR_ISQL_TERMINATE)
2025-02-25 12:45:21.123 if p_handed_isql.poll() is None:
2025-02-25 12:45:21.131 print(f'ISQL process WAS NOT terminated in {MAX_WAIT_FOR_ISQL_TERMINATE} second(s).!')
2025-02-25 12:45:21.139 else:
2025-02-25 12:45:21.146 print(f'ISQL process terminated.')
2025-02-25 12:45:21.153
2025-02-25 12:45:21.160 memo_rss_diff = []
2025-02-25 12:45:21.166 for i,x in enumerate(memo_rss_list):
2025-02-25 12:45:21.177 if i >= 1:
2025-02-25 12:45:21.186 memo_rss_diff.append(x - memo_rss_list[i-1])
2025-02-25 12:45:21.194
2025-02-25 12:45:21.205 memo_rss_diff_median = median(memo_rss_diff)
2025-02-25 12:45:21.214 median_acceptable_msg = 'Memory differences median acceptable.'
2025-02-25 12:45:21.228 if memo_rss_diff_median <= MAX_RSS_DIFFERENCE_MEDIAN:
2025-02-25 12:45:21.240 print(median_acceptable_msg)
2025-02-25 12:45:21.248 else:
2025-02-25 12:45:21.256 print(f'Memory LEAK detected. Median of differences: {memo_rss_diff_median} Kb - is UNACCEPTABLE. Check memo_rss_diff:')
2025-02-25 12:45:21.268 for p in memo_rss_diff:
2025-02-25 12:45:21.283 print('%6d' % p)
2025-02-25 12:45:21.293
2025-02-25 12:45:21.301 expected_stdout = f"""
2025-02-25 12:45:21.308 ISQL process terminated.
2025-02-25 12:45:21.315 {median_acceptable_msg}
2025-02-25 12:45:21.322 """
2025-02-25 12:45:21.329
2025-02-25 12:45:21.336 act.expected_stdout = expected_stdout
2025-02-25 12:45:21.343 act.stdout = capsys.readouterr().out
2025-02-25 12:45:21.351 >       assert act.clean_stdout == act.clean_expected_stdout
2025-02-25 12:45:21.366 E       assert
2025-02-25 12:45:21.378 E           ISQL process terminated.
2025-02-25 12:45:21.389 E         - Memory differences median acceptable.
2025-02-25 12:45:21.402 E         + Memory LEAK detected. Median of differences: 10240.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
2025-02-25 12:45:21.415 E         + 21376
2025-02-25 12:45:21.425 E         + 16384
2025-02-25 12:45:21.434 E         + 14592
2025-02-25 12:45:21.442 E         + 15488
2025-02-25 12:45:21.449 E         + 14848
2025-02-25 12:45:21.458 E         + 13184
2025-02-25 12:45:21.468 E         + 10368
2025-02-25 12:45:21.480 E         + 1972
2025-02-25 12:45:21.492 E         + 10112
2025-02-25 12:45:21.506 E         + 9984
2025-02-25 12:45:21.520 E         + 8192
2025-02-25 12:45:21.536 E         + 7552
2025-02-25 12:45:21.549 E         + 8832
2025-02-25 12:45:21.566 E         + 7936
2025-02-25 12:45:21.574
2025-02-25 12:45:21.581 tests/bugs/gh_8085_test.py:129: AssertionError
2025-02-25 12:45:21.589 ---------------------------- Captured stdout setup -----------------------------
2025-02-25 12:45:21.594 Creating db: localhost:/var/tmp/qa_2024/test_11641/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]>
tmp_sql = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.sql')
tmp_log = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.log')
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    @pytest.mark.version('>=4.0.5')
    def test_1(act: Action, tmp_sql: Path, tmp_log: Path, capsys):
    
        test_sql = f"""
            recreate table tmplog(srv_pid int);
            insert into tmplog(srv_pid)
            select mon$server_pid as p
            from mon$attachments
            where mon$attachment_id = current_connection
            ;
            commit;
            SET STATEMENT TIMEOUT 7200;
            set term ^;
            execute block as
                declare res double precision;
            begin
                while (1=1) do
                begin
                    execute statement 'select ' || rand() || ' from rdb$database' into res;
                end
            end
            ^
        """
        with open(tmp_sql, 'w') as f:
            f.write(test_sql)
    
        memo_rss_list = []
        with act.db.connect() as con:
            with open(tmp_log, 'w') as f:
                try:
                    p_handed_isql = subprocess.Popen( [act.vars['isql'], '-i', str(tmp_sql),
                                                      '-user', act.db.user,
                                                      '-password', act.db.password, act.db.dsn],
                                                      stdout = f,
                                                      stderr = subprocess.STDOUT
                                                    )
    
                    # Let ISQL time to establish connection and start infinite loop with ES:
                    time.sleep(MAX_WAIT_FOR_ISQL_BEGIN_WORK)
    
                    cur = con.cursor()
                    cur.execute('select srv_pid from tmplog')
                    fb_srv = psutil.Process( int(cur.fetchone()[0]) )
    
                    for i in range(N_CNT):
                        memo_rss_list.append(int(fb_srv.memory_info().rss / 1024))
                        time.sleep(1)
    
                finally:
                    p_handed_isql.terminate()
    
                p_handed_isql.wait(MAX_WAIT_FOR_ISQL_TERMINATE)
                if p_handed_isql.poll() is None:
                    print(f'ISQL process WAS NOT terminated in {MAX_WAIT_FOR_ISQL_TERMINATE} second(s).!')
                else:
                    print(f'ISQL process terminated.')
    
            memo_rss_diff = []
            for i,x in enumerate(memo_rss_list):
                if i >= 1:
                    memo_rss_diff.append(x - memo_rss_list[i-1])
    
        memo_rss_diff_median = median(memo_rss_diff)
        median_acceptable_msg = 'Memory differences median acceptable.'
        if memo_rss_diff_median <= MAX_RSS_DIFFERENCE_MEDIAN:
            print(median_acceptable_msg)
        else:
            print(f'Memory LEAK detected. Median of differences: {memo_rss_diff_median} Kb - is UNACCEPTABLE. Check memo_rss_diff:')
            for p in memo_rss_diff:
                print('%6d' % p)
    
        expected_stdout = f"""
            ISQL process terminated.
            {median_acceptable_msg}
        """
    
        act.expected_stdout = expected_stdout
        act.stdout = capsys.readouterr().out
>       assert act.clean_stdout == act.clean_expected_stdout
E       assert   
E           ISQL process terminated.
E         - Memory differences median acceptable.
E         + Memory LEAK detected. Median of differences: 10240.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
E         + 21376
E         + 16384
E         + 14592
E         + 15488
E         + 14848
E         + 13184
E         + 10368
E         + 1972
E         + 10112
E         + 9984
E         + 8192
E         + 7552
E         + 8832
E         + 7936

tests/bugs/gh_8085_test.py:129: 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 5.0.3.1674 2025.06.27 3ee5c P P 18666 18392 2025.07.03 10:55:20.109 2025.07.03 10:55:38.775 2025.07.03 09:35:18.550 2025.07.03 09:35:36.942
2 5.0.3.1657 2025.06.19 4bd4c P P 18772 18495 2025.06.27 12:19:18.914 2025.06.27 12:19:37.686 2025.06.27 11:00:35.112 2025.06.27 11:00:53.607
3 5.0.3.1657 2025.06.11 dae6f P P 18629 18373 2025.06.17 07:24:21.197 2025.06.17 07:24:39.826 2025.06.17 06:04:26.876 2025.06.17 06:04:45.249
4 5.0.3.1657 2025.06.10 dbc92 P P 18764 18405 2025.06.11 12:14:48.461 2025.06.11 12:15:07.225 2025.06.11 10:46:00.001 2025.06.11 10:46:18.406
5 5.0.3.1656 2025.05.20 c4b11 P P 18826 18433 2025.06.10 12:08:30.349 2025.06.10 12:08:49.175 2025.06.10 10:44:35.629 2025.06.10 10:44:54.062
6 5.0.3.1652 2025.05.13 f51c6 P P 18848 18497 2025.05.20 05:12:30.551 2025.05.20 05:12:49.399 2025.05.20 03:36:46.045 2025.05.20 03:37:04.542
7 5.0.3.1651 2025.04.30 141ef P P 18769 18476 2025.05.13 12:10:30.798 2025.05.13 12:10:49.567 2025.05.13 10:33:43.536 2025.05.13 10:34:02.012
8 5.0.3.1650 2025.04.28 4cbff P P 18821 18428 2025.05.01 11:44:19.817 2025.05.01 11:44:38.638 2025.05.01 10:08:28.669 2025.05.01 10:08:47.097
9 5.0.3.1649 2025.04.21 5b2d0 P P 18849 18447 2025.04.28 05:42:07.752 2025.04.28 05:42:26.601 2025.04.28 04:08:13.634 2025.04.28 04:08:32.081
10 5.0.3.1648 2025.04.18 2f4c5 P P 18769 18395 2025.04.20 05:33:53.328 2025.04.20 05:34:12.097 2025.04.20 04:02:39.117 2025.04.20 04:02:57.512
11 5.0.3.1635 2025.03.31 22ec6 P P 18853 18501 2025.04.18 11:56:56.338 2025.04.18 11:57:15.191 2025.04.18 10:21:43.002 2025.04.18 10:22:01.503
12 5.0.3.1633 2025.03.28 3123a P P 18744 18462 2025.03.31 10:31:00.634 2025.03.31 10:31:19.378 2025.03.31 09:02:00.701 2025.03.31 09:02:19.163
13 5.0.3.1633 2025.03.27 e0fb8 F F 19276 18756 2025.03.28 11:06:13.637 2025.03.28 11:06:32.913 2025.03.28 09:34:10.622 2025.03.28 09:34:29.378
14 5.0.3.1631 2025.03.21 1925b F F 19124 18917 2025.03.27 10:53:56.637 2025.03.27 10:54:15.761 2025.03.27 09:23:04.760 2025.03.27 09:23:23.677
15 5.0.3.1628 2025.03.14 16d05 F F 815 476 2025.03.17 08:27:12.398 2025.03.17 08:27:13.213 2025.03.17 06:47:28.614 2025.03.17 06:47:29.090
16 5.0.3.1627 2025.02.26 4e218 F F 822 469 2025.03.14 11:41:36.171 2025.03.14 11:41:36.993 2025.03.14 10:00:46.414 2025.03.14 10:00:46.883
17 5.0.3.1624 2025.02.25 dc3b2 F F 829 446 2025.02.26 10:32:12.279 2025.02.26 10:32:13.108 2025.02.26 08:56:53.683 2025.02.26 08:56:54.129
18 5.0.2.1615 2025.02.20 4a726 F F 711 423 2025.02.25 10:59:37.447 2025.02.25 10:59:38.158 2025.02.25 09:22:30.234 2025.02.25 09:22:30.657
19 5.0.2.1615 2025.02.14 9cb76 F F 772 424 2025.02.20 07:48:50.111 2025.02.20 07:48:50.883 2025.02.20 06:15:26.995 2025.02.20 06:15:27.419
20 5.0.2.1577 2024.12.24 3c80e P P 758 415 2025.02.14 11:02:39.618 2025.02.14 11:02:40.376 2025.02.14 09:29:02.080 2025.02.14 09:29:02.495
21 5.0.2.1576 2024.12.17 646b0 P P 618 326 2024.12.24 20:25:48.632 2024.12.24 20:25:49.250 2024.12.24 17:14:49.915 2024.12.24 17:14:50.241
22 5.0.2.1575 2024.12.08 63d39 P P 580 322 2024.12.16 08:07:14.292 2024.12.16 08:07:14.872 2024.12.16 06:57:35.072 2024.12.16 06:57:35.394
23 5.0.2.1567 2024.11.26 56e63 P P 622 341 2024.12.04 07:48:15.971 2024.12.04 07:48:16.593 2024.12.04 06:36:54.106 2024.12.04 06:36:54.447
24 5.0.2.1567 2024.11.21 96f61 P P 587 332 2024.11.26 05:30:07.819 2024.11.26 05:30:08.406 2024.11.26 04:22:06.163 2024.11.26 04:22:06.495
25 5.0.2.1567 2024.11.18 e1289 P P 584 365 2024.11.21 07:34:30.102 2024.11.21 07:34:30.686 2024.11.21 06:27:10.900 2024.11.21 06:27:11.265
26 5.0.2.1533 2024.10.23 0ec43 P P 658 330 2024.11.18 07:50:48.718 2024.11.18 07:50:49.376 2024.11.18 06:41:33.196 2024.11.18 06:41:33.526
27 5.0.2.1533 2024.10.22 8af7a P P 597 352 2024.10.23 09:48:01.712 2024.10.23 09:48:02.309 2024.10.23 08:37:35.694 2024.10.23 08:37:36.046
28 5.0.2.1532 2024.10.15 36dc0 P P 629 352 2024.10.22 19:59:45.901 2024.10.22 19:59:46.530 2024.10.22 18:49:46.396 2024.10.22 18:49:46.748
29 5.0.2.1518 2024.10.04 259ba P P 604 439 2024.10.15 09:33:24.621 2024.10.15 09:33:25.225 2024.10.15 08:23:13.586 2024.10.15 08:23:14.025
30 5.0.2.1518 2024.09.26 703cd P P 638 352 2024.10.03 08:00:50.006 2024.10.03 08:00:50.644 2024.10.03 06:48:22.738 2024.10.03 06:48:23.090
31 5.0.2.1489 2024.09.05 40838 P P 619 384 2024.09.25 08:01:44.377 2024.09.25 08:01:44.996 2024.09.25 06:48:22.320 2024.09.25 06:48:22.704
32 5.0.2.1489 2024.08.31 994a6 P P 1251 572 2024.09.05 12:13:24.289 2024.09.05 12:13:25.540 2024.09.05 10:31:41.941 2024.09.05 10:31:42.513
33 5.0.2.1476 2024.08.09 843ea P P 1473 740 2024.08.31 14:45:38.829 2024.08.31 14:45:40.302 2024.08.31 12:36:33.787 2024.08.31 12:36:34.527
34 5.0.1.1454 2024.08.08 30f9f P P 830 409 2024.08.09 08:40:33.531 2024.08.09 08:40:34.361 2024.08.09 07:26:37.647 2024.08.09 07:26:38.056
35 5.0.1.1453 2024.08.06 1b9d0 P P 847 496 2024.08.08 21:18:57.020 2024.08.08 21:18:57.867 2024.08.08 20:04:50.350 2024.08.08 20:04:50.846
36 5.0.1.1453 2024.07.30 48044 P P 546 308 2024.08.06 07:21:44.597 2024.08.06 07:21:45.143 2024.08.06 06:16:53.948 2024.08.06 06:16:54.256
37 5.0.1.1453 2024.07.28 8d956 P P 524 306 2024.07.30 07:15:58.156 2024.07.30 07:15:58.680 2024.07.30 06:12:07.704 2024.07.30 06:12:08.010
38 5.0.1.1429 2024.07.19 8ee90 P P 573 358 2024.07.27 07:15:59.508 2024.07.27 07:16:00.081 2024.07.27 06:11:13.406 2024.07.27 06:11:13.764
39 5.0.1.1428 2024.07.15 00392 P P 504 275 2024.07.19 07:09:03.081 2024.07.19 07:09:03.585 2024.07.19 06:05:37.899 2024.07.19 06:05:38.174
40 5.0.1.1428 2024.06.30 67a31 P P 543 331 2024.07.15 07:10:36.838 2024.07.15 07:10:37.381 2024.07.15 06:06:41.349 2024.07.15 06:06:41.680
41 5.0.1.1415 2024.06.11 31d74 P P 501 263 2024.06.22 06:58:10.854 2024.06.22 06:58:11.355 2024.06.22 05:56:59.015 2024.06.22 05:56:59.278

Elapsed time, ms. Chart for last 41 runs:

Last commits information (all timestamps in UTC):