|
| 1 | +#coding:utf-8 |
| 2 | + |
| 3 | +""" |
| 4 | +ID: issue-8085 |
| 5 | +ISSUE: https://github.com/FirebirdSQL/firebird/issues/8085 |
| 6 | +TITLE: Memory leak when executing a lot of different queries and StatementTimeout > 0 |
| 7 | +DESCRIPTION: |
| 8 | + Test launches ISQL in async mode and then checks in loop for <N_CNT> seconds value of psutil.Process( <fb_pid> ) |
| 9 | + where <fb_pid> is value of server PID that can be found in mon$attachments.mon$server_pid of ISQL connection. |
| 10 | + This value is written in auxiliary table 'tmplog' and can be obtained from it when ISQL establishes attachment. |
| 11 | + Then we collect values of memory_info().rss returned by instance of psutil.Process( <fb_pid> ) in the list, |
| 12 | + see 'memo_rss_list' variable. |
| 13 | + Collection of memory_info().rss value is made with interval 1 second. |
| 14 | + After that we reuire ISQL process to be terminated and wait for that no more than <MAX_WAIT_FOR_ISQL_TERMINATE> seconds. |
| 15 | + Finally, we evaluate differences between adjacent values from memo_rss_list. |
| 16 | + Median of these differences must be <MAX_RSS_DIFFERENCE_MEDIAN> (Kb). |
| 17 | + Before fix this median was about 650K. |
| 18 | +NOTES: |
| 19 | + [17.04.2024] pzotov |
| 20 | + Bug detected on 6.0.0.313 during implementation of test for gh-2388 (there is loop with ~20E6 iterations which run ES). |
| 21 | + Confirmed fix on intermediate snapshots: 6.0.0.321 #cc6fe45; 5.0.1.1381 #0f3cdde; 4.0.5.3086 #9d13bd3 |
| 22 | +""" |
| 23 | + |
| 24 | +import psutil |
| 25 | +import pytest |
| 26 | +import time |
| 27 | +from pathlib import Path |
| 28 | +import subprocess |
| 29 | + |
| 30 | +import firebird.driver |
| 31 | +from firebird.qa import * |
| 32 | + |
| 33 | +db = db_factory() |
| 34 | +act = python_act('db') |
| 35 | + |
| 36 | +N_CNT = 15 |
| 37 | +tmp_sql = temp_file('tmp_8085.sql') |
| 38 | +tmp_log = temp_file('tmp_8085.log') |
| 39 | + |
| 40 | +MAX_WAIT_FOR_ISQL_BEGIN_WORK=3 |
| 41 | +MAX_WAIT_FOR_ISQL_TERMINATE=11 |
| 42 | +MAX_RSS_DIFFERENCE_MEDIAN = 0 |
| 43 | + |
| 44 | +#-------------------------------------------------------------------- |
| 45 | +def median(lst): |
| 46 | + n = len(lst) |
| 47 | + s = sorted(lst) |
| 48 | + return (sum(s[n//2-1:n//2+1])/2.0, s[n//2])[n % 2] if n else None |
| 49 | +#-------------------------------------------------------------------- |
| 50 | + |
| 51 | +@pytest.mark.version('>=4.0.5') |
| 52 | +def test_1(act: Action, tmp_sql: Path, tmp_log: Path, capsys): |
| 53 | + |
| 54 | + test_sql = f""" |
| 55 | + recreate table tmplog(srv_pid int); |
| 56 | + insert into tmplog(srv_pid) |
| 57 | + select mon$server_pid as p |
| 58 | + from mon$attachments |
| 59 | + where mon$attachment_id = current_connection |
| 60 | + ; |
| 61 | + commit; |
| 62 | + SET STATEMENT TIMEOUT 7200; |
| 63 | + set term ^; |
| 64 | + execute block as |
| 65 | + declare res double precision; |
| 66 | + begin |
| 67 | + while (1=1) do |
| 68 | + begin |
| 69 | + execute statement 'select ' || rand() || ' from rdb$database' into res; |
| 70 | + end |
| 71 | + end |
| 72 | + ^ |
| 73 | + """ |
| 74 | + with open(tmp_sql, 'w') as f: |
| 75 | + f.write(test_sql) |
| 76 | + |
| 77 | + memo_rss_list = [] |
| 78 | + with act.db.connect() as con: |
| 79 | + with open(tmp_log, 'w') as f: |
| 80 | + try: |
| 81 | + p_handed_isql = subprocess.Popen( [act.vars['isql'], '-i', str(tmp_sql), |
| 82 | + '-user', act.db.user, |
| 83 | + '-password', act.db.password, act.db.dsn], |
| 84 | + stdout = f, |
| 85 | + stderr = subprocess.STDOUT |
| 86 | + ) |
| 87 | + |
| 88 | + # Let ISQL time to establish connection and start infinite loop with ES: |
| 89 | + time.sleep(MAX_WAIT_FOR_ISQL_BEGIN_WORK) |
| 90 | + |
| 91 | + cur = con.cursor() |
| 92 | + cur.execute('select srv_pid from tmplog') |
| 93 | + fb_srv = psutil.Process( int(cur.fetchone()[0]) ) |
| 94 | + |
| 95 | + for i in range(N_CNT): |
| 96 | + memo_rss_list.append(int(fb_srv.memory_info().rss / 1024)) |
| 97 | + time.sleep(1) |
| 98 | + |
| 99 | + finally: |
| 100 | + p_handed_isql.terminate() |
| 101 | + |
| 102 | + p_handed_isql.wait(MAX_WAIT_FOR_ISQL_TERMINATE) |
| 103 | + if p_handed_isql.poll() is None: |
| 104 | + print(f'ISQL process WAS NOT terminated in {MAX_WAIT_FOR_ISQL_TERMINATE} second(s).!') |
| 105 | + else: |
| 106 | + print(f'ISQL process terminated.') |
| 107 | + |
| 108 | + memo_rss_diff = [] |
| 109 | + for i,x in enumerate(memo_rss_list): |
| 110 | + if i >= 1: |
| 111 | + memo_rss_diff.append(x - memo_rss_list[i-1]) |
| 112 | + |
| 113 | + memo_rss_diff_median = median(memo_rss_diff) |
| 114 | + median_acceptable_msg = 'Memory differences median acceptable.' |
| 115 | + if memo_rss_diff_median <= MAX_RSS_DIFFERENCE_MEDIAN: |
| 116 | + print(median_acceptable_msg) |
| 117 | + else: |
| 118 | + print(f'Memory LEAK detected. Median of differences: {memo_rss_diff_median} Kb - is UNACCEPTABLE. Check memo_rss_diff:') |
| 119 | + for p in memo_rss_diff: |
| 120 | + print('%6d' % p) |
| 121 | + |
| 122 | + expected_stdout = f""" |
| 123 | + ISQL process terminated. |
| 124 | + {median_acceptable_msg} |
| 125 | + """ |
| 126 | + |
| 127 | + act.expected_stdout = expected_stdout |
| 128 | + act.stdout = capsys.readouterr().out |
| 129 | + assert act.clean_stdout == act.clean_expected_stdout |
0 commit comments