#coding:utf-8 """ ID: issue-6298 ISSUE: 6298 TITLE: Provide ability to see current state of DB encryption DESCRIPTION: Test adds lot of data to database, issues 'alter database encrypt ...' and starts loop with query: 'select mon$crypt_page, mon$crypt_state from mon$database', with repeating it every 1 second. Loop continues until we find that mon$crypt_state become 1, or if ms expired. On every iteration of this loop we accumulate pairs (mon$crypt_page, mon$crypt_state) in the list, and when encryption completes we check that: * at least two measures could be done (i.e. there was no hang of query to mon$ table during encryption); * last query to mon$database returned mon$crypt_page =0 and mon$crypt_state = 1 (i.e. encryption was actually finished). JIRA: CORE-6048 FBTEST: bugs.core_6048 NOTES: [13.06.2022] pzotov Checked on 5.0.0.509 - both on Linux and Windows. ::: NB-1 ::: Currently test must check only FB 5.0! Encryption in FB 3.x and 4.x *block* obtaining data from monitoring tables. See also: https://github.com/FirebirdSQL/firebird/issues/6947 ::: NB-2 ::: Number of records that will be added into table must be sufficient big to force encryption thread work at least 3 seconds, but - at the same time - it must not be too large because we have time limit which must not be exeeded. Careful tuning required on each tesing box for this test. """ import os import time import datetime as py_dt from datetime import timedelta import pytest from firebird.qa import * from firebird.driver import DatabaseError, DbWriteMode ########################### ACHTUNG ############### # this must be carefully tuned on every new host: # ################################################### N_ROWS =15000 if os.name == 'nt' else 5000 F_LEN = 16383 init_script = f""" set bail on; create table tlog(id bigint generated by default as identity constraint pk_tlog primary key, crypt_page int, crypt_state smallint); create table test(s varchar({F_LEN})); commit; set term ^; execute block as declare n bigint = {N_ROWS}; begin while (n>0) do begin insert into test(s) values( lpad('',{F_LEN}, uuid_to_char(gen_uuid())) ); n = n - 1; end end ^ commit ^ """ db = db_factory(init = init_script, utf8filename = False, charset='none') act = python_act('db', substitutions=[('[ \t]+', ' ')]) expected_stdout = """ Number of distinct values of mon$crypt_page: EXPECTED Last measured values of mon$crypt_page and mon$crypt_state: EXPECTED """ @pytest.mark.encryption @pytest.mark.version('>=5.0') def test_1(act: Action, capsys): # QA_GLOBALS -- dict, is defined in qa/plugin.py, obtain settings # from act.files_dir/'test_config.ini': enc_settings = QA_GLOBALS['encryption'] MAX_ENCRYPT_DECRYPT_MS = int(enc_settings['max_encrypt_decrypt_ms']) # 5000 // was: 60'000 ENCRYPTION_PLUGIN = enc_settings['encryption_plugin'] # fbSampleDbCrypt ENCRYPTION_KEY = enc_settings['encryption_key'] # Red with act.connect_server() as srv: srv.database.set_write_mode(database=act.db.db_path, mode=DbWriteMode.SYNC) encryption_finished = False encryption_started = False with act.db.connect() as con, act.db.connect() as con2: t1=py_dt.datetime.now() d1 = t1-t1 sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}" key "{ENCRYPTION_KEY}"' try: con.execute_immediate(sttm) con.commit() encryption_started = True except DatabaseError as e: # -ALTER DATABASE failed # -Crypt plugin fbSampleDbCrypt failed to load # ==> no sense to do anything else, encryption_started remains False. print( e.__str__() ) cur2 = con2.cursor() ps = cur2.prepare('select mon$crypt_page, mon$crypt_state from mon$database') crypt_chronolody = [] while encryption_started: t2=py_dt.datetime.now() d1=t2-t1 if d1.seconds*1000 + d1.microseconds//1000 > MAX_ENCRYPT_DECRYPT_MS: print(f'TIMEOUT EXPIRATION: encryption took {d1.seconds*1000 + d1.microseconds//1000} ms which exceeds limit = {MAX_ENCRYPT_DECRYPT_MS} ms.') break cur2.execute(ps) crypt_page, crypt_state = cur2.fetchone() crypt_chronolody.append( (crypt_page, crypt_state) ) con2.commit() # 0 = non crypted; # 1 = has been encrypted; # 2 = is DEcrypting; # 3 = is Encrypting; if crypt_state == 1: encryption_finished = True break else: time.sleep(1) if encryption_started: # encryption_finished: crypt_chrono_pset = set([ p[0] for p in crypt_chronolody if p[1] == 3 ]) crypt_chrono_last = crypt_chronolody[-1] if len( crypt_chrono_pset ) > 1: logged_unique_crypt_pages_msg = 'EXPECTED' else: logged_unique_crypt_pages_msg = 'UNEXPECTED: len = %d; list: %s' % ( len(crypt_chrono_pset), ','.join( (str(x) for x in sorted(crypt_chrono_pset)) ) ) print('Number of distinct values of mon$crypt_page: %s' % logged_unique_crypt_pages_msg) if crypt_chrono_last == (0,1): logged_last_crypt_page_state_msg = 'EXPECTED' else: logged_last_crypt_page_state_msg = 'UNEXPECTED: %s' % ','.join( (str(x) for x in crypt_chrono_last) ) print('Last measured values of mon$crypt_page and mon$crypt_state: %s' % logged_last_crypt_page_state_msg) act.expected_stdout = expected_stdout act.stdout = capsys.readouterr().out assert act.clean_stdout == act.clean_expected_stdout act.reset()