1 @message |
Performance problem
assert
- ALTER DOMAIN DROP CONSTRAINT performed for acceptable time
+ /* perf_issue_tag */ ALTER DOMAIN DROP CONSTRAINT perfomed too slow. Ratios of DML to COMMIT time:
+ 0.6000
+ 0.7000
+ 0.8889
+ 0.8889
+ 0.7778
+ 0.7000
+ 1.0000
+ 0.8889
+ 0.8889
+ 1.0000
+ 0.7000
+ Median value: 0.8889 - GREATER than threshold: 0.8000
ALTER DOMAIN ADD CONSTRAINT performed for acceptable time
LOG DETAILS:
2025-06-26 18:11:02.530
2025-06-26 18:11:02.530 act = <firebird.qa.plugin.Action object at [hex]>
2025-06-26 18:11:02.530 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2025-06-26 18:11:02.530
2025-06-26 18:11:02.530 @pytest.mark.version('>=3.0.3')
2025-06-26 18:11:02.530 def test_1(act: Action, capsys):
2025-06-26 18:11:02.530 time_data = {}
2025-06-26 18:11:02.530 with act.db.connect() as con:
2025-06-26 18:11:02.530 cur=con.cursor()
2025-06-26 18:11:02.530 cur.execute('select mon$server_pid as p from mon$attachments where mon$attachment_id = current_connection')
2025-06-26 18:11:02.530 fb_pid = int(cur.fetchone()[0])
2025-06-26 18:11:02.530
2025-06-26 18:11:02.530 for i in range(0, N_MEASURES):
2025-06-26 18:11:02.530 fb_info_1 = psutil.Process(fb_pid).cpu_times()
2025-06-26 18:11:02.530 con.execute_immediate(f'alter domain bool_emul drop constraint -- {i}')
2025-06-26 18:11:02.530 fb_info_2 = psutil.Process(fb_pid).cpu_times()
2025-06-26 18:11:02.530 con.commit()
2025-06-26 18:11:02.530 fb_info_3 = psutil.Process(fb_pid).cpu_times()
2025-06-26 18:11:02.530 time_data[ 'del_constraint', i ] = ( max(fb_info_2.user - fb_info_1.user, 0.000001), max(fb_info_3.user - fb_info_2.user, 0.000001) )
2025-06-26 18:11:02.531
2025-06-26 18:11:02.531 con.execute_immediate(f"alter domain bool_emul add check (value in ('t', 'f')) -- {i}")
2025-06-26 18:11:02.531 fb_info_4 = psutil.Process(fb_pid).cpu_times()
2025-06-26 18:11:02.531 con.commit()
2025-06-26 18:11:02.531 fb_info_5 = psutil.Process(fb_pid).cpu_times()
2025-06-26 18:11:02.531 time_data[ 'add_constraint', i ] = ( max(fb_info_4.user - fb_info_3.user, 0.000001), max(fb_info_5.user - fb_info_4.user, 0.000001) )
2025-06-26 18:11:02.531
2025-06-26 18:11:02.531
2025-06-26 18:11:02.531 del_constraint_to_commit_ratios = [ v[0] / v[1] for k,v in time_data.items() if k[0] == 'del_constraint' ]
2025-06-26 18:11:02.531 add_constraint_to_commit_ratios = [ v[0] / v[1] for k,v in time_data.items() if k[0] == 'add_constraint' ]
2025-06-26 18:11:02.531
2025-06-26 18:11:02.531 #for k,v in sorted(time_data.items()):
2025-06-26 18:11:02.531 # print(k,':::',v)
2025-06-26 18:11:02.531 #print(del_constraint_to_commit_ratios)
2025-06-26 18:11:02.531 #print(add_constraint_to_commit_ratios)
2025-06-26 18:11:02.531
2025-06-26 18:11:02.531 del_constr_to_commit_median = median(del_constraint_to_commit_ratios)
2025-06-26 18:11:02.531 add_constr_to_commit_median = median(add_constraint_to_commit_ratios)
2025-06-26 18:11:02.531
2025-06-26 18:11:02.531 msg_del_success = 'ALTER DOMAIN DROP CONSTRAINT performed for acceptable time'
2025-06-26 18:11:02.532 msg_add_success = 'ALTER DOMAIN ADD CONSTRAINT performed for acceptable time'
2025-06-26 18:11:02.532
2025-06-26 18:11:02.532 if del_constr_to_commit_median < DEL_2_COMMIT_MAX_RATIO:
2025-06-26 18:11:02.532 print(msg_del_success)
2025-06-26 18:11:02.532 else:
2025-06-26 18:11:02.532 print('/* perf_issue_tag */ ALTER DOMAIN DROP CONSTRAINT perfomed too slow. Ratios of DML to COMMIT time:')
2025-06-26 18:11:02.532 for p in del_constraint_to_commit_ratios:
2025-06-26 18:11:02.532 print('%12.4f' % p)
2025-06-26 18:11:02.532 print('Median value: %12.4f - GREATER than threshold: %12.4f' % (del_constr_to_commit_median,DEL_2_COMMIT_MAX_RATIO))
2025-06-26 18:11:02.532
2025-06-26 18:11:02.532
2025-06-26 18:11:02.532 if add_constr_to_commit_median < ADD_2_COMMIT_MAX_RATIO:
2025-06-26 18:11:02.532 print(msg_add_success)
2025-06-26 18:11:02.532 else:
2025-06-26 18:11:02.532 print('ALTER DOMAIN ADD CONSTRAINT perfomed too slow. Ratios of DML to COMMIT time:')
2025-06-26 18:11:02.532 for p in add_constraint_to_commit_ratios:
2025-06-26 18:11:02.532 print('%12.4f' % p)
2025-06-26 18:11:02.532 print('Median value: %12.4f - GREATER than threshold: %12.4f' % (add_constr_to_commit_median,ADD_2_COMMIT_MAX_RATIO))
2025-06-26 18:11:02.532
2025-06-26 18:11:02.533 expected_stdout = '''
2025-06-26 18:11:02.533 ALTER DOMAIN DROP CONSTRAINT performed for acceptable time
2025-06-26 18:11:02.533 ALTER DOMAIN ADD CONSTRAINT performed for acceptable time
2025-06-26 18:11:02.533 '''
2025-06-26 18:11:02.533
2025-06-26 18:11:02.533 act.expected_stdout = expected_stdout
2025-06-26 18:11:02.533 act.stdout = capsys.readouterr().out
2025-06-26 18:11:02.533 > assert act.clean_stdout == act.clean_expected_stdout
2025-06-26 18:11:02.533 E assert
2025-06-26 18:11:02.533 E - ALTER DOMAIN DROP CONSTRAINT performed for acceptable time
2025-06-26 18:11:02.533 E + /* perf_issue_tag */ ALTER DOMAIN DROP CONSTRAINT perfomed too slow. Ratios of DML to COMMIT time:
2025-06-26 18:11:02.533 E + 0.6000
2025-06-26 18:11:02.533 E + 0.7000
2025-06-26 18:11:02.533 E + 0.8889
2025-06-26 18:11:02.533 E + 0.8889
2025-06-26 18:11:02.533 E + 0.7778
2025-06-26 18:11:02.533 E + 0.7000
2025-06-26 18:11:02.533 E + 1.0000
2025-06-26 18:11:02.534 E + 0.8889
2025-06-26 18:11:02.534 E + 0.8889
2025-06-26 18:11:02.534 E + 1.0000
2025-06-26 18:11:02.534 E + 0.7000
2025-06-26 18:11:02.534 E + Median value: 0.8889 - GREATER than threshold: 0.8000
2025-06-26 18:11:02.534 E ALTER DOMAIN ADD CONSTRAINT performed for acceptable time
2025-06-26 18:11:02.534
2025-06-26 18:11:02.534 tests\bugs\core_5602_test.py:115: AssertionError
2025-06-26 18:11:02.534 ---------------------------- Captured stdout setup ----------------------------
2025-06-26 18:11:02.534 Restoring db: H:\QA\temp\qa2024.tmp\fbqa\test_11122\test.fdb from H:\QA\firebird-qa\backups\core5602.fbk
|
2 #text |
act = <firebird.qa.plugin.Action pytest object at [hex]>
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>
@pytest.mark.version('>=3.0.3')
def test_1(act: Action, capsys):
time_data = {}
with act.db.connect() as con:
cur=con.cursor()
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):
fb_info_1 = psutil.Process(fb_pid).cpu_times()
con.execute_immediate(f'alter domain bool_emul drop constraint -- {i}')
fb_info_2 = psutil.Process(fb_pid).cpu_times()
con.commit()
fb_info_3 = psutil.Process(fb_pid).cpu_times()
time_data[ 'del_constraint', i ] = ( max(fb_info_2.user - fb_info_1.user, 0.000001), max(fb_info_3.user - fb_info_2.user, 0.000001) )
con.execute_immediate(f"alter domain bool_emul add check (value in ('t', 'f')) -- {i}")
fb_info_4 = psutil.Process(fb_pid).cpu_times()
con.commit()
fb_info_5 = psutil.Process(fb_pid).cpu_times()
time_data[ 'add_constraint', i ] = ( max(fb_info_4.user - fb_info_3.user, 0.000001), max(fb_info_5.user - fb_info_4.user, 0.000001) )
del_constraint_to_commit_ratios = [ v[0] / v[1] for k,v in time_data.items() if k[0] == 'del_constraint' ]
add_constraint_to_commit_ratios = [ v[0] / v[1] for k,v in time_data.items() if k[0] == 'add_constraint' ]
#for k,v in sorted(time_data.items()):
# print(k,':::',v)
#print(del_constraint_to_commit_ratios)
#print(add_constraint_to_commit_ratios)
del_constr_to_commit_median = median(del_constraint_to_commit_ratios)
add_constr_to_commit_median = median(add_constraint_to_commit_ratios)
msg_del_success = 'ALTER DOMAIN DROP CONSTRAINT performed for acceptable time'
msg_add_success = 'ALTER DOMAIN ADD CONSTRAINT performed for acceptable time'
if del_constr_to_commit_median < DEL_2_COMMIT_MAX_RATIO:
print(msg_del_success)
else:
print('/* perf_issue_tag */ ALTER DOMAIN DROP CONSTRAINT perfomed too slow. Ratios of DML to COMMIT time:')
for p in del_constraint_to_commit_ratios:
print('%12.4f' % p)
print('Median value: %12.4f - GREATER than threshold: %12.4f' % (del_constr_to_commit_median,DEL_2_COMMIT_MAX_RATIO))
if add_constr_to_commit_median < ADD_2_COMMIT_MAX_RATIO:
print(msg_add_success)
else:
print('ALTER DOMAIN ADD CONSTRAINT perfomed too slow. Ratios of DML to COMMIT time:')
for p in add_constraint_to_commit_ratios:
print('%12.4f' % p)
print('Median value: %12.4f - GREATER than threshold: %12.4f' % (add_constr_to_commit_median,ADD_2_COMMIT_MAX_RATIO))
expected_stdout = '''
ALTER DOMAIN DROP CONSTRAINT performed for acceptable time
ALTER DOMAIN ADD CONSTRAINT performed for acceptable time
'''
act.expected_stdout = expected_stdout
act.stdout = capsys.readouterr().out
> assert act.clean_stdout == act.clean_expected_stdout
E assert
E - ALTER DOMAIN DROP CONSTRAINT performed for acceptable time
E + /* perf_issue_tag */ ALTER DOMAIN DROP CONSTRAINT perfomed too slow. Ratios of DML to COMMIT time:
E + 0.6000
E + 0.7000
E + 0.8889
E + 0.8889
E + 0.7778
E + 0.7000
E + 1.0000
E + 0.8889
E + 0.8889
E + 1.0000
E + 0.7000
E + Median value: 0.8889 - GREATER than threshold: 0.8000
E ALTER DOMAIN ADD CONSTRAINT performed for acceptable time
tests\bugs\core_5602_test.py:115: AssertionError
|