Added/Updated tests\bugs\gh_5995_test.py: Checked on 6.0.0.366, 5.0.1.1411, 4.0.5.3103

tests/bugs/gh_5995_test.py

@@ -6,149 +6,199 @@ ISSUE:       5995
 TITLE:       Connection to server may hang when working with encrypted databases over non-TCP protocol
 DESCRIPTION:
     Test implemented only to be run on Windows.
-  It assumes that there are files keyholder.dll and keyholder.conf in the %FIREBIRD_HOME%\\plugins dir.
+    Folder %FIREBIRD_HOME%/plugins/ must have files fbSampleKeyHolder.conf and fbSampleKeyHolder.dll which should be
-  These files were provided by IBSurgeon and added during fbt_run prepare phase by batch scenario (qa_rundaily).
+    copied there from %FIREBIRD_HOME%/examples/prebuilt/plugins/.
-  File keyholder.conf initially contains several keys.
+    NB! These files ABSENT in FB 3.x but they can be taken from FB 4.x snapshot.
+    File fbSampleKeyHolder.conf must have following lines:
+        Auto = true
+        KeyRed=111
 
-  If we make this file EMPTY then usage of XNET and WNET protocols became improssible before this ticket was fixed.
+    If we encrypt database and then make file fbSampleKeyHolder.conf EMPTY then usage of XNET and WNET protocols became
+    impossible before this ticket was fixed.
     Great thanks to Alex for suggestions.
-
-  Confirmed bug on 3.0.1.32609: ISQL hangs on attempt to connect to database when file plugins\\keyholder.conf is empty.
-  In order to properly finish test, we have to kill hanging ISQL and change DB state to full shutdown (with subsequent
-  returning it to online) - fortunately, connection using TCP remains avaliable in this case.
 JIRA:        CORE-5730
 FBTEST:      bugs.gh_5995
+NOTES:
+    [03.06.2024] pzotov
+    Confirmed bug on 3.0.1.32609, 4.0.0.853: ISQL hangs on attempt to connect to database when file plugins/keyholder.conf is empty.
+    Checked on 6.0.0.366, 5.0.1.1411, 4.0.5.3103 (all of them were checked for ServerMode = SS and CS).
+
+    ATTENTION: 3.x raises different SQLSTATE and error text, depending on ServerMode!
+    For 3.x value of SQLSTATE and error text depends on Servermode.
+    On Classic FB 3.x output will be almost like in FB 4.x+:
+       Statement failed, SQLSTATE = 08004
+       Missing correct crypt key
+       -Plugin fbSampleDbCrypt:
+       -Crypt key Red not set
+       -IProvider::attachDatabase failed when loading mapping cache
+    On Super FB 3.x output is:
+       Statement failed, SQLSTATE = HY000
+       Missing correct crypt key
+       -Plugin fbSampleDbCrypt:
+       -Crypt key Red not set
+    Because of that, it was decided not to check FB 3.x as this version soon will be considered as obsolete.
 """
 
+import shutil
+import locale
+import re
+import time
+import platform
+import subprocess
+
+import datetime as py_dt
+from pathlib import Path
+
 import pytest
 from firebird.qa import *
+from firebird.driver import DatabaseError, DbInfoCode, NetProtocol
+
+import time
+
+###########################
+###   S E T T I N G S   ###
+###########################
+
+# QA_GLOBALS -- dict, is defined in qa/plugin.py, obtain settings
+# from act.files_dir/'test_config.ini':
+enc_settings = QA_GLOBALS['encryption']
+
+# ACHTUNG: this must be carefully tuned on every new host:
+#
+MAX_WAITING_ENCR_FINISH = int(enc_settings['MAX_WAIT_FOR_ENCR_FINISH_WIN'])
+assert MAX_WAITING_ENCR_FINISH > 0
+
+ENCRYPTION_PLUGIN = enc_settings['encryption_plugin'] # fbSampleDbCrypt
+ENCRYPTION_KEY = enc_settings['encryption_key'] # Red
 
 db = db_factory()
+act = python_act('db', substitutions = [('After line \\d+.*', ''),('[ \t]+', ' ')])
 
-act = python_act('db')
+kholder_cfg_bak = temp_file('fbSampleKeyHolder.bak')
+tmp_sql = temp_file('tmp_5995.sql')
+tmp_log = temp_file('tmp_5995.log')
 
-expected_stdout = """
+#-----------------------------------------------------------------------
-    MON$REMOTE_PROTOCOL             WNET
-    MON$REMOTE_PROTOCOL             XNET
-"""
 
-@pytest.mark.skip('FIXME: Not IMPLEMENTED')
+def run_encr_decr(act: Action, mode, max_wait_encr_thread_finish, capsys):
-@pytest.mark.version('>=3.0.4')
+    
+    assert mode in ('encrypt', 'decrypt')
+
+    if mode == 'encrypt':
+        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
+
+    d1 = py_dt.timedelta(0)
+    with act.db.connect() as con:
+        #cur = con.cursor()
+        #ps = cur.prepare('select mon$crypt_state from mon$database')
+
+        t1=py_dt.datetime.now()
+        try:
+            d1 = t1-t1
+            con.execute_immediate(alter_db_sttm)
+            con.commit()
+            # Pattern to check for completed encryption thread:
+            completed_encr_pattern = re.compile(f'Attributes\\s+encrypted,\\s+plugin\\s+{ENCRYPTION_PLUGIN}', re.IGNORECASE)
+            while not e_thread_finished:
+                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    G S T A T    A T T R.  ###
+                #############################################
+                # 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 mode == 'encrypt' and completed_encr_pattern.match(line.strip()):
+                        e_thread_finished = True
+                    if mode == 'decrypt' and 'Attributes' in line and not completed_encr_pattern.search(line.strip()):
+                        e_thread_finished = True
+                    if e_thread_finished:
+                        break
+
+                time.sleep(0.5)
+                    
+        except DatabaseError as e:
+            print( e.__str__() )
+
+    assert e_thread_finished, f'TIMEOUT EXPIRATION: {mode=} took {d1.seconds*1000 + d1.microseconds//1000} ms which greater than {max_wait_encr_thread_finish=} ms'
+
+#-----------------------------------------------------------------------
+
+@pytest.mark.encryption
+@pytest.mark.version('>=4.0')
 @pytest.mark.platform('Windows')
-def test_1(act: Action):
+def test_1(act: Action, kholder_cfg_bak: Path, tmp_sql: Path, tmp_log: Path, capsys):
-    pytest.fail("Not IMPLEMENTED")
+    kholder_cfg_file = act.vars['home-dir'] / 'plugins' / 'fbSampleKeyHolder.conf'
+    shutil.copy2(kholder_cfg_file, kholder_cfg_bak)
+    finish_encryption = False
 
-# test_script_1
+    protocols_list = [ NetProtocol.INET, NetProtocol.XNET, ]
-#---
+    if act.is_version('<5'):
-#
+        protocols_list.append(NetProtocol.WNET)
-#  import os
+
-#  import subprocess
+    expected_output = actual_output = test_sql = ''
-#  from subprocess import Popen
+    try:
-#  import datetime
+        run_encr_decr(act, 'encrypt', MAX_WAITING_ENCR_FINISH, capsys)
-#  import time
+        finish_encryption = True
-#  import shutil
+        with open(kholder_cfg_file,'w') as f:
-#  import re
+            pass
-#  import fdb
+        
-#
+        for protocol_name in protocols_list:
-#  os.environ["ISC_USER"] = user_name
+            conn_str = f"connect {protocol_name.name.lower()}://{act.db.db_path} user {act.db.user} password '{act.db.password}'"
-#  os.environ["ISC_PASSWORD"] = user_password
+            test_sql = f"""
-#  engine = db_conn.engine_version
+                set list on;
-#  db_name = db_conn.database_name
+                set bail on;
-#  db_conn.close()
+                set echo on;
-#
+                {conn_str};
-#  svc = fdb.services.connect(host='localhost', user=user_name, password=user_password)
+                select mon$remote_protocol from mon$attachments where mon$attachment_id = current_connection;
-#  FB_HOME = svc.get_home_directory()
+            """
-#  svc.close()
+            tmp_sql.write_text(test_sql)
-#
+            
-#  #--------------------------------------------
+            with open(tmp_log, 'w') as f_log:
-#
+                # ISQL-4.x must issue:
-#  def flush_and_close( file_handle ):
+                #   Statement failed, SQLSTATE = 08004
-#      # https://docs.python.org/2/library/os.html#os.fsync
+                #   Missing database encryption key for your attachment
-#      # If you're starting with a Python file object f,
+                #   -Plugin fbSampleDbCrypt:
-#      # first do f.flush(), and
+                #   -Crypt key Red not set
-#      # then do os.fsync(f.fileno()), to ensure that all internal buffers associated with f are written to disk.
+                # Before fix, ISQL hanged on CONNECT, thus we have to use timeout here!
-#      global os
+                #
-#
+                p = subprocess.run( [ act.vars['isql'],
-#      file_handle.flush()
+                                      '-q',
-#      if file_handle.mode not in ('r', 'rb') and file_handle.name != os.devnull:
+                                      '-i', str(tmp_sql)
-#          # otherwise: "OSError: [Errno 9] Bad file descriptor"!
+                                    ], 
-#          os.fsync(file_handle.fileno())
+                                    stdout = f_log, stderr = subprocess.STDOUT,
-#      file_handle.close()
+                                    timeout = 3
-#
+                                  )
-#  #--------------------------------------------
+       
-#
+            actual_output += tmp_log.read_text()
-#  def cleanup( f_names_list ):
+
-#      global os
+            expected_output += f"""
-#      for i in range(len( f_names_list )):
+                {conn_str};
-#         if type(f_names_list[i]) == file:
+                Statement failed, SQLSTATE = 08004
-#            del_name = f_names_list[i].name
+                Missing database encryption key for your attachment
-#         elif type(f_names_list[i]) == str:
+                -Plugin {ENCRYPTION_PLUGIN}:
-#            del_name = f_names_list[i]
+                -Crypt key {ENCRYPTION_KEY} not set
-#         else:
+            """
-#            print('Unrecognized type of element:', f_names_list[i], ' - can not be treated as file.')
+    
-#            print('type(f_names_list[i])=',type(f_names_list[i]))
+    except Exception as e:
-#            del_name = None
+        actual_output += test_sql  + '\n' + e.__str__()
-#
+    finally:
-#         if del_name and os.path.isfile( del_name ):
+        shutil.copy2(kholder_cfg_bak, kholder_cfg_file)
-#             os.remove( del_name )
+        if finish_encryption:
-#
+            run_encr_decr(act, 'decrypt', MAX_WAITING_ENCR_FINISH, capsys)
-#  #--------------------------------------------
+
-#
+    act.expected_stdout = expected_output
-#
+    act.stdout = actual_output # capsys.readouterr().out
-#  dts = datetime.datetime.now().strftime("%y%m%d_%H%M%S")
+    assert act.clean_stdout == act.clean_expected_stdout
-#
-#  kholder_cur = os.path.join( FB_HOME, 'plugins', 'keyholder.conf')
-#  kholder_bak = os.path.join( context['temp_directory'], 'keyholder'+dts+'.bak')
-#
-#  shutil.copy2( kholder_cur, kholder_bak)
-#
-#  # Make file %FB_HOME%\\plugins\\keyholder.conf empty:
-#  with open(kholder_cur,'w') as f:
-#    pass
-#
-#  MAX_SECONDS_TO_WAIT = 3
-#
-#  # Trying to establish connection to database using WNET and XNET protocols.
-#  # Async. launch of ISQL with check that it will finished within some reasonable time (and w/o errors).
-#  # If it will hang - kill (this is bug dexcribed in the ticket)
-#  for p in ('wnet', 'xnet'):
-#      f_isql_sql=open(os.path.join(context['temp_directory'],'tmp_gh_5995.'+p+'.sql'),'w')
-#      f_isql_sql.write('set list on; select mon$remote_protocol from mon$attachments where mon$attachment_id = current_connection;')
-#      flush_and_close( f_isql_sql )
-#
-#      protocol_conn_string = ''.join( (p, '://', db_name) )
-#      f_isql_log=open( os.path.join(context['temp_directory'],'tmp_gh_5995.'+p+'.log'), 'w')
-#      p_isql = Popen([ context['isql_path'], protocol_conn_string, "-i", f_isql_sql.name], stdout=f_isql_log, stderr=subprocess.STDOUT )
-#
-#      time.sleep(0.2)
-#      for i in range(0,MAX_SECONDS_TO_WAIT):
-#          # Check if child process has terminated. Set and return returncode attribute. Otherwise, returns None.
-#          p_isql.poll()
-#          if p_isql.returncode is None:
-#              # A None value indicates that the process has not terminated yet.
-#              time.sleep(1)
-#              if i < MAX_SECONDS_TO_WAIT-1:
-#                  continue
-#              else:
-#                  f_isql_log.write( '\\nISQL process %d hangs for %d seconds and is forcedly killed.' % (p_isql.pid, MAX_SECONDS_TO_WAIT) )
-#                  p_isql.terminate()
-#
-#      flush_and_close(f_isql_log)
-#
-#      with open(f_isql_log.name,'r') as f:
-#          for line in f:
-#              if line:
-#                  print(line)
-#
-#      cleanup((f_isql_sql,f_isql_log))
-#
-#  shutil.move( kholder_bak, kholder_cur)
-#
-#  # ::: NOTE ::: We have to change DB state to full shutdown and bring it back online
-#  # in order to prevent "Object in use" while fbtest will try to drop this DB
-#  #####################################
-#  runProgram('gfix',[dsn,'-shut','full','-force','0'])
-#  runProgram('gfix',[dsn,'-online'])
-#
-#
-#---