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: 9536.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
  + 20352
  + 17024
  + 12416
  + 12416
  + 11520
  + 11648
  + 10496
  + 2204
  + 8576
  + 7808
  + 7936
  + 6912
  + 6656
  + 7296

LOG DETAILS:

2025-03-14 13:21:46.378
2025-03-14 13:21:46.385 act = <firebird.qa.plugin.Action object at [hex]>
2025-03-14 13:21:46.392 tmp_sql = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.sql')
2025-03-14 13:21:46.399 tmp_log = PosixPath('/var/tmp/qa_2024/test_11641/tmp_8085.log')
2025-03-14 13:21:46.406 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-03-14 13:21:46.414
2025-03-14 13:21:46.421 @pytest.mark.version('>=4.0.5')
2025-03-14 13:21:46.428 def test_1(act: Action, tmp_sql: Path, tmp_log: Path, capsys):
2025-03-14 13:21:46.435
2025-03-14 13:21:46.442 test_sql = f"""
2025-03-14 13:21:46.449 recreate table tmplog(srv_pid int);
2025-03-14 13:21:46.456 insert into tmplog(srv_pid)
2025-03-14 13:21:46.463 select mon$server_pid as p
2025-03-14 13:21:46.470 from mon$attachments
2025-03-14 13:21:46.478 where mon$attachment_id = current_connection
2025-03-14 13:21:46.489 ;
2025-03-14 13:21:46.500 commit;
2025-03-14 13:21:46.507 SET STATEMENT TIMEOUT 7200;
2025-03-14 13:21:46.513 set term ^;
2025-03-14 13:21:46.519 execute block as
2025-03-14 13:21:46.525 declare res double precision;
2025-03-14 13:21:46.531 begin
2025-03-14 13:21:46.538 while (1=1) do
2025-03-14 13:21:46.545 begin
2025-03-14 13:21:46.551 execute statement 'select ' || rand() || ' from rdb$database' into res;
2025-03-14 13:21:46.561 end
2025-03-14 13:21:46.573 end
2025-03-14 13:21:46.583 ^
2025-03-14 13:21:46.591 """
2025-03-14 13:21:46.598 with open(tmp_sql, 'w') as f:
2025-03-14 13:21:46.604 f.write(test_sql)
2025-03-14 13:21:46.611
2025-03-14 13:21:46.618 memo_rss_list = []
2025-03-14 13:21:46.627 with act.db.connect() as con:
2025-03-14 13:21:46.640 with open(tmp_log, 'w') as f:
2025-03-14 13:21:46.650 try:
2025-03-14 13:21:46.663 p_handed_isql = subprocess.Popen( [act.vars['isql'], '-i', str(tmp_sql),
2025-03-14 13:21:46.671 '-user', act.db.user,
2025-03-14 13:21:46.678 '-password', act.db.password, act.db.dsn],
2025-03-14 13:21:46.695 stdout = f,
2025-03-14 13:21:46.704 stderr = subprocess.STDOUT
2025-03-14 13:21:46.711 )
2025-03-14 13:21:46.717
2025-03-14 13:21:46.724 # Let ISQL time to establish connection and start infinite loop with ES:
2025-03-14 13:21:46.732 time.sleep(MAX_WAIT_FOR_ISQL_BEGIN_WORK)
2025-03-14 13:21:46.738
2025-03-14 13:21:46.748 cur = con.cursor()
2025-03-14 13:21:46.756 cur.execute('select srv_pid from tmplog')
2025-03-14 13:21:46.763 fb_srv = psutil.Process( int(cur.fetchone()[0]) )
2025-03-14 13:21:46.772
2025-03-14 13:21:46.785 for i in range(N_CNT):
2025-03-14 13:21:46.798 memo_rss_list.append(int(fb_srv.memory_info().rss / 1024))
2025-03-14 13:21:46.808 time.sleep(1)
2025-03-14 13:21:46.816
2025-03-14 13:21:46.829 finally:
2025-03-14 13:21:46.842 p_handed_isql.terminate()
2025-03-14 13:21:46.854
2025-03-14 13:21:46.865 p_handed_isql.wait(MAX_WAIT_FOR_ISQL_TERMINATE)
2025-03-14 13:21:46.879 if p_handed_isql.poll() is None:
2025-03-14 13:21:46.891 print(f'ISQL process WAS NOT terminated in {MAX_WAIT_FOR_ISQL_TERMINATE} second(s).!')
2025-03-14 13:21:46.902 else:
2025-03-14 13:21:46.916 print(f'ISQL process terminated.')
2025-03-14 13:21:46.926
2025-03-14 13:21:46.939 memo_rss_diff = []
2025-03-14 13:21:46.948 for i,x in enumerate(memo_rss_list):
2025-03-14 13:21:46.957 if i >= 1:
2025-03-14 13:21:46.965 memo_rss_diff.append(x - memo_rss_list[i-1])
2025-03-14 13:21:46.972
2025-03-14 13:21:46.978 memo_rss_diff_median = median(memo_rss_diff)
2025-03-14 13:21:46.983 median_acceptable_msg = 'Memory differences median acceptable.'
2025-03-14 13:21:46.990 if memo_rss_diff_median <= MAX_RSS_DIFFERENCE_MEDIAN:
2025-03-14 13:21:46.999 print(median_acceptable_msg)
2025-03-14 13:21:47.007 else:
2025-03-14 13:21:47.017 print(f'Memory LEAK detected. Median of differences: {memo_rss_diff_median} Kb - is UNACCEPTABLE. Check memo_rss_diff:')
2025-03-14 13:21:47.026 for p in memo_rss_diff:
2025-03-14 13:21:47.034 print('%6d' % p)
2025-03-14 13:21:47.048
2025-03-14 13:21:47.061 expected_stdout = f"""
2025-03-14 13:21:47.070 ISQL process terminated.
2025-03-14 13:21:47.077 {median_acceptable_msg}
2025-03-14 13:21:47.084 """
2025-03-14 13:21:47.090
2025-03-14 13:21:47.098 act.expected_stdout = expected_stdout
2025-03-14 13:21:47.113 act.stdout = capsys.readouterr().out
2025-03-14 13:21:47.124 >       assert act.clean_stdout == act.clean_expected_stdout
2025-03-14 13:21:47.131 E       assert
2025-03-14 13:21:47.144 E           ISQL process terminated.
2025-03-14 13:21:47.155 E         - Memory differences median acceptable.
2025-03-14 13:21:47.165 E         + Memory LEAK detected. Median of differences: 9536.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
2025-03-14 13:21:47.179 E         + 20352
2025-03-14 13:21:47.194 E         + 17024
2025-03-14 13:21:47.207 E         + 12416
2025-03-14 13:21:47.220 E         + 12416
2025-03-14 13:21:47.230 E         + 11520
2025-03-14 13:21:47.237 E         + 11648
2025-03-14 13:21:47.245 E         + 10496
2025-03-14 13:21:47.252 E         + 2204
2025-03-14 13:21:47.263 E         + 8576
2025-03-14 13:21:47.276 E         + 7808
2025-03-14 13:21:47.284 E         + 7936
2025-03-14 13:21:47.292 E         + 6912
2025-03-14 13:21:47.299 E         + 6656
2025-03-14 13:21:47.306 E         + 7296
2025-03-14 13:21:47.314
2025-03-14 13:21:47.323 tests/bugs/gh_8085_test.py:129: AssertionError
2025-03-14 13:21:47.331 ---------------------------- Captured stdout setup -----------------------------
2025-03-14 13:21:47.339 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: 9536.0 Kb - is UNACCEPTABLE. Check memo_rss_diff:
E         + 20352
E         + 17024
E         + 12416
E         + 12416
E         + 11520
E         + 11648
E         + 10496
E         + 2204
E         + 8576
E         + 7808
E         + 7936
E         + 6912
E         + 6656
E         + 7296

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.1657 2025.06.19 4bd4c P P 18712 18414 2025.06.26 12:12:07.918 2025.06.26 12:12:26.630 2025.06.26 10:53:23.074 2025.06.26 10:53:41.488
2 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
3 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
4 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
5 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
6 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
7 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
8 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
9 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
10 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
11 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
12 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
13 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
14 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
15 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
16 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
17 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
18 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
19 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
20 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
21 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
22 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
23 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
24 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
25 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
26 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
27 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
28 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
29 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
30 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
31 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
32 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
33 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
34 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
35 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
36 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
37 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
38 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
39 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
40 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 40 runs:

Last commits information (all timestamps in UTC):