Jump to: output_first_mismatch    outcomes_full_history    elapsed_time_chart
Show cross-report outcomes.

Annotation type Annotation details
1 @message
NameError: name 'DatabaseError' is not defined

LOG DETAILS:

2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 act = <firebird.qa.plugin.Action object at [hex]>, mode = 'encrypt'
2024-04-21 04:46:56.618 max_wait_encr_thread_finish = 10000
2024-04-21 04:46:56.618 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618     def run_encr_decr(act: Action, mode, max_wait_encr_thread_finish, capsys):
2024-04-21 04:46:56.618         if mode == 'encrypt':
2024-04-21 04:46:56.618             # alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}"' # <<< ::: NB ::: DO NOT add '... key "{ENCRYPTION_KEY}"' here!
2024-04-21 04:46:56.618             alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}" key "{ENCRYPTION_KEY}"'
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618             wait_for_state = 'Database encrypted'
2024-04-21 04:46:56.618         elif mode == 'decrypt':
2024-04-21 04:46:56.618             alter_db_sttm = 'alter database decrypt'
2024-04-21 04:46:56.618             wait_for_state = 'Database not encrypted'
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         e_thread_finished = False
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         # 0 = non crypted;
2024-04-21 04:46:56.618         # 1 = has been encrypted;
2024-04-21 04:46:56.618         # 2 = is DEcrypting;
2024-04-21 04:46:56.618         # 3 = is Encrypting;
2024-04-21 04:46:56.618         #
2024-04-21 04:46:56.618         # only since FB 4.x: REQUIRED_CRYPT_STATE = 1 if mode == 'encrypt' else 0
2024-04-21 04:46:56.618         current_crypt_state = -1
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         REQUIRED_CRYPT_PAGE = 0
2024-04-21 04:46:56.618         current_crypt_page = -1
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         d1 = py_dt.timedelta(0)
2024-04-21 04:46:56.618         with act.db.connect() as con:
2024-04-21 04:46:56.618             t1=py_dt.datetime.now()
2024-04-21 04:46:56.618             try:
2024-04-21 04:46:56.618                 d1 = t1-t1
2024-04-21 04:46:56.618 >               con.execute_immediate(alter_db_sttm)
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 tests\bugs\core_5501_test.py:189:
2024-04-21 04:46:56.618 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 self = Connection[3720]
2024-04-21 04:46:56.618 sql = 'alter database encrypt with "fbSampleDbCrypt" key "Red"'
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618     def execute_immediate(self, sql: str) -> None:
2024-04-21 04:46:56.618         """Executes SQL statement.
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         Important:
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618             The statement MUST NOT return any result. The statement is executed in the
2024-04-21 04:46:56.618             context of `.main_transaction`.
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         Arguments:
2024-04-21 04:46:56.618            sql: SQL statement to be executed.
2024-04-21 04:46:56.618         """
2024-04-21 04:46:56.618         assert self._att is not None
2024-04-21 04:46:56.618 >       self.main_transaction.execute_immediate(sql)
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 C:\Python3x\Lib\site-packages\firebird\driver\core.py:1806:
2024-04-21 04:46:56.618 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 self = <firebird.driver.core.TransactionManager object at [hex]>
2024-04-21 04:46:56.618 sql = 'alter database encrypt with "fbSampleDbCrypt" key "Red"'
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618     def execute_immediate(self, sql: str) -> None:
2024-04-21 04:46:56.618         """Executes SQL statement. The statement MUST NOT return any result.
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         Arguments:
2024-04-21 04:46:56.618            sql: SQL statement to be executed.
2024-04-21 04:46:56.618         """
2024-04-21 04:46:56.618         assert not self.__closed
2024-04-21 04:46:56.618         if not self.is_active():
2024-04-21 04:46:56.618             self.begin()
2024-04-21 04:46:56.618 >       self._connection()._att.execute(self._tra, sql, self._connection().sql_dialect)
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 C:\Python3x\Lib\site-packages\firebird\driver\core.py:2431:
2024-04-21 04:46:56.618 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 self = <firebird.driver.interfaces.iAttachment_v3 object at [hex]>
2024-04-21 04:46:56.618 transaction = <firebird.driver.interfaces.iTransaction_v3 object at [hex]>
2024-04-21 04:46:56.618 stmt = 'alter database encrypt with "fbSampleDbCrypt" key "Red"', dialect = 3
2024-04-21 04:46:56.618 in_metadata = None, in_buffer = None, out_metadata = None, out_buffer = None
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         def execute(self, transaction: iTransaction, stmt: str, dialect: int,
2024-04-21 04:46:56.618                     in_metadata: iMessageMetadata = None, in_buffer: bytes = None,
2024-04-21 04:46:56.618                     out_metadata: iMessageMetadata = None, out_buffer: bytes = None) -> None:
2024-04-21 04:46:56.618             """Executes any SQL statement except returning multiple rows of data.
2024-04-21 04:46:56.618     Partial analogue of `isc_dsql_execute2()` - in and out XSLQDAs replaced with
2024-04-21 04:46:56.618     input and output messages with appropriate buffers."""
2024-04-21 04:46:56.618             b_stmt: bytes = stmt.encode(self.encoding)
2024-04-21 04:46:56.618             result = self.vtable.execute(self, self.status, transaction, len(b_stmt), b_stmt,
2024-04-21 04:46:56.618                                          dialect, in_metadata, in_buffer, out_metadata, out_buffer)
2024-04-21 04:46:56.618 >           self._check()
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 C:\Python3x\Lib\site-packages\firebird\driver\interfaces.py:1145:
2024-04-21 04:46:56.618 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 self = <firebird.driver.interfaces.iAttachment_v3 object at [hex]>
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618     def _check(self) -> None:
2024-04-21 04:46:56.618         state = self.status.get_state()
2024-04-21 04:46:56.618         if StateFlag.ERRORS in state:
2024-04-21 04:46:56.618 >           raise self.__report(DatabaseError, self.status.get_errors())
2024-04-21 04:46:56.618 E           firebird.driver.types.DatabaseError: unsuccessful metadata update
2024-04-21 04:46:56.618 E           -ALTER DATABASE failed
2024-04-21 04:46:56.618 E           -Missing correct crypt key
2024-04-21 04:46:56.618 E           -Plugin fbSampleDbCrypt:
2024-04-21 04:46:56.618 E           -Crypt key Red not set
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 C:\Python3x\Lib\site-packages\firebird\driver\interfaces.py:113: DatabaseError
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 During handling of the above exception, another exception occurred:
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618 act = <firebird.qa.plugin.Action object at [hex]>
2024-04-21 04:46:56.618 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618     @pytest.mark.encryption
2024-04-21 04:46:56.618     @pytest.mark.version('>=3.0.2')
2024-04-21 04:46:56.618     def test_1(act: Action, capsys):
2024-04-21 04:46:56.618         map_dbo = {}
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         # Query to find first generators page number:
2024-04-21 04:46:56.618         first_gens_page_sql = f"""
2024-04-21 04:46:56.618             select p.rdb$page_number
2024-04-21 04:46:56.618             from rdb$pages p
2024-04-21 04:46:56.618             where p.rdb$page_type = {GENS_PAGE}
2024-04-21 04:46:56.618             order by p.rdb$page_number desc
2024-04-21 04:46:56.618             rows 1
2024-04-21 04:46:56.618         """
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         # Query to find relation_id and first PP for 'TEST' table:
2024-04-21 04:46:56.618         first_pp_sql = f"""
2024-04-21 04:46:56.618             select p.rdb$relation_id, p.rdb$page_number
2024-04-21 04:46:56.618             from rdb$pages p
2024-04-21 04:46:56.618             join rdb$relations r on p.rdb$relation_id = r.rdb$relation_id
2024-04-21 04:46:56.618             where r.rdb$relation_name=upper('TEST') and p.rdb$page_type = {POINTER_PAGE}
2024-04-21 04:46:56.618             order by p.rdb$page_number
2024-04-21 04:46:56.618             rows 1
2024-04-21 04:46:56.618         """
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         broken_pages_map = { POINTER_PAGE : [], DATA_PAGE : [], IDX_ROOT_PAGE : [], IDX_B_TREE : [], BLOB_PAGE : [], GENS_PAGE : [] }
2024-04-21 04:46:56.618         with act.db.connect() as con:
2024-04-21 04:46:56.618             fill_dbo(con, map_dbo)
2024-04-21 04:46:56.618             c = con.cursor()
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618             broken_pages_map[GENS_PAGE] = [c.execute(first_gens_page_sql).fetchone()[0],]
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618             test_rel_id, test_rel_first_pp = c.execute(first_pp_sql).fetchone()
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618             # Found first page for each of three types: Data, Index and Blob
2024-04-21 04:46:56.618             # (loop starts from first PointerPage of table 'TEST')
2024-04-21 04:46:56.618             brk_datapage = brk_indxpage = brk_blobpage = -1
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618             for page_no in range(test_rel_first_pp, con.info.pages_allocated):
2024-04-21 04:46:56.618                 page_type, relation_id, page_info = parse_page_header(con, page_no, map_dbo)
2024-04-21 04:46:56.618                 #print('page:',page_no, '; page_type:',page_type, '; test_rel_id:',relation_id,';',  page_info)
2024-04-21 04:46:56.618                 if relation_id == test_rel_id and page_type == POINTER_PAGE:
2024-04-21 04:46:56.618                     brk_datapage = page_no
2024-04-21 04:46:56.618                     broken_pages_map[POINTER_PAGE].append(page_no)
2024-04-21 04:46:56.618                 elif relation_id == test_rel_id and page_type == DATA_PAGE:
2024-04-21 04:46:56.618                     brk_datapage = page_no
2024-04-21 04:46:56.618                     broken_pages_map[DATA_PAGE].append(page_no)
2024-04-21 04:46:56.618                 elif relation_id == test_rel_id and page_type == IDX_ROOT_PAGE:
2024-04-21 04:46:56.618                     brk_indxpage = page_no
2024-04-21 04:46:56.618                     broken_pages_map[IDX_ROOT_PAGE].append(page_no)
2024-04-21 04:46:56.618                 elif relation_id == test_rel_id and page_type == IDX_B_TREE:
2024-04-21 04:46:56.618                     brk_indxpage = page_no
2024-04-21 04:46:56.618                     broken_pages_map[IDX_B_TREE].append(page_no)
2024-04-21 04:46:56.618                 elif page_type == BLOB_PAGE: #  relation_id == test_rel_id and
2024-04-21 04:46:56.618                     brk_blobpage = page_no
2024-04-21 04:46:56.618                     broken_pages_map[BLOB_PAGE].append(page_no)
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618                 if min([ len(v) for v in broken_pages_map.values() ]) > 0:
2024-04-21 04:46:56.618                     break
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618                 #if brk_datapage > 0 and brk_indxpage > 0 and brk_blobpage > 0:
2024-04-21 04:46:56.618                 #    break
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         assert min([ len(v) for v in broken_pages_map.values() ]) > 0, f'At least one of required page types was not found: broken_pages_map = {broken_pages_map}'
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         # Preserve binary content of .fdb for futher restore:
2024-04-21 04:46:56.618         #
2024-04-21 04:46:56.618         raw_db_content = act.db.db_path.read_bytes()
2024-04-21 04:46:56.618
2024-04-21 04:46:56.618         #################################################
2024-04-21 04:46:56.618         ###   P U T    G A R B A G E    I N     D B   ###
2024-04-21 04:46:56.618         #################################################
2024-04-21 04:46:56.618         # DO NOT!! >>> garbage_bytes = bytearray(os.urandom(16)) -- this can cause missed 'Other pages:' line in the 'gstat -e' output
2024-04-21 04:46:56.618         garbage_bytes = bytearray(b'\x1e\xaa\\,es\x06\x92B3\x0c\xa7e\xa6\x04\x0f') # <<< this value WILL CAUSE appearance of line 'Other pages' in the 'gstat -e' output'
2024-04-21 04:46:56.618         with open(act.db.db_path, 'r+b') as w:
2024-04-21 04:46:56.618             for pg_type, pg_no_lst in broken_pages_map.items():
2024-04-21 04:46:56.618                 # See letters to Vlad, 17-feb-2024.
2024-04-21 04:46:56.618                 # We have to PRESERVE from damage TWO page types: POINTER_PAGE and IDX_ROOT_PAGE.
2024-04-21 04:46:56.618                 # If we preserve from damage only POINTER_PAGE then
2024-04-21 04:46:56.618                 # 5.0.1.1340 and 6.0.0.264 will crash during validation via TCP.
2024-04-21 04:46:56.618                 # 3.0.12.33791 and 4.0.5.3059 will perform validation but DB remains opened and second call to validation fails with
2024-04-21 04:46:56.618                 #     bad parameters on attach or create database
2024-04-21 04:46:56.618                 #     -secondary server attachments cannot validate databases
2024-04-21 04:46:56.618                 # Also, if IDX_ROOT_PAGE is damaged then b-tree pages will not be handled during validation (no messages in firebird.log about them).
2024-04-21 04:46:56.633                 if pg_type in (POINTER_PAGE,IDX_ROOT_PAGE):
2024-04-21 04:46:56.633                      pass
2024-04-21 04:46:56.633                 else:
2024-04-21 04:46:56.633                     for p in pg_no_lst:
2024-04-21 04:46:56.633                         w.seek(p * con.info.page_size)
2024-04-21 04:46:56.633                         w.write(garbage_bytes)
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633         ############################################
2024-04-21 04:46:56.633         ###   E N C R Y P T    D A T A B A S E   ###
2024-04-21 04:46:56.633         ############################################
2024-04-21 04:46:56.633 >       run_encr_decr(act, 'encrypt', MAX_WAITING_ENCR_FINISH, capsys)
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633 tests\bugs\core_5501_test.py:480:
2024-04-21 04:46:56.633 _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633 act = <firebird.qa.plugin.Action object at [hex]>, mode = 'encrypt'
2024-04-21 04:46:56.633 max_wait_encr_thread_finish = 10000
2024-04-21 04:46:56.633 capsys = <_pytest.capture.CaptureFixture object at [hex]>
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633     def run_encr_decr(act: Action, mode, max_wait_encr_thread_finish, capsys):
2024-04-21 04:46:56.633         if mode == 'encrypt':
2024-04-21 04:46:56.633             # alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}"' # <<< ::: NB ::: DO NOT add '... key "{ENCRYPTION_KEY}"' here!
2024-04-21 04:46:56.633             alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}" key "{ENCRYPTION_KEY}"'
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633             wait_for_state = 'Database encrypted'
2024-04-21 04:46:56.633         elif mode == 'decrypt':
2024-04-21 04:46:56.633             alter_db_sttm = 'alter database decrypt'
2024-04-21 04:46:56.633             wait_for_state = 'Database not encrypted'
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633         e_thread_finished = False
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633         # 0 = non crypted;
2024-04-21 04:46:56.633         # 1 = has been encrypted;
2024-04-21 04:46:56.633         # 2 = is DEcrypting;
2024-04-21 04:46:56.633         # 3 = is Encrypting;
2024-04-21 04:46:56.633         #
2024-04-21 04:46:56.633         # only since FB 4.x: REQUIRED_CRYPT_STATE = 1 if mode == 'encrypt' else 0
2024-04-21 04:46:56.633         current_crypt_state = -1
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633         REQUIRED_CRYPT_PAGE = 0
2024-04-21 04:46:56.633         current_crypt_page = -1
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633         d1 = py_dt.timedelta(0)
2024-04-21 04:46:56.633         with act.db.connect() as con:
2024-04-21 04:46:56.633             t1=py_dt.datetime.now()
2024-04-21 04:46:56.633             try:
2024-04-21 04:46:56.633                 d1 = t1-t1
2024-04-21 04:46:56.633                 con.execute_immediate(alter_db_sttm)
2024-04-21 04:46:56.633                 con.commit()
2024-04-21 04:46:56.633                 time.sleep(1)
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633                 # Pattern to check for completed encryption thread:
2024-04-21 04:46:56.633                 completed_encr_pattern = re.compile(f'Attributes\\s+encrypted,\\s+plugin\\s+{ENCRYPTION_PLUGIN}', re.IGNORECASE)
2024-04-21 04:46:56.633                 while True:
2024-04-21 04:46:56.633                     t2=py_dt.datetime.now()
2024-04-21 04:46:56.633                     d1=t2-t1
2024-04-21 04:46:56.633                     if d1.seconds*1000 + d1.microseconds//1000 > max_wait_encr_thread_finish:
2024-04-21 04:46:56.633                         break
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633                     ######################################################
2024-04-21 04:46:56.633                     ###   C H E C K    M O N $ C R Y P T _ S T A T E   ###
2024-04-21 04:46:56.633                     ######################################################
2024-04-21 04:46:56.633                     # Invoke 'gstat -h' and read its ouput.
2024-04-21 04:46:56.633                     # Encryption can be considered as COMPLETED when we will found:
2024-04-21 04:46:56.633                     # "Attributes              encrypted, plugin fbSampleDbCrypt"
2024-04-21 04:46:56.633                     #
2024-04-21 04:46:56.633                     act.gstat(switches=['-h'])
2024-04-21 04:46:56.633                     for line in act.stdout.splitlines():
2024-04-21 04:46:56.633                         if completed_encr_pattern.match(line.strip()):
2024-04-21 04:46:56.633                             e_thread_finished = True
2024-04-21 04:46:56.633                             break
2024-04-21 04:46:56.633                     if e_thread_finished:
2024-04-21 04:46:56.633                         break
2024-04-21 04:46:56.633                     else:
2024-04-21 04:46:56.633                         time.sleep(0.5)
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633 >           except DatabaseError as e:
2024-04-21 04:46:56.633 E           NameError: name 'DatabaseError' is not defined
2024-04-21 04:46:56.633
2024-04-21 04:46:56.633 tests\bugs\core_5501_test.py:218: NameError
2024-04-21 04:46:56.633 ---------------------------- Captured stdout setup ----------------------------
2024-04-21 04:46:56.633 Cached db: db-12.0-8192-None-NONE.fdb [page_size=8192, sql_dialect=None, charset='NONE'
2 #text
act = <firebird.qa.plugin.Action pytest object at [hex]>, mode = 'encrypt'
max_wait_encr_thread_finish = 10000
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    def run_encr_decr(act: Action, mode, max_wait_encr_thread_finish, capsys):
        if mode == 'encrypt':
            # alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}"' # <<< ::: NB ::: DO NOT add '... key "{ENCRYPTION_KEY}"' here!
            alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}" key "{ENCRYPTION_KEY}"'
    
            wait_for_state = 'Database encrypted'
        elif mode == 'decrypt':
            alter_db_sttm = 'alter database decrypt'
            wait_for_state = 'Database not encrypted'
    
        e_thread_finished = False
    
        # 0 = non crypted;
        # 1 = has been encrypted;
        # 2 = is DEcrypting;
        # 3 = is Encrypting;
        #
        # only since FB 4.x: REQUIRED_CRYPT_STATE = 1 if mode == 'encrypt' else 0
        current_crypt_state = -1
    
        REQUIRED_CRYPT_PAGE = 0
        current_crypt_page = -1
    
        d1 = py_dt.timedelta(0)
        with act.db.connect() as con:
            t1=py_dt.datetime.now()
            try:
                d1 = t1-t1
>               con.execute_immediate(alter_db_sttm)

tests\bugs\core_5501_test.py:189: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = Connection[3720]
sql = 'alter database encrypt with "fbSampleDbCrypt" key "Red"'

    def execute_immediate(self, sql: str) -> None:
        """Executes SQL statement.
    
        Important:
    
            The statement MUST NOT return any result. The statement is executed in the
            context of `.main_transaction`.
    
        Arguments:
           sql: SQL statement to be executed.
        """
        assert self._att is not None
>       self.main_transaction.execute_immediate(sql)

C:\Python3x\Lib\site-packages\firebird\driver\core.py:1806: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <firebird.driver.core.TransactionManager pytest object at [hex]>
sql = 'alter database encrypt with "fbSampleDbCrypt" key "Red"'

    def execute_immediate(self, sql: str) -> None:
        """Executes SQL statement. The statement MUST NOT return any result.
    
        Arguments:
           sql: SQL statement to be executed.
        """
        assert not self.__closed
        if not self.is_active():
            self.begin()
>       self._connection()._att.execute(self._tra, sql, self._connection().sql_dialect)

C:\Python3x\Lib\site-packages\firebird\driver\core.py:2431: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <firebird.driver.interfaces.iAttachment_v3 pytest object at [hex]>
transaction = <firebird.driver.interfaces.iTransaction_v3 pytest object at [hex]>
stmt = 'alter database encrypt with "fbSampleDbCrypt" key "Red"', dialect = 3
in_metadata = None, in_buffer = None, out_metadata = None, out_buffer = None

        def execute(self, transaction: iTransaction, stmt: str, dialect: int,
                    in_metadata: iMessageMetadata = None, in_buffer: bytes = None,
                    out_metadata: iMessageMetadata = None, out_buffer: bytes = None) -> None:
            """Executes any SQL statement except returning multiple rows of data.
    Partial analogue of `isc_dsql_execute2()` - in and out XSLQDAs replaced with
    input and output messages with appropriate buffers."""
            b_stmt: bytes = stmt.encode(self.encoding)
            result = self.vtable.execute(self, self.status, transaction, len(b_stmt), b_stmt,
                                         dialect, in_metadata, in_buffer, out_metadata, out_buffer)
>           self._check()

C:\Python3x\Lib\site-packages\firebird\driver\interfaces.py:1145: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

self = <firebird.driver.interfaces.iAttachment_v3 pytest object at [hex]>

    def _check(self) -> None:
        state = self.status.get_state()
        if StateFlag.ERRORS in state:
>           raise self.__report(DatabaseError, self.status.get_errors())
E           firebird.driver.types.DatabaseError: unsuccessful metadata update
E           -ALTER DATABASE failed
E           -Missing correct crypt key
E           -Plugin fbSampleDbCrypt:
E           -Crypt key Red not set

C:\Python3x\Lib\site-packages\firebird\driver\interfaces.py:113: DatabaseError

During handling of the above exception, another exception occurred:

act = <firebird.qa.plugin.Action pytest object at [hex]>
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    @pytest.mark.encryption
    @pytest.mark.version('>=3.0.2')
    def test_1(act: Action, capsys):
        map_dbo = {}
    
        # Query to find first generators page number:
        first_gens_page_sql = f"""
            select p.rdb$page_number
            from rdb$pages p
            where p.rdb$page_type = {GENS_PAGE}
            order by p.rdb$page_number desc
            rows 1
        """
    
        # Query to find relation_id and first PP for 'TEST' table:
        first_pp_sql = f"""
            select p.rdb$relation_id, p.rdb$page_number
            from rdb$pages p
            join rdb$relations r on p.rdb$relation_id = r.rdb$relation_id
            where r.rdb$relation_name=upper('TEST') and p.rdb$page_type = {POINTER_PAGE}
            order by p.rdb$page_number
            rows 1
        """
    
        broken_pages_map = { POINTER_PAGE : [], DATA_PAGE : [], IDX_ROOT_PAGE : [], IDX_B_TREE : [], BLOB_PAGE : [], GENS_PAGE : [] }
        with act.db.connect() as con:
            fill_dbo(con, map_dbo)
            c = con.cursor()
    
            broken_pages_map[GENS_PAGE] = [c.execute(first_gens_page_sql).fetchone()[0],]
    
            test_rel_id, test_rel_first_pp = c.execute(first_pp_sql).fetchone()
    
            # Found first page for each of three types: Data, Index and Blob
            # (loop starts from first PointerPage of table 'TEST')
            brk_datapage = brk_indxpage = brk_blobpage = -1
    
            for page_no in range(test_rel_first_pp, con.info.pages_allocated):
                page_type, relation_id, page_info = parse_page_header(con, page_no, map_dbo)
                #print('page:',page_no, '; page_type:',page_type, '; test_rel_id:',relation_id,';',  page_info)
                if relation_id == test_rel_id and page_type == POINTER_PAGE:
                    brk_datapage = page_no
                    broken_pages_map[POINTER_PAGE].append(page_no)
                elif relation_id == test_rel_id and page_type == DATA_PAGE:
                    brk_datapage = page_no
                    broken_pages_map[DATA_PAGE].append(page_no)
                elif relation_id == test_rel_id and page_type == IDX_ROOT_PAGE:
                    brk_indxpage = page_no
                    broken_pages_map[IDX_ROOT_PAGE].append(page_no)
                elif relation_id == test_rel_id and page_type == IDX_B_TREE:
                    brk_indxpage = page_no
                    broken_pages_map[IDX_B_TREE].append(page_no)
                elif page_type == BLOB_PAGE: #  relation_id == test_rel_id and
                    brk_blobpage = page_no
                    broken_pages_map[BLOB_PAGE].append(page_no)
    
                if min([ len(v) for v in broken_pages_map.values() ]) > 0:
                    break
    
                #if brk_datapage > 0 and brk_indxpage > 0 and brk_blobpage > 0:
                #    break
    
    
        assert min([ len(v) for v in broken_pages_map.values() ]) > 0, f'At least one of required page types was not found: broken_pages_map = {broken_pages_map}'
    
        # Preserve binary content of .fdb for futher restore:
        #
        raw_db_content = act.db.db_path.read_bytes()
    
        #################################################
        ###   P U T    G A R B A G E    I N     D B   ###
        #################################################
        # DO NOT!! >>> garbage_bytes = bytearray(os.urandom(16)) -- this can cause missed 'Other pages:' line in the 'gstat -e' output
        garbage_bytes = bytearray(b'\x1e\xaa\\,es\x06\x92B3\x0c\xa7e\xa6\x04\x0f') # <<< this value WILL CAUSE appearance of line 'Other pages' in the 'gstat -e' output'
        with open(act.db.db_path, 'r+b') as w:
            for pg_type, pg_no_lst in broken_pages_map.items():
                # See letters to Vlad, 17-feb-2024.
                # We have to PRESERVE from damage TWO page types: POINTER_PAGE and IDX_ROOT_PAGE.
                # If we preserve from damage only POINTER_PAGE then
                # 5.0.1.1340 and 6.0.0.264 will crash during validation via TCP.
                # 3.0.12.33791 and 4.0.5.3059 will perform validation but DB remains opened and second call to validation fails with
                #     bad parameters on attach or create database
                #     -secondary server attachments cannot validate databases
                # Also, if IDX_ROOT_PAGE is damaged then b-tree pages will not be handled during validation (no messages in firebird.log about them).
                if pg_type in (POINTER_PAGE,IDX_ROOT_PAGE):
                     pass
                else:
                    for p in pg_no_lst:
                        w.seek(p * con.info.page_size)
                        w.write(garbage_bytes)
    
    
        ############################################
        ###   E N C R Y P T    D A T A B A S E   ###
        ############################################
>       run_encr_decr(act, 'encrypt', MAX_WAITING_ENCR_FINISH, capsys)

tests\bugs\core_5501_test.py:480: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _

act = <firebird.qa.plugin.Action pytest object at [hex]>, mode = 'encrypt'
max_wait_encr_thread_finish = 10000
capsys = <_pytest.capture.CaptureFixture pytest object at [hex]>

    def run_encr_decr(act: Action, mode, max_wait_encr_thread_finish, capsys):
        if mode == 'encrypt':
            # alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}"' # <<< ::: NB ::: DO NOT add '... key "{ENCRYPTION_KEY}"' here!
            alter_db_sttm = f'alter database encrypt with "{ENCRYPTION_PLUGIN}" key "{ENCRYPTION_KEY}"'
    
            wait_for_state = 'Database encrypted'
        elif mode == 'decrypt':
            alter_db_sttm = 'alter database decrypt'
            wait_for_state = 'Database not encrypted'
    
        e_thread_finished = False
    
        # 0 = non crypted;
        # 1 = has been encrypted;
        # 2 = is DEcrypting;
        # 3 = is Encrypting;
        #
        # only since FB 4.x: REQUIRED_CRYPT_STATE = 1 if mode == 'encrypt' else 0
        current_crypt_state = -1
    
        REQUIRED_CRYPT_PAGE = 0
        current_crypt_page = -1
    
        d1 = py_dt.timedelta(0)
        with act.db.connect() as con:
            t1=py_dt.datetime.now()
            try:
                d1 = t1-t1
                con.execute_immediate(alter_db_sttm)
                con.commit()
                time.sleep(1)
    
                # Pattern to check for completed encryption thread:
                completed_encr_pattern = re.compile(f'Attributes\\s+encrypted,\\s+plugin\\s+{ENCRYPTION_PLUGIN}', re.IGNORECASE)
                while True:
                    t2=py_dt.datetime.now()
                    d1=t2-t1
                    if d1.seconds*1000 + d1.microseconds//1000 > max_wait_encr_thread_finish:
                        break
    
                    ######################################################
                    ###   C H E C K    M O N $ C R Y P T _ S T A T E   ###
                    ######################################################
                    # Invoke 'gstat -h' and read its ouput.
                    # Encryption can be considered as COMPLETED when we will found:
                    # "Attributes              encrypted, plugin fbSampleDbCrypt"
                    #
                    act.gstat(switches=['-h'])
                    for line in act.stdout.splitlines():
                        if completed_encr_pattern.match(line.strip()):
                            e_thread_finished = True
                            break
                    if e_thread_finished:
                        break
                    else:
                        time.sleep(0.5)
    
>           except DatabaseError as e:
E           NameError: name 'DatabaseError' is not defined

tests\bugs\core_5501_test.py:218: NameError
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 3.0.13.33809 2025.05.14 6638e P P 2525 1722 2025.06.30 14:39:33.823 2025.06.30 14:39:36.348 2025.06.30 14:04:40.352 2025.06.30 14:04:42.074
2 3.0.13.33809 2025.05.06 28ad0 P P 2579 1712 2025.05.14 08:19:12.751 2025.05.14 08:19:15.330 2025.05.14 07:42:49.527 2025.05.14 07:42:51.239
3 3.0.13.33808 2025.04.25 28426 P P 2729 1716 2025.05.06 13:30:02.956 2025.05.06 13:30:05.685 2025.05.06 12:55:30.521 2025.05.06 12:55:32.237
4 3.0.13.33803 2025.04.23 307b8 P P 2481 1843 2025.04.25 13:38:36.586 2025.04.25 13:38:39.067 2025.04.25 13:03:56.630 2025.04.25 13:03:58.473
5 3.0.13.33803 2025.03.25 ea22a P P 2454 1704 2025.04.20 08:09:55.651 2025.04.20 08:09:58.105 2025.04.20 07:13:30.630 2025.04.20 07:13:32.334
6 3.0.13.33803 2025.02.25 08ebd P P 2822 1732 2025.03.25 10:25:32.619 2025.03.25 10:25:35.441 2025.03.25 09:27:56.155 2025.03.25 09:27:57.887
7 3.0.13.33796 2025.01.29 0ab85 P P 2785 1703 2025.02.25 12:16:12.234 2025.02.25 12:16:15.019 2025.02.25 11:41:13.322 2025.02.25 11:41:15.025
8 3.0.13.33796 2025.01.14 99b3b P P 2742 1775 2025.01.24 11:20:44.818 2025.01.24 11:20:47.560 2025.01.24 10:45:57.171 2025.01.24 10:45:58.946
9 3.0.13.33795 2024.12.13 fbbd9 P P 2480 1713 2025.01.01 12:31:47.594 2025.01.01 12:31:50.074 2025.01.01 11:56:31.767 2025.01.01 11:56:33.480
10 3.0.13.33795 2024.11.24 b8847 P P 2516 1727 2024.12.11 12:29:31.843 2024.12.11 12:29:34.359 2024.12.11 11:54:28.227 2024.12.11 11:54:29.954
11 3.0.13.33794 2024.10.15 abe09 P P 2866 1924 2024.11.22 12:05:53.416 2024.11.22 12:05:56.282 2024.11.22 11:30:43.399 2024.11.22 11:30:45.323
12 3.0.13.33793 2024.10.14 f831a P P 2812 1703 2024.10.15 12:33:29.527 2024.10.15 12:33:32.339 2024.10.15 11:58:10.862 2024.10.15 11:58:12.565
13 3.0.13.33793 2024.10.04 82ccc P P 2510 1686 2024.10.12 12:32:29.010 2024.10.12 12:32:31.520 2024.10.12 11:57:28.112 2024.10.12 11:57:29.798
14 3.0.13.33792 2024.08.31 d8791 P P 2759 1701 2024.10.03 12:40:46.858 2024.10.03 12:40:49.617 2024.10.03 12:04:44.127 2024.10.03 12:04:45.828
15 3.0.13.33787 2024.08.23 8ee81 P P 2542 1782 2024.09.01 12:50:58.495 2024.09.01 12:51:01.037 2024.09.01 12:11:54.718 2024.09.01 12:11:56.500
16 3.0.13.33787 2024.08.09 df740 P P 2642 1817 2024.08.23 12:46:46.134 2024.08.23 12:46:48.776 2024.08.23 12:07:54.959 2024.08.23 12:07:56.776
17 3.0.12.33746 2024.07.15 11dd4 P P 2627 1804 2024.08.09 12:06:59.985 2024.08.09 12:07:02.612 2024.08.09 11:28:30.932 2024.08.09 11:28:32.736
18 3.0.12.33746 2024.06.11 8a5eb P P 2450 2172 2024.07.15 11:00:22.609 2024.07.15 11:00:25.059 2024.07.15 10:26:38.680 2024.07.15 10:26:40.852
19 3.0.12.33745 2024.05.21 301a7 P P 3844 3031 2024.05.25 07:57:59.924 2024.05.25 07:58:03.768 2024.05.25 07:26:52.514 2024.05.25 07:26:55.545
20 3.0.12.33745 2024.05.09 9cf37 P P 4000 3297 2024.05.21 07:58:20.397 2024.05.21 07:58:24.397 2024.05.21 07:27:07.273 2024.05.21 07:27:10.570
21 3.0.12.33744 2024.04.20 af6b2 P P 3813 3031 2024.05.11 07:54:49.209 2024.05.11 07:54:53.022 2024.05.11 07:24:20.695 2024.05.11 07:24:23.726
22 3.0.12.33740 2024.04.06 c6cdd F F 1234 593 2024.04.21 02:09:03.855 2024.04.21 02:09:05.089 2024.04.21 01:38:57.442 2024.04.21 01:38:58.035
23 3.0.12.33726 2024.03.29 1fac6 F F 1204 594 2024.04.05 07:04:46.490 2024.04.05 07:04:47.694 2024.04.05 06:35:12.277 2024.04.05 06:35:12.871
24 3.0.12.33726 2024.03.11 456ca F F 1156 577 2024.03.29 12:45:40.449 2024.03.29 12:45:41.605 2024.03.29 12:17:29.652 2024.03.29 12:17:30.229

Elapsed time, ms. Chart for last 24 runs:

Last commits information (all timestamps in UTC):