Added/Updated tests\functional\transactions\test_read_consist_statement_delete_undone_01.py: Replaced verification method of worker attachment presense (which tries DML and waits for resource). Loop with query to mon$statements is used instead. Maximal duration of this loop is limited - see notes.

tests/functional/transactions/test_read_consist_statement_delete_undone_01.py

@@ -118,6 +118,15 @@ NOTES:
             Restarted <N> time(s)
 
         Checked on 5.0.0.561 (date of build: 29-jun-2022) - all OK.
+
+    [23.09.2023] pzotov
+        Replaced verification method of worker attachment presense (which tries DML and waits for resource).
+        This attachment is created by *asynchronously* launched ISQL thus using of time.sleep(1) is COMPLETELY wrong.
+        Loop with query to mon$statements is used instead (we search for record which SQL_TEXT contains 'special tag', see variable SQL_TAG_THAT_WE_WAITING_FOR).
+        Maximal duration of this loop is limited by variable 'MAX_WAIT_FOR_WORKER_START_MS'.
+        Many thanks to Vlad for suggestions.
+
+        Checked on WI-T6.0.0.48, WI-T5.0.0.1211, WI-V4.0.4.2988.
 """
 
 import subprocess
@@ -125,6 +134,7 @@ import pytest
 from firebird.qa import *
 from pathlib import Path
 import time
+import datetime as py_dt
 import re
 import locale
 
@@ -162,7 +172,9 @@ expected_stdout_worker = """
     Records affected: 4
 """
 
-SQL_TO_BE_RESTARTED = 'delete from test where not exists(select * from test where id >= 10) order by id desc'
+MAX_WAIT_FOR_WORKER_START_MS = 10000;
+SQL_TAG_THAT_WE_WAITING_FOR = 'SQL_TAG_THAT_WE_WAITING_FOR'
+SQL_TO_BE_RESTARTED = f'delete /* {SQL_TAG_THAT_WE_WAITING_FOR} */ from test where not exists(select * from test where id >= 10) order by id desc'
 
 expected_stdout_trace = f"""
     {SQL_TO_BE_RESTARTED}
@@ -192,6 +204,29 @@ expected_stdout_trace = f"""
 """
 act = python_act('db', substitutions=[('=', ''), ('[ \t]+', ' '), ('.* EXECUTE_STATEMENT_RESTART', 'EXECUTE_STATEMENT_RESTART')])
 
+def wait_for_attach_showup_in_monitoring(con_monitoring, sql_text_tag):
+    chk_sql = f"select 1 from mon$statements s where s.mon$attachment_id != current_connection and s.mon$sql_text containing '{sql_text_tag}'"
+    attach_with_sql_tag = None
+    t1=py_dt.datetime.now()
+    cur_monitoring = con_monitoring.cursor()
+    while True:
+        cur_monitoring.execute(chk_sql)
+        for r in cur_monitoring:
+            attach_with_sql_tag = r[0]
+        if not attach_with_sql_tag:
+            t2=py_dt.datetime.now()
+            d1=t2-t1
+            if d1.seconds*1000 + d1.microseconds//1000 >= MAX_WAIT_FOR_WORKER_START_MS:
+                break
+            else:
+                con_monitoring.commit()
+                time.sleep(0.2)
+        else:
+            break
+            
+    assert attach_with_sql_tag, f"Could not find attach statement containing '{sql_text_tag}' for {MAX_WAIT_FOR_WORKER_START_MS} ms. ABEND."
+    return
+
 @pytest.mark.version('>=4.0')
 def test_1(act: Action, fn_worker_sql: Path, fn_worker_log: Path, fn_worker_err: Path, capsys):
     sql_init = (act.files_dir / 'read-consist-sttm-restart-DDL.sql').read_text()
@@ -225,8 +260,7 @@ def test_1(act: Action, fn_worker_sql: Path, fn_worker_log: Path, fn_worker_err:
 
     with act.trace(db_events = trace_cfg_items, encoding=locale.getpreferredencoding()):
 
-
-        with act.db.connect() as con_lock_1, act.db.connect() as con_lock_2:
+        with act.db.connect() as con_lock_1, act.db.connect() as con_lock_2, act.db.connect() as con_monitoring:
             for i,c in enumerate((con_lock_1,con_lock_2)):
                 sttm = f"execute block as begin rdb$set_context('USER_SESSION', 'WHO', 'LOCKER #{i+1}'); end"
                 c.execute_immediate(sttm)
@@ -290,7 +324,8 @@ def test_1(act: Action, fn_worker_sql: Path, fn_worker_log: Path, fn_worker_err:
                                               stdout = hang_out,
                                               stderr = hang_err
                                            )
-                time.sleep(1)
+                wait_for_attach_showup_in_monitoring(con_monitoring, SQL_TAG_THAT_WE_WAITING_FOR)
+                # >>> !!!THIS WAS WRONG!!! >>> time.sleep(1)
 
 
                 #########################