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: 9152.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
  + 21120
  + 14592
  + 13568
  + 13440
  + 12160
  + 12800
  + 7504
  + 100
  + 9088
  + 8576
  + 9216
  + 7936
  + 7680
  + 6912

LOG DETAILS:

2025-03-28 12:56:16.886
2025-03-28 12:56:16.894 act = <firebird.qa.plugin.Action object at [hex]>
2025-03-28 12:56:16.906 tmp_sql = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.sql')
2025-03-28 12:56:16.918 tmp_log = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.log')
2025-03-28 12:56:16.931 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-03-28 12:56:16.938
2025-03-28 12:56:16.951 @pytest.mark.version('>=4.0.5')
2025-03-28 12:56:16.962 def test_1(act: Action, tmp_sql: Path, tmp_log: Path, capsys):
2025-03-28 12:56:16.970
2025-03-28 12:56:16.982 test_sql = f"""
2025-03-28 12:56:16.990 recreate table tmplog(srv_pid int);
2025-03-28 12:56:17.008 insert into tmplog(srv_pid)
2025-03-28 12:56:17.019 select mon$server_pid as p
2025-03-28 12:56:17.035 from mon$attachments
2025-03-28 12:56:17.047 where mon$attachment_id = current_connection
2025-03-28 12:56:17.062 ;
2025-03-28 12:56:17.070 commit;
2025-03-28 12:56:17.082 SET STATEMENT TIMEOUT 7200;
2025-03-28 12:56:17.095 set term ^;
2025-03-28 12:56:17.106 execute block as
2025-03-28 12:56:17.114 declare res double precision;
2025-03-28 12:56:17.126 begin
2025-03-28 12:56:17.134 while (1=1) do
2025-03-28 12:56:17.146 begin
2025-03-28 12:56:17.158 execute statement 'select ' || rand() || ' from rdb$database' into res;
2025-03-28 12:56:17.171 end
2025-03-28 12:56:17.182 end
2025-03-28 12:56:17.194 ^
2025-03-28 12:56:17.207 """
2025-03-28 12:56:17.214 with open(tmp_sql, 'w') as f:
2025-03-28 12:56:17.226 f.write(test_sql)
2025-03-28 12:56:17.238
2025-03-28 12:56:17.246 memo_rss_list = []
2025-03-28 12:56:17.259 with act.db.connect() as con:
2025-03-28 12:56:17.275 with open(tmp_log, 'w') as f:
2025-03-28 12:56:17.282 try:
2025-03-28 12:56:17.295 p_handed_isql = subprocess.Popen( [act.vars['isql'], '-i', str(tmp_sql),
2025-03-28 12:56:17.315 '-user', act.db.user,
2025-03-28 12:56:17.331 '-password', act.db.password, act.db.dsn],
2025-03-28 12:56:17.338 stdout = f,
2025-03-28 12:56:17.351 stderr = subprocess.STDOUT
2025-03-28 12:56:17.363 )
2025-03-28 12:56:17.371
2025-03-28 12:56:17.382 # Let ISQL time to establish connection and start infinite loop with ES:
2025-03-28 12:56:17.395 time.sleep(MAX_WAIT_FOR_ISQL_BEGIN_WORK)
2025-03-28 12:56:17.406
2025-03-28 12:56:17.414 cur = con.cursor()
2025-03-28 12:56:17.426 cur.execute('select srv_pid from tmplog')
2025-03-28 12:56:17.438 fb_srv = psutil.Process( int(cur.fetchone()[0]) )
2025-03-28 12:56:17.446
2025-03-28 12:56:17.462 for i in range(N_CNT):
2025-03-28 12:56:17.475 memo_rss_list.append(int(fb_srv.memory_info().rss / 1024))
2025-03-28 12:56:17.487 time.sleep(1)
2025-03-28 12:56:17.503
2025-03-28 12:56:17.510 finally:
2025-03-28 12:56:17.522 p_handed_isql.terminate()
2025-03-28 12:56:17.539
2025-03-28 12:56:17.555 p_handed_isql.wait(MAX_WAIT_FOR_ISQL_TERMINATE)
2025-03-28 12:56:17.566 if p_handed_isql.poll() is None:
2025-03-28 12:56:17.575 print(f'ISQL process WAS NOT terminated in {MAX_WAIT_FOR_ISQL_TERMINATE} second(s).!')
2025-03-28 12:56:17.591 else:
2025-03-28 12:56:17.607 print(f'ISQL process terminated.')
2025-03-28 12:56:17.623
2025-03-28 12:56:17.640 memo_rss_diff = []
2025-03-28 12:56:17.655 for i,x in enumerate(memo_rss_list):
2025-03-28 12:56:17.671 if i >= 1:
2025-03-28 12:56:17.683 memo_rss_diff.append(x - memo_rss_list[i-1])
2025-03-28 12:56:17.694
2025-03-28 12:56:17.700 memo_rss_diff_median = median(memo_rss_diff)
2025-03-28 12:56:17.705 median_acceptable_msg = 'Memory differences median acceptable.'
2025-03-28 12:56:17.710 if memo_rss_diff_median <= MAX_RSS_DIFFERENCE_MEDIAN:
2025-03-28 12:56:17.715 print(median_acceptable_msg)
2025-03-28 12:56:17.719 else:
2025-03-28 12:56:17.724 print(f'Memory LEAK detected. Median of differences: {memo_rss_diff_median} Kb - is UNACCEPTABLE. Check memo_rss_diff:')
2025-03-28 12:56:17.729 for p in memo_rss_diff:
2025-03-28 12:56:17.734 print('%6d' % p)
2025-03-28 12:56:17.738
2025-03-28 12:56:17.743 expected_stdout = f"""
2025-03-28 12:56:17.748 ISQL process terminated.
2025-03-28 12:56:17.753 {median_acceptable_msg}
2025-03-28 12:56:17.757 """
2025-03-28 12:56:17.762
2025-03-28 12:56:17.769 act.expected_stdout = expected_stdout
2025-03-28 12:56:17.775 act.stdout = capsys.readouterr().out
2025-03-28 12:56:17.782 >       assert act.clean_stdout == act.clean_expected_stdout
2025-03-28 12:56:17.789 E       assert
2025-03-28 12:56:17.796 E           ISQL process terminated.
2025-03-28 12:56:17.802 E         - Memory differences median acceptable.
2025-03-28 12:56:17.809 E         + Memory LEAK detected. Median of differences: 9152.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
2025-03-28 12:56:17.816 E         + 21120
2025-03-28 12:56:17.823 E         + 14592
2025-03-28 12:56:17.829 E         + 13568
2025-03-28 12:56:17.836 E         + 13440
2025-03-28 12:56:17.843 E         + 12160
2025-03-28 12:56:17.850 E         + 12800
2025-03-28 12:56:17.856 E         + 7504
2025-03-28 12:56:17.863 E         + 100
2025-03-28 12:56:17.870 E         + 9088
2025-03-28 12:56:17.877 E         + 8576
2025-03-28 12:56:17.884 E         + 9216
2025-03-28 12:56:17.891 E         + 7936
2025-03-28 12:56:17.898 E         + 7680
2025-03-28 12:56:17.908 E         + 6912
2025-03-28 12:56:17.914
2025-03-28 12:56:17.921 tests/bugs/gh_8085_test.py:129: AssertionError
2025-03-28 12:56:17.927 ---------------------------- Captured stdout setup -----------------------------
2025-03-28 12:56:17.934 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: 9152.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
E         + 21120
E         + 14592
E         + 13568
E         + 13440
E         + 12160
E         + 12800
E         + 7504
E         + 100
E         + 9088
E         + 8576
E         + 9216
E         + 7936
E         + 7680
E         + 6912

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 18637 18377 2025.06.30 12:47:06.219 2025.06.30 12:47:24.856 2025.06.30 11:26:32.495 2025.06.30 11:26:50.872
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):