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: 7744.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
  + 23552
  + 18432
  + 14080
  + 11776
  + 7680
  + 7552
  + 10240
  + 4612
  + 7808
  + 7680
  + 5888
  + 7168
  + 8064
  + 7168

LOG DETAILS:

2025-03-17 11:58:27.519
2025-03-17 11:58:27.527 act = <firebird.qa.plugin.Action object at [hex]>
2025-03-17 11:58:27.534 tmp_sql = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.sql')
2025-03-17 11:58:27.542 tmp_log = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.log')
2025-03-17 11:58:27.550 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-03-17 11:58:27.558
2025-03-17 11:58:27.566 @pytest.mark.version('>=4.0.5')
2025-03-17 11:58:27.574 def test_1(act: Action, tmp_sql: Path, tmp_log: Path, capsys):
2025-03-17 11:58:27.581
2025-03-17 11:58:27.588 test_sql = f"""
2025-03-17 11:58:27.596 recreate table tmplog(srv_pid int);
2025-03-17 11:58:27.603 insert into tmplog(srv_pid)
2025-03-17 11:58:27.611 select mon$server_pid as p
2025-03-17 11:58:27.618 from mon$attachments
2025-03-17 11:58:27.626 where mon$attachment_id = current_connection
2025-03-17 11:58:27.633 ;
2025-03-17 11:58:27.641 commit;
2025-03-17 11:58:27.648 SET STATEMENT TIMEOUT 7200;
2025-03-17 11:58:27.656 set term ^;
2025-03-17 11:58:27.663 execute block as
2025-03-17 11:58:27.671 declare res double precision;
2025-03-17 11:58:27.679 begin
2025-03-17 11:58:27.692 while (1=1) do
2025-03-17 11:58:27.705 begin
2025-03-17 11:58:27.715 execute statement 'select ' || rand() || ' from rdb$database' into res;
2025-03-17 11:58:27.726 end
2025-03-17 11:58:27.740 end
2025-03-17 11:58:27.751 ^
2025-03-17 11:58:27.759 """
2025-03-17 11:58:27.767 with open(tmp_sql, 'w') as f:
2025-03-17 11:58:27.773 f.write(test_sql)
2025-03-17 11:58:27.781
2025-03-17 11:58:27.788 memo_rss_list = []
2025-03-17 11:58:27.800 with act.db.connect() as con:
2025-03-17 11:58:27.814 with open(tmp_log, 'w') as f:
2025-03-17 11:58:27.826 try:
2025-03-17 11:58:27.836 p_handed_isql = subprocess.Popen( [act.vars['isql'], '-i', str(tmp_sql),
2025-03-17 11:58:27.851 '-user', act.db.user,
2025-03-17 11:58:27.864 '-password', act.db.password, act.db.dsn],
2025-03-17 11:58:27.879 stdout = f,
2025-03-17 11:58:27.891 stderr = subprocess.STDOUT
2025-03-17 11:58:27.898 )
2025-03-17 11:58:27.913
2025-03-17 11:58:27.924 # Let ISQL time to establish connection and start infinite loop with ES:
2025-03-17 11:58:27.932 time.sleep(MAX_WAIT_FOR_ISQL_BEGIN_WORK)
2025-03-17 11:58:27.939
2025-03-17 11:58:27.950 cur = con.cursor()
2025-03-17 11:58:27.960 cur.execute('select srv_pid from tmplog')
2025-03-17 11:58:27.975 fb_srv = psutil.Process( int(cur.fetchone()[0]) )
2025-03-17 11:58:27.984
2025-03-17 11:58:27.992 for i in range(N_CNT):
2025-03-17 11:58:27.999 memo_rss_list.append(int(fb_srv.memory_info().rss / 1024))
2025-03-17 11:58:28.013 time.sleep(1)
2025-03-17 11:58:28.025
2025-03-17 11:58:28.036 finally:
2025-03-17 11:58:28.047 p_handed_isql.terminate()
2025-03-17 11:58:28.062
2025-03-17 11:58:28.072 p_handed_isql.wait(MAX_WAIT_FOR_ISQL_TERMINATE)
2025-03-17 11:58:28.080 if p_handed_isql.poll() is None:
2025-03-17 11:58:28.089 print(f'ISQL process WAS NOT terminated in {MAX_WAIT_FOR_ISQL_TERMINATE} second(s).!')
2025-03-17 11:58:28.096 else:
2025-03-17 11:58:28.103 print(f'ISQL process terminated.')
2025-03-17 11:58:28.111
2025-03-17 11:58:28.120 memo_rss_diff = []
2025-03-17 11:58:28.127 for i,x in enumerate(memo_rss_list):
2025-03-17 11:58:28.134 if i >= 1:
2025-03-17 11:58:28.142 memo_rss_diff.append(x - memo_rss_list[i-1])
2025-03-17 11:58:28.150
2025-03-17 11:58:28.164 memo_rss_diff_median = median(memo_rss_diff)
2025-03-17 11:58:28.174 median_acceptable_msg = 'Memory differences median acceptable.'
2025-03-17 11:58:28.181 if memo_rss_diff_median <= MAX_RSS_DIFFERENCE_MEDIAN:
2025-03-17 11:58:28.186 print(median_acceptable_msg)
2025-03-17 11:58:28.192 else:
2025-03-17 11:58:28.199 print(f'Memory LEAK detected. Median of differences: {memo_rss_diff_median} Kb - is UNACCEPTABLE. Check memo_rss_diff:')
2025-03-17 11:58:28.206 for p in memo_rss_diff:
2025-03-17 11:58:28.222 print('%6d' % p)
2025-03-17 11:58:28.232
2025-03-17 11:58:28.241 expected_stdout = f"""
2025-03-17 11:58:28.247 ISQL process terminated.
2025-03-17 11:58:28.264 {median_acceptable_msg}
2025-03-17 11:58:28.271 """
2025-03-17 11:58:28.280
2025-03-17 11:58:28.287 act.expected_stdout = expected_stdout
2025-03-17 11:58:28.294 act.stdout = capsys.readouterr().out
2025-03-17 11:58:28.303 >       assert act.clean_stdout == act.clean_expected_stdout
2025-03-17 11:58:28.310 E       assert
2025-03-17 11:58:28.323 E           ISQL process terminated.
2025-03-17 11:58:28.333 E         - Memory differences median acceptable.
2025-03-17 11:58:28.343 E         + Memory LEAK detected. Median of differences: 7744.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
2025-03-17 11:58:28.350 E         + 23552
2025-03-17 11:58:28.358 E         + 18432
2025-03-17 11:58:28.365 E         + 14080
2025-03-17 11:58:28.378 E         + 11776
2025-03-17 11:58:28.390 E         + 7680
2025-03-17 11:58:28.400 E         + 7552
2025-03-17 11:58:28.412 E         + 10240
2025-03-17 11:58:28.424 E         + 4612
2025-03-17 11:58:28.438 E         + 7808
2025-03-17 11:58:28.449 E         + 7680
2025-03-17 11:58:28.458 E         + 5888
2025-03-17 11:58:28.466 E         + 7168
2025-03-17 11:58:28.473 E         + 8064
2025-03-17 11:58:28.480 E         + 7168
2025-03-17 11:58:28.487
2025-03-17 11:58:28.495 tests/bugs/gh_8085_test.py:129: AssertionError
2025-03-17 11:58:28.507 ---------------------------- Captured stdout setup -----------------------------
2025-03-17 11:58:28.518 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: 7744.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
E         + 23552
E         + 18432
E         + 14080
E         + 11776
E         + 7680
E         + 7552
E         + 10240
E         + 4612
E         + 7808
E         + 7680
E         + 5888
E         + 7168
E         + 8064
E         + 7168

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):