2 @message |
Performance problem
assert
- Median value for 21 ratios of commit_time/compile_time when create 1500 packaged PSQL objects: acceptable
- Median value for 21 ratios of commit_time/compile_time when create 1500 standalone PSQL objects: acceptable
+ Median value for 21 ratios of commit_time/compile_time when create 1500 packaged PSQL objects: /* perf_issue_tag */ UNACCEPTABLE: 0.55 -- greater than threshold = 0.55
+ Check result of 21 measures:
+ 0 : 0.53
+ 1 : 0.56
+ 2 : 0.53
+ 3 : 0.54
+ 4 : 0.59
+ 5 : 0.53
+ 6 : 0.58
+ 7 : 0.50
+ 8 : 0.55
+ 9 : 0.53
+ 10 : 0.54
+ 11 : 0.50
+ 12 : 0.61
+ 13 : 0.55
+ 14 : 0.58
+ 15 : 0.55
+ 16 : 0.54
+ 17 : 0.52
+ 18 : 0.55
+ 19 : 0.57
+ 20 : 0.55
+ Median value for 21 ratios of commit_time/compile_time when create 1500 standalone PSQL objects: /* perf_issue_tag */ UNACCEPTABLE: 0.55 -- greater than threshold = 0.50
+ Check result of 21 measures:
+ 0 : 0.89
+ 1 : 0.56
+ 2 : 0.59
+ 3 : 0.49
+ 4 : 0.54
+ 5 : 0.51
+ 6 : 0.61
+ 7 : 0.52
+ 8 : 0.59
+ 9 : 0.53
+ 10 : 0.52
+ 11 : 0.53
+ 12 : 0.59
+ 13 : 0.59
+ 14 : 0.55
+ 15 : 0.54
+ 16 : 0.60
+ 17 : 0.55
+ 18 : 0.64
+ 19 : 0.55
+ 20 : 0.66
LOG DETAILS:
2024-08-09 15:08:46.910
2024-08-09 15:08:46.916 act = <firebird.qa.plugin.Action object at [hex]>
2024-08-09 15:08:46.920 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2024-08-09 15:08:46.925
2024-08-09 15:08:46.930 @pytest.mark.version('>=3.0')
2024-08-09 15:08:46.934 def test_1(act: Action, capsys):
2024-08-09 15:08:46.938
2024-08-09 15:08:46.943 act.db.set_async_write() # just to be sure, although this is by default
2024-08-09 15:08:46.947
2024-08-09 15:08:46.952 expected_stdout = f"""
2024-08-09 15:08:46.957 Median value for {N_MEASURES} ratios of commit_time/compile_time when create {N_LIMIT} packaged PSQL objects: acceptable
2024-08-09 15:08:46.962 Median value for {N_MEASURES} ratios of commit_time/compile_time when create {N_LIMIT} standalone PSQL objects: acceptable
2024-08-09 15:08:46.966 """
2024-08-09 15:08:46.971
2024-08-09 15:08:46.975 func_headers_ddl = ''.join( [ '\n function fn_%d returns int;' % i for i in range(N_LIMIT) ] )
2024-08-09 15:08:46.980 func_bodies_ddl = ''.join( [ '\n function fn_%d returns int as begin return %d; end' % (i,i) for i in range(N_LIMIT) ] )
2024-08-09 15:08:46.985
2024-08-09 15:08:46.989 pkg_header_ddl = '\n'.join( ('create or alter package huge as\nbegin', func_headers_ddl, 'end') )
2024-08-09 15:08:46.994 pkg_body_ddl = '\n'.join( ('recreate package body huge as\nbegin', func_bodies_ddl, 'end') )
2024-08-09 15:08:46.999
2024-08-09 15:08:47.004 sp_time = {}
2024-08-09 15:08:47.009 with act.db.connect() as con:
2024-08-09 15:08:47.014
2024-08-09 15:08:47.019 with con.cursor() as cur:
2024-08-09 15:08:47.024 cur.execute('select mon$server_pid as p from mon$attachments where mon$attachment_id = current_connection')
2024-08-09 15:08:47.028 fb_pid = int(cur.fetchone()[0])
2024-08-09 15:08:47.033
2024-08-09 15:08:47.037 for i in range(0, N_MEASURES):
2024-08-09 15:08:47.042 for ftype in ('packaged', 'standalone'):
2024-08-09 15:08:47.046
2024-08-09 15:08:47.051 fb_info_a = psutil.Process(fb_pid).cpu_times()
2024-08-09 15:08:47.056 if ftype == 'packaged':
2024-08-09 15:08:47.060 con.execute_immediate(pkg_header_ddl)
2024-08-09 15:08:47.065 con.execute_immediate(pkg_body_ddl)
2024-08-09 15:08:47.070 else:
2024-08-09 15:08:47.074 for k in range(0,N_LIMIT):
2024-08-09 15:08:47.079 con.execute_immediate( 'create or alter function sf_%d returns int as begin return %d; end' % (k,k) )
2024-08-09 15:08:47.083
2024-08-09 15:08:47.088 fb_info_b = psutil.Process(fb_pid).cpu_times()
2024-08-09 15:08:47.092 con.commit()
2024-08-09 15:08:47.097 fb_info_c = psutil.Process(fb_pid).cpu_times()
2024-08-09 15:08:47.101
2024-08-09 15:08:47.106 cpu_time_for_compile = max(fb_info_b.user - fb_info_a.user, 0.000001)
2024-08-09 15:08:47.111 cpu_time_for_commit = fb_info_c.user - fb_info_b.user
2024-08-09 15:08:47.115
2024-08-09 15:08:47.120 sp_time[ ftype, i ] = cpu_time_for_commit / cpu_time_for_compile
2024-08-09 15:08:47.124
2024-08-09 15:08:47.129 commit_2_compile_ratio_for_package = [round(v,2) for k,v in sp_time.items() if k[0] == 'packaged']
2024-08-09 15:08:47.136 commit_2_compile_ratio_for_standal = [round(v,2) for k,v in sp_time.items() if k[0] == 'standalone']
2024-08-09 15:08:47.141
2024-08-09 15:08:47.147 actual_time_ratios_commit2compile = { 'packaged' : median(commit_2_compile_ratio_for_package), 'standalone': median(commit_2_compile_ratio_for_standal) }
2024-08-09 15:08:47.151
2024-08-09 15:08:47.156 for ftype in ('packaged', 'standalone'):
2024-08-09 15:08:47.160 msg = f"Median value for {N_MEASURES} ratios of commit_time/compile_time when create {N_LIMIT} {ftype} PSQL objects: "
2024-08-09 15:08:47.165 if actual_time_ratios_commit2compile[ ftype ] < MAX_TIME_RATIOS_COMMIT_TO_COMPILE[ ftype ]:
2024-08-09 15:08:47.169 print( msg + 'acceptable')
2024-08-09 15:08:47.174 else:
2024-08-09 15:08:47.178 print( msg + '/* perf_issue_tag */ UNACCEPTABLE: %12.2f -- greater than threshold = %12.2f' % (actual_time_ratios_commit2compile[ ftype ], MAX_TIME_RATIOS_COMMIT_TO_COMPILE[ ftype ]) )
2024-08-09 15:08:47.183 print( 'Check result of %d measures:' % N_MEASURES )
2024-08-09 15:08:47.187
2024-08-09 15:08:47.192 # List with concrete values (source for median evaluation):
2024-08-09 15:08:47.196 lst = commit_2_compile_ratio_for_package if ftype == 'packaged' else commit_2_compile_ratio_for_standal
2024-08-09 15:08:47.201 for i,p in enumerate(lst):
2024-08-09 15:08:47.205 print('%3d' % i, ':', '%12.2f' % p)
2024-08-09 15:08:47.210
2024-08-09 15:08:47.214
2024-08-09 15:08:47.219 act.expected_stdout = expected_stdout
2024-08-09 15:08:47.224 act.stdout = capsys.readouterr().out
2024-08-09 15:08:47.228 > assert act.clean_stdout == act.clean_expected_stdout
2024-08-09 15:08:47.233 E assert
2024-08-09 15:08:47.238 E - Median value for 21 ratios of commit_time/compile_time when create 1500 packaged PSQL objects: acceptable
2024-08-09 15:08:47.242 E - Median value for 21 ratios of commit_time/compile_time when create 1500 standalone PSQL objects: acceptable
2024-08-09 15:08:47.247 E + Median value for 21 ratios of commit_time/compile_time when create 1500 packaged PSQL objects: /* perf_issue_tag */ UNACCEPTABLE: 0.55 -- greater than threshold = 0.55
2024-08-09 15:08:47.252 E + Check result of 21 measures:
2024-08-09 15:08:47.256 E + 0 : 0.53
2024-08-09 15:08:47.262 E + 1 : 0.56
2024-08-09 15:08:47.267 E + 2 : 0.53
2024-08-09 15:08:47.271 E + 3 : 0.54
2024-08-09 15:08:47.276 E + 4 : 0.59
2024-08-09 15:08:47.281 E + 5 : 0.53
2024-08-09 15:08:47.285 E + 6 : 0.58
2024-08-09 15:08:47.289 E + 7 : 0.50
2024-08-09 15:08:47.294 E + 8 : 0.55
2024-08-09 15:08:47.298 E + 9 : 0.53
2024-08-09 15:08:47.303 E + 10 : 0.54
2024-08-09 15:08:47.308 E + 11 : 0.50
2024-08-09 15:08:47.313 E + 12 : 0.61
2024-08-09 15:08:47.317 E + 13 : 0.55
2024-08-09 15:08:47.322 E + 14 : 0.58
2024-08-09 15:08:47.326 E + 15 : 0.55
2024-08-09 15:08:47.330 E + 16 : 0.54
2024-08-09 15:08:47.335 E + 17 : 0.52
2024-08-09 15:08:47.340 E + 18 : 0.55
2024-08-09 15:08:47.344 E + 19 : 0.57
2024-08-09 15:08:47.349 E + 20 : 0.55
2024-08-09 15:08:47.353 E + Median value for 21 ratios of commit_time/compile_time when create 1500 standalone PSQL objects: /* perf_issue_tag */ UNACCEPTABLE: 0.55 -- greater than threshold = 0.50
2024-08-09 15:08:47.358 E + Check result of 21 measures:
2024-08-09 15:08:47.362 E + 0 : 0.89
2024-08-09 15:08:47.367 E + 1 : 0.56
2024-08-09 15:08:47.372 E + 2 : 0.59
2024-08-09 15:08:47.377 E + 3 : 0.49
2024-08-09 15:08:47.381 E + 4 : 0.54
2024-08-09 15:08:47.386 E + 5 : 0.51
2024-08-09 15:08:47.390 E + 6 : 0.61
2024-08-09 15:08:47.395 E + 7 : 0.52
2024-08-09 15:08:47.399 E + 8 : 0.59
2024-08-09 15:08:47.404 E + 9 : 0.53
2024-08-09 15:08:47.408 E + 10 : 0.52
2024-08-09 15:08:47.413 E + 11 : 0.53
2024-08-09 15:08:47.417 E + 12 : 0.59
2024-08-09 15:08:47.422 E + 13 : 0.59
2024-08-09 15:08:47.426 E + 14 : 0.55
2024-08-09 15:08:47.431 E + 15 : 0.54
2024-08-09 15:08:47.435 E + 16 : 0.60
2024-08-09 15:08:47.439 E + 17 : 0.55
2024-08-09 15:08:47.444 E + 18 : 0.64
2024-08-09 15:08:47.449 E + 19 : 0.55
2024-08-09 15:08:47.453 E + 20 : 0.66
2024-08-09 15:08:47.457
2024-08-09 15:08:47.462 tests/bugs/core_4880_test.py:164: AssertionError
2024-08-09 15:08:47.466 ---------------------------- Captured stdout setup -----------------------------
2024-08-09 15:08:47.471 Creating db: localhost:/var/tmp/qa_2024/test_1971/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]>
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>
@pytest.mark.version('>=3.0')
def test_1(act: Action, capsys):
act.db.set_async_write() # just to be sure, although this is by default
expected_stdout = f"""
Median value for {N_MEASURES} ratios of commit_time/compile_time when create {N_LIMIT} packaged PSQL objects: acceptable
Median value for {N_MEASURES} ratios of commit_time/compile_time when create {N_LIMIT} standalone PSQL objects: acceptable
"""
func_headers_ddl = ''.join( [ '\n function fn_%d returns int;' % i for i in range(N_LIMIT) ] )
func_bodies_ddl = ''.join( [ '\n function fn_%d returns int as begin return %d; end' % (i,i) for i in range(N_LIMIT) ] )
pkg_header_ddl = '\n'.join( ('create or alter package huge as\nbegin', func_headers_ddl, 'end') )
pkg_body_ddl = '\n'.join( ('recreate package body huge as\nbegin', func_bodies_ddl, 'end') )
sp_time = {}
with act.db.connect() as con:
with con.cursor() as cur:
cur.execute('select mon$server_pid as p from mon$attachments where mon$attachment_id = current_connection')
fb_pid = int(cur.fetchone()[0])
for i in range(0, N_MEASURES):
for ftype in ('packaged', 'standalone'):
fb_info_a = psutil.Process(fb_pid).cpu_times()
if ftype == 'packaged':
con.execute_immediate(pkg_header_ddl)
con.execute_immediate(pkg_body_ddl)
else:
for k in range(0,N_LIMIT):
con.execute_immediate( 'create or alter function sf_%d returns int as begin return %d; end' % (k,k) )
fb_info_b = psutil.Process(fb_pid).cpu_times()
con.commit()
fb_info_c = psutil.Process(fb_pid).cpu_times()
cpu_time_for_compile = max(fb_info_b.user - fb_info_a.user, 0.000001)
cpu_time_for_commit = fb_info_c.user - fb_info_b.user
sp_time[ ftype, i ] = cpu_time_for_commit / cpu_time_for_compile
commit_2_compile_ratio_for_package = [round(v,2) for k,v in sp_time.items() if k[0] == 'packaged']
commit_2_compile_ratio_for_standal = [round(v,2) for k,v in sp_time.items() if k[0] == 'standalone']
actual_time_ratios_commit2compile = { 'packaged' : median(commit_2_compile_ratio_for_package), 'standalone': median(commit_2_compile_ratio_for_standal) }
for ftype in ('packaged', 'standalone'):
msg = f"Median value for {N_MEASURES} ratios of commit_time/compile_time when create {N_LIMIT} {ftype} PSQL objects: "
if actual_time_ratios_commit2compile[ ftype ] < MAX_TIME_RATIOS_COMMIT_TO_COMPILE[ ftype ]:
print( msg + 'acceptable')
else:
print( msg + '/* perf_issue_tag */ UNACCEPTABLE: %12.2f -- greater than threshold = %12.2f' % (actual_time_ratios_commit2compile[ ftype ], MAX_TIME_RATIOS_COMMIT_TO_COMPILE[ ftype ]) )
print( 'Check result of %d measures:' % N_MEASURES )
# List with concrete values (source for median evaluation):
lst = commit_2_compile_ratio_for_package if ftype == 'packaged' else commit_2_compile_ratio_for_standal
for i,p in enumerate(lst):
print('%3d' % i, ':', '%12.2f' % p)
act.expected_stdout = expected_stdout
act.stdout = capsys.readouterr().out
> assert act.clean_stdout == act.clean_expected_stdout
E assert
E - Median value for 21 ratios of commit_time/compile_time when create 1500 packaged PSQL objects: acceptable
E - Median value for 21 ratios of commit_time/compile_time when create 1500 standalone PSQL objects: acceptable
E + Median value for 21 ratios of commit_time/compile_time when create 1500 packaged PSQL objects: /* perf_issue_tag */ UNACCEPTABLE: 0.55 -- greater than threshold = 0.55
E + Check result of 21 measures:
E + 0 : 0.53
E + 1 : 0.56
E + 2 : 0.53
E + 3 : 0.54
E + 4 : 0.59
E + 5 : 0.53
E + 6 : 0.58
E + 7 : 0.50
E + 8 : 0.55
E + 9 : 0.53
E + 10 : 0.54
E + 11 : 0.50
E + 12 : 0.61
E + 13 : 0.55
E + 14 : 0.58
E + 15 : 0.55
E + 16 : 0.54
E + 17 : 0.52
E + 18 : 0.55
E + 19 : 0.57
E + 20 : 0.55
E + Median value for 21 ratios of commit_time/compile_time when create 1500 standalone PSQL objects: /* perf_issue_tag */ UNACCEPTABLE: 0.55 -- greater than threshold = 0.50
E + Check result of 21 measures:
E + 0 : 0.89
E + 1 : 0.56
E + 2 : 0.59
E + 3 : 0.49
E + 4 : 0.54
E + 5 : 0.51
E + 6 : 0.61
E + 7 : 0.52
E + 8 : 0.59
E + 9 : 0.53
E + 10 : 0.52
E + 11 : 0.53
E + 12 : 0.59
E + 13 : 0.59
E + 14 : 0.55
E + 15 : 0.54
E + 16 : 0.60
E + 17 : 0.55
E + 18 : 0.64
E + 19 : 0.55
E + 20 : 0.66
tests/bugs/core_4880_test.py:164: AssertionError
|