diff --git a/tests/bugs/core_5685_test.py b/tests/bugs/core_5685_test.py index c53fd123..8fa3a885 100644 --- a/tests/bugs/core_5685_test.py +++ b/tests/bugs/core_5685_test.py @@ -1,208 +1,218 @@ -#coding:utf-8 - -""" -ID: issue-5951 -ISSUE: 5951 -TITLE: Sometime it is impossible to cancel/kill connection executing external query -DESCRIPTION: - Problem did appear when host "A" established connection to host "B" but could not get completed reply from this "B". - This can be emulated by following steps: - 1. We establich new remote connection to the same database using EDS mechanism and supply completely new ROLE to force new attachment be created; - 2. Within this EDS we do query to selectable procedure (with name 'sp_unreachable') which surely will not produce any result. - Bogon IP '192.0.2.2' is used in order to make this SP hang for sufficient time (on Windows it is about 20, on POSIX - about 44 seconds). - Steps 1 and 2 are implemented by asynchronous call of ISQL: we must have ability to kill its process after. - When this 'hanging ISQL' is launched, we wait 1..2 seconds and run one more ISQL, which has mission to KILL all attachments except his own. - This ISQL session is named 'killer', and it writes result of actions to log. - This "killer-ISQL" does TWO iterations with the same code which looks like 'select ... from mon$attachments' and 'delete from mon$attachments'. - First iteration must return data of 'hanging ISQL' and also this session must be immediately killed. - Second iteration must NOT return any data - and this is main check in this test. - - For builds which had bug (before 25.12.2017) one may see that second iteration STILL RETURNS the same data as first one: - ==== - ITERATION_NO 1 - HANGING_ATTACH_CONNECTION 1 - HANGING_ATTACH_PROTOCOL TCP - HANGING_STATEMENT_STATE 1 - HANGING_STATEMENT_BLOB_ID 0:3 - select * from sp_get_data - Records affected: 1 - - ITERATION_NO 2 - HANGING_ATTACH_CONNECTION 1 - HANGING_ATTACH_PROTOCOL TCP - HANGING_STATEMENT_STATE 1 - HANGING_STATEMENT_BLOB_ID 0:1 - select * from sp_get_data - Records affected: 1 - ==== - (expected: all fields in ITER #2 must be NULL) -JIRA: CORE-5685 -FBTEST: bugs.core_5685 -NOTES: - [06.10.2022] pzotov - Fails on Linux when run in 'batch' mode (i.e. when pytest has to perform the whole tests set). - Can not reproduce fail when run this test 'separately': it passes, but lasts too longm, ~130 s. - Test will be re-implemented. - DEFERRED. -""" -import platform -import pytest -import re -import subprocess -import time -from pathlib import Path -from firebird.qa import * -from firebird.driver import ShutdownMode, ShutdownMethod - -substitutions = [('.*After line.*', ''), ('.*Data source.*', '.*Data source'), - ('.*HANGING_STATEMENT_BLOB_ID.*', '')] - -init_script = """ - create sequence g; - commit; - set term ^; - create or alter procedure sp_unreachable returns( unreachable_address varchar(50) ) as - begin - for - execute statement ('select mon$remote_address from mon$attachments a where a.mon$attachment_id = current_connection') - on external '192.0.2.2:' || rdb$get_context('SYSTEM', 'DB_NAME') - as user 'SYSDBA' password 'masterkey' role left(replace( uuid_to_char(gen_uuid()), '-', ''), 31) - into unreachable_address - do - suspend; - end - ^ - - create or alter procedure sp_get_data returns( unreachable_address varchar(50) ) as - begin - for - execute statement ('select u.unreachable_address from sp_unreachable as u') - on external 'localhost:' || rdb$get_context('SYSTEM', 'DB_NAME') - as user 'SYSDBA' password 'masterkey' role left(replace( uuid_to_char(gen_uuid()), '-', ''), 31) - into unreachable_address - do - suspend; - end - ^ - set term ;^ - commit; -""" - -db = db_factory(init=init_script) - -act = python_act('db', substitutions=substitutions) - -expected_stdout = """ - HANGED ATTACH, STDOUT: Records affected: 0 - HANGED ATTACH, STDERR: Statement failed, SQLSTATE = 42000 - HANGED ATTACH, STDERR: Execute statement error at isc_dsql_fetch : - HANGED ATTACH, STDERR: - HANGED ATTACH, STDERR: Statement : select u.unreachable_address from sp_unreachable as u - .*Data source - HANGED ATTACH, STDERR: -At procedure 'SP_GET_DATA' line: 3, col: 9 - HANGED ATTACH, STDERR: - HANGED ATTACH, STDERR: - HANGED ATTACH, STDERR: - HANGED ATTACH, STDERR: - KILLER ATTACH, STDOUT: ITERATION_NO 1 - KILLER ATTACH, STDOUT: HANGING_ATTACH_CONNECTION 1 - KILLER ATTACH, STDOUT: HANGING_ATTACH_PROTOCOL TCP - KILLER ATTACH, STDOUT: HANGING_STATEMENT_STATE 1 - KILLER ATTACH, STDOUT: select * from sp_get_data - KILLER ATTACH, STDOUT: Records affected: 1 - KILLER ATTACH, STDOUT: ITERATION_NO 2 - KILLER ATTACH, STDOUT: HANGING_ATTACH_CONNECTION - KILLER ATTACH, STDOUT: HANGING_ATTACH_PROTOCOL - KILLER ATTACH, STDOUT: HANGING_STATEMENT_STATE - KILLER ATTACH, STDOUT: Records affected: 0 -""" - - -kill_script = """ - set list on; - set blob all; - select gen_id(g,1) as ITERATION_NO from rdb$database; - commit; - - select - sign(a.mon$attachment_id) as hanging_attach_connection - ,left(a.mon$remote_protocol,3) as hanging_attach_protocol - ,s.mon$state as hanging_statement_state - ,s.mon$sql_text as hanging_statement_blob_id - from rdb$database d - left join mon$attachments a on a.mon$remote_process containing 'isql' - -- do NOT use, field not existed in 2.5.x: and a.mon$system_flag is distinct from 1 - and a.mon$attachment_id is distinct from current_connection - left join mon$statements s on - a.mon$attachment_id = s.mon$attachment_id - and s.mon$state = 1 -- 4.0 Classic: 'SELECT RDB$MAP_USING, RDB$MAP_PLUGIN, ... FROM RDB$AUTH_MAPPING', mon$state = 0 - ; - - set count on; - delete from mon$attachments a - where - a.mon$attachment_id <> current_connection - and a.mon$remote_process containing 'isql' - ; - commit; -""" - -hang_script = temp_file('hang_script.sql') -hang_stdout = temp_file('hang_script.out') -hang_stderr = temp_file('hang_script.err') - -@pytest.mark.skipif(platform.system() != 'Windows', reason='FIXME: see notes') -@pytest.mark.es_eds -@pytest.mark.version('>=3.0.3') -def test_1(act: Action, hang_script: Path, hang_stdout: Path, hang_stderr: Path, - capsys): - hang_script.write_text('set list on; set count on; select * from sp_get_data;') - pattern_for_failed_statement = re.compile('Statement failed, SQLSTATE = (08006|08003)') - pattern_for_connection_close = re.compile('(Error (reading|writing) data (from|to) the connection)|(connection shutdown)') - pattern_for_ignored_messages = re.compile('(-send_packet/send)|(-Killed by database administrator.)') - killer_output = [] - # - with open(hang_stdout, mode='w') as hang_out, open(hang_stderr, mode='w') as hang_err: - p_hang_sql = subprocess.Popen([act.vars['isql'], '-i', str(hang_script), - '-user', act.db.user, - '-password', act.db.password, act.db.dsn], - stdout=hang_out, stderr=hang_err) - try: - time.sleep(4) - for i in range(2): - act.reset() - act.isql(switches=[], input=kill_script) - killer_output.append(act.stdout) - finally: - p_hang_sql.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) - time.sleep(2) - srv.database.bring_online(database=act.db.db_path) - # - output = [] - for line in hang_stdout.read_text().splitlines(): - if line.strip(): - output.append(f'HANGED ATTACH, STDOUT: {line}') - for line in hang_stderr.read_text().splitlines(): - if line.strip(): - if pattern_for_ignored_messages.search(line): - continue - elif pattern_for_failed_statement.search(line): - msg = '' - elif pattern_for_connection_close.search(line): - msg = '' - else: - msg = line - output.append(f'HANGED ATTACH, STDERR: {msg}') - for step in killer_output: - for line in act.clean_string(step).splitlines(): - if line.strip(): - output.append(f"KILLER ATTACH, STDOUT: {' '.join(line.split())}") - # Check - act.reset() - act.expected_stdout = expected_stdout - act.stdout = '\n'.join(output) - assert act.clean_stdout == act.clean_expected_stdout +#coding:utf-8 + +""" +ID: issue-5951 +ISSUE: 5951 +TITLE: Sometime it is impossible to cancel/kill connection executing external query +DESCRIPTION: + Problem did appear when host "A" established connection to host "B" but could not get completed reply from this "B". + This can be emulated by following steps: + 1. We establich new remote connection to the same database using EDS mechanism and supply completely new ROLE to force new attachment be created; + 2. Within this EDS we do query to selectable procedure (with name 'sp_unreachable') which surely will not produce any result. + Bogon IP '192.0.2.2' is used in order to make this SP hang for sufficient time (on Windows it is about 20, on POSIX - about 44 seconds). + Steps 1 and 2 are implemented by asynchronous call of ISQL: we must have ability to kill its process after. + When this 'hanging ISQL' is launched, we wait 1..2 seconds and run one more ISQL, which has mission to KILL all attachments except his own. + This ISQL session is named 'killer', and it writes result of actions to log. + This "killer-ISQL" does TWO iterations with the same code which looks like 'select ... from mon$attachments' and 'delete from mon$attachments'. + First iteration must return data of 'hanging ISQL' and also this session must be immediately killed. + Second iteration must NOT return any data - and this is main check in this test. + + For builds which had bug (before 25.12.2017) one may see that second iteration STILL RETURNS the same data as first one: + ==== + ITERATION_NO 1 + HANGING_ATTACH_CONNECTION 1 + HANGING_ATTACH_PROTOCOL TCP + HANGING_STATEMENT_STATE 1 + HANGING_STATEMENT_BLOB_ID 0:3 + select * from sp_get_data + Records affected: 1 + + ITERATION_NO 2 + HANGING_ATTACH_CONNECTION 1 + HANGING_ATTACH_PROTOCOL TCP + HANGING_STATEMENT_STATE 1 + HANGING_STATEMENT_BLOB_ID 0:1 + select * from sp_get_data + Records affected: 1 + ==== + (expected: all fields in ITER #2 must be NULL) +JIRA: CORE-5685 +FBTEST: bugs.core_5685 +NOTES: + [06.10.2022] pzotov + Fails on Linux when run in 'batch' mode (i.e. when pytest has to perform the whole tests set). + Can not reproduce fail when run this test 'separately': it passes, but lasts too longm, ~130 s. + Test will be re-implemented. + DEFERRED. + [09.07.2024] pzotov + Added item to substitutions related to 'port detached' message that raises in dev build. + Fixed wrong logic because of missed indentation, see hang_stderr. +""" +import platform +import pytest +import re +import subprocess +import time +from pathlib import Path +from firebird.qa import * +from firebird.driver import ShutdownMode, ShutdownMethod + +substitutions = [ ('.*After line.*', '') + ,('.*Data source.*', '.*Data source') + ,('.*HANGING_STATEMENT_BLOB_ID.*', '') + ,('.*-port detached', '') + ] + +init_script = """ + create sequence g; + commit; + set term ^; + create or alter procedure sp_unreachable returns( unreachable_address varchar(50) ) as + begin + for + execute statement ('select mon$remote_address from mon$attachments a where a.mon$attachment_id = current_connection') + on external '192.0.2.2:' || rdb$get_context('SYSTEM', 'DB_NAME') + as user 'SYSDBA' password 'masterkey' role left(replace( uuid_to_char(gen_uuid()), '-', ''), 31) + into unreachable_address + do + suspend; + end + ^ + + create or alter procedure sp_get_data returns( unreachable_address varchar(50) ) as + begin + for + execute statement ('select u.unreachable_address from sp_unreachable as u') + on external 'localhost:' || rdb$get_context('SYSTEM', 'DB_NAME') + as user 'SYSDBA' password 'masterkey' role left(replace( uuid_to_char(gen_uuid()), '-', ''), 31) + into unreachable_address + do + suspend; + end + ^ + set term ;^ + commit; +""" + +db = db_factory(init=init_script) + +act = python_act('db', substitutions=substitutions) + +expected_stdout = """ + HANGED ATTACH, STDOUT: Records affected: 0 + HANGED ATTACH, STDERR: Statement failed, SQLSTATE = 42000 + HANGED ATTACH, STDERR: Execute statement error at isc_dsql_fetch : + HANGED ATTACH, STDERR: + HANGED ATTACH, STDERR: Statement : select u.unreachable_address from sp_unreachable as u + .*Data source + HANGED ATTACH, STDERR: -At procedure 'SP_GET_DATA' line: 3, col: 9 + HANGED ATTACH, STDERR: + HANGED ATTACH, STDERR: + HANGED ATTACH, STDERR: + HANGED ATTACH, STDERR: + KILLER ATTACH, STDOUT: ITERATION_NO 1 + KILLER ATTACH, STDOUT: HANGING_ATTACH_CONNECTION 1 + KILLER ATTACH, STDOUT: HANGING_ATTACH_PROTOCOL TCP + KILLER ATTACH, STDOUT: HANGING_STATEMENT_STATE 1 + KILLER ATTACH, STDOUT: select * from sp_get_data + KILLER ATTACH, STDOUT: Records affected: 1 + KILLER ATTACH, STDOUT: ITERATION_NO 2 + KILLER ATTACH, STDOUT: HANGING_ATTACH_CONNECTION + KILLER ATTACH, STDOUT: HANGING_ATTACH_PROTOCOL + KILLER ATTACH, STDOUT: HANGING_STATEMENT_STATE + KILLER ATTACH, STDOUT: Records affected: 0 +""" + + +kill_script = """ + set list on; + set blob all; + select gen_id(g,1) as ITERATION_NO from rdb$database; + commit; + + select + sign(a.mon$attachment_id) as hanging_attach_connection + ,left(a.mon$remote_protocol,3) as hanging_attach_protocol + ,s.mon$state as hanging_statement_state + ,s.mon$sql_text as hanging_statement_blob_id + from rdb$database d + left join mon$attachments a on a.mon$remote_process containing 'isql' + -- do NOT use, field not existed in 2.5.x: and a.mon$system_flag is distinct from 1 + and a.mon$attachment_id is distinct from current_connection + left join mon$statements s on + a.mon$attachment_id = s.mon$attachment_id + and s.mon$state = 1 -- 4.0 Classic: 'SELECT RDB$MAP_USING, RDB$MAP_PLUGIN, ... FROM RDB$AUTH_MAPPING', mon$state = 0 + ; + + set count on; + delete from mon$attachments a + where + a.mon$attachment_id <> current_connection + and a.mon$remote_process containing 'isql' + ; + commit; +""" + +hang_script = temp_file('hang_script.sql') +hang_stdout = temp_file('hang_script.out') +hang_stderr = temp_file('hang_script.err') + +@pytest.mark.skipif(platform.system() != 'Windows', reason='FIXME: see notes') +@pytest.mark.es_eds +@pytest.mark.version('>=3.0.3') +def test_1(act: Action, hang_script: Path, hang_stdout: Path, hang_stderr: Path, + capsys): + hang_script.write_text('set list on; set count on; select * from sp_get_data;') + pattern_for_failed_statement = re.compile('Statement failed, SQLSTATE = (08006|08003)') + pattern_for_connection_close = re.compile('(Error (reading|writing) data (from|to) the connection)|(connection shutdown)') + pattern_for_ignored_messages = re.compile('(-send_packet/send)|(-Killed by database administrator.)') + killer_output = [] + # + with open(hang_stdout, mode='w') as hang_out, open(hang_stderr, mode='w') as hang_err: + p_hang_sql = subprocess.Popen([act.vars['isql'], '-i', str(hang_script), + '-user', act.db.user, + '-password', act.db.password, act.db.dsn], + stdout=hang_out, stderr=hang_err) + try: + time.sleep(4) + for i in range(2): + act.reset() + act.isql(switches=[], input=kill_script) + killer_output.append(act.stdout) + finally: + p_hang_sql.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) + time.sleep(2) + srv.database.bring_online(database=act.db.db_path) + # + output = [] + for line in hang_stdout.read_text().splitlines(): + if line.strip(): + output.append(f'HANGED ATTACH, STDOUT: {line}') + for line in hang_stderr.read_text().splitlines(): + if line.strip(): + msg = '' + if pattern_for_ignored_messages.search(line): + continue + elif pattern_for_failed_statement.search(line): + msg = '' + elif pattern_for_connection_close.search(line): + msg = '' + else: + msg = line + + if msg.strip(): + output.append(f'HANGED ATTACH, STDERR: {msg}') + + for step in killer_output: + for line in act.clean_string(step).splitlines(): + if line.strip(): + output.append(f"KILLER ATTACH, STDOUT: {' '.join(line.split())}") + + act.reset() + act.expected_stdout = expected_stdout + act.stdout = '\n'.join(output) + assert act.clean_stdout == act.clean_expected_stdout