2 @message |
assert
- RESULT_MSG OK: second EDS was fast
+ RESULT_MSG FAILED: second EDS waited too long, 675.0 ms - more than max_wait_ms=500
LOG DETAILS:
2024-08-30 14:20:49.538
2024-08-30 14:20:49.549 act = <firebird.qa.plugin.Action object at [hex]>
2024-08-30 14:20:49.557 eds_script = PosixPath('/var/tmp/qa_2024/test_11121/eds_script.sql')
2024-08-30 14:20:49.564
2024-08-30 14:20:49.573 @pytest.mark.es_eds
2024-08-30 14:20:49.579 @pytest.mark.version('>=3.0.3')
2024-08-30 14:20:49.587 def test_1(act: Action, eds_script: Path):
2024-08-30 14:20:49.594 eds_sql = f"""
2024-08-30 14:20:49.603 set bail on;
2024-08-30 14:20:49.612 set list on;
2024-08-30 14:20:49.623 --select current_timestamp as " " from rdb$database;
2024-08-30 14:20:49.631 set term ^;
2024-08-30 14:20:49.640 execute block as
2024-08-30 14:20:49.649 declare c smallint;
2024-08-30 14:20:49.657 declare remote_host varchar(50) = '%(remote_host)s'; -- never unreachable: 192.0.2.2
2024-08-30 14:20:49.663 begin
2024-08-30 14:20:49.670 rdb$set_context('USER_SESSION','DTS_BEG', cast('now' as timestamp) );
2024-08-30 14:20:49.676 execute statement 'select 1 from rdb$database'
2024-08-30 14:20:49.683 on external remote_host || ':' || rdb$get_context('SYSTEM', 'DB_NAME')
2024-08-30 14:20:49.689 as user '{act.db.user}' password '{act.db.password}'
2024-08-30 14:20:49.695 into c;
2024-08-30 14:20:50.317 end
2024-08-30 14:20:50.331 ^
2024-08-30 14:20:50.341 set term ;^
2024-08-30 14:20:50.350 --select current_timestamp as " " from rdb$database;
2024-08-30 14:20:50.358 select iif( waited_ms < max_wait_ms,
2024-08-30 14:20:50.367 'OK: second EDS was fast',
2024-08-30 14:20:50.375 'FAILED: second EDS waited too long, ' || waited_ms || ' ms - more than max_wait_ms='||max_wait_ms
2024-08-30 14:20:50.383 ) as result_msg
2024-08-30 14:20:50.391 from (
2024-08-30 14:20:50.399 select
2024-08-30 14:20:50.407 datediff( millisecond from cast( rdb$get_context('USER_SESSION','DTS_BEG') as timestamp) to current_timestamp ) as waited_ms
2024-08-30 14:20:50.415 ,500 as max_wait_ms
2024-08-30 14:20:50.423 -- ^
2024-08-30 14:20:50.430 -- | #################
2024-08-30 14:20:50.439 -- +-------------------------------- T H R E S H O L D
2024-08-30 14:20:50.447 -- #################
2024-08-30 14:20:50.454 from rdb$database
2024-08-30 14:20:50.461 );
2024-08-30 14:20:50.469 """
2024-08-30 14:20:50.476 #
2024-08-30 14:20:50.483 remote_host = '192.0.2.2'
2024-08-30 14:20:50.491 eds_script.write_text(eds_sql % locals())
2024-08-30 14:20:50.499 p_unavail_host = subprocess.Popen([act.vars['isql'], '-n', '-i', str(eds_script),
2024-08-30 14:20:50.509 '-user', act.db.user,
2024-08-30 14:20:50.518 '-password', act.db.password, act.db.dsn],
2024-08-30 14:20:50.526 stdout=subprocess.DEVNULL, stderr=subprocess.STDOUT)
2024-08-30 14:20:50.534 try:
2024-08-30 14:20:50.542 time.sleep(2)
2024-08-30 14:20:50.551 remote_host = 'localhost'
2024-08-30 14:20:50.559 act.expected_stdout = expected_stdout
2024-08-30 14:20:50.569 act.isql(switches=['-n'], input=eds_sql % locals())
2024-08-30 14:20:50.577 finally:
2024-08-30 14:20:50.593 p_unavail_host.terminate()
2024-08-30 14:20:50.613 # Ensure that database is not busy
2024-08-30 14:20:50.621 with act.connect_server() as srv:
2024-08-30 14:20:50.630 srv.database.shutdown(database=act.db.db_path, mode=ShutdownMode.FULL,
2024-08-30 14:20:50.638 method=ShutdownMethod.FORCED, timeout=0)
2024-08-30 14:20:50.645 srv.database.bring_online(database=act.db.db_path)
2024-08-30 14:20:50.652 # Check
2024-08-30 14:20:50.660 > assert act.clean_stdout == act.clean_expected_stdout
2024-08-30 14:20:50.676 E assert
2024-08-30 14:20:50.684 E - RESULT_MSG OK: second EDS was fast
2024-08-30 14:20:50.692 E + RESULT_MSG FAILED: second EDS waited too long, 675.0 ms - more than max_wait_ms=500
2024-08-30 14:20:50.700
2024-08-30 14:20:50.709 tests/bugs/core_5648_test.py:99: AssertionError
2024-08-30 14:20:50.716 ---------------------------- Captured stdout setup -----------------------------
2024-08-30 14:20:50.725 Creating db: localhost:/var/tmp/qa_2024/test_11121/test.fdb [page_size=None, sql_dialect=None, charset='NONE', user=SYSDBA, password=masterkey]
|
3 #text |
act = <firebird.qa.plugin.Action pytest object at [hex]>
eds_script = PosixPath('/var/tmp/qa_2024/test_11121/eds_script.sql')
@pytest.mark.es_eds
@pytest.mark.version('>=3.0.3')
def test_1(act: Action, eds_script: Path):
eds_sql = f"""
set bail on;
set list on;
--select current_timestamp as " " from rdb$database;
set term ^;
execute block as
declare c smallint;
declare remote_host varchar(50) = '%(remote_host)s'; -- never unreachable: 192.0.2.2
begin
rdb$set_context('USER_SESSION','DTS_BEG', cast('now' as timestamp) );
execute statement 'select 1 from rdb$database'
on external remote_host || ':' || rdb$get_context('SYSTEM', 'DB_NAME')
as user '{act.db.user}' password '{act.db.password}'
into c;
end
^
set term ;^
--select current_timestamp as " " from rdb$database;
select iif( waited_ms < max_wait_ms,
'OK: second EDS was fast',
'FAILED: second EDS waited too long, ' || waited_ms || ' ms - more than max_wait_ms='||max_wait_ms
) as result_msg
from (
select
datediff( millisecond from cast( rdb$get_context('USER_SESSION','DTS_BEG') as timestamp) to current_timestamp ) as waited_ms
,500 as max_wait_ms
-- ^
-- | #################
-- +-------------------------------- T H R E S H O L D
-- #################
from rdb$database
);
"""
#
remote_host = '192.0.2.2'
eds_script.write_text(eds_sql % locals())
p_unavail_host = subprocess.Popen([act.vars['isql'], '-n', '-i', str(eds_script),
'-user', act.db.user,
'-password', act.db.password, act.db.dsn],
stdout=subprocess.DEVNULL, stderr=subprocess.STDOUT)
try:
time.sleep(2)
remote_host = 'localhost'
act.expected_stdout = expected_stdout
act.isql(switches=['-n'], input=eds_sql % locals())
finally:
p_unavail_host.terminate()
# Ensure that database is not busy
with act.connect_server() as srv:
srv.database.shutdown(database=act.db.db_path, mode=ShutdownMode.FULL,
method=ShutdownMethod.FORCED, timeout=0)
srv.database.bring_online(database=act.db.db_path)
# Check
> assert act.clean_stdout == act.clean_expected_stdout
E assert
E - RESULT_MSG OK: second EDS was fast
E + RESULT_MSG FAILED: second EDS waited too long, 675.0 ms - more than max_wait_ms=500
tests/bugs/core_5648_test.py:99: AssertionError
|