2025-10-26 18:36:52,223 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-10-26 18:36:52,223 - INFO - ya.test - pytest_runtest_setup: test_dml_requests_logged_when_sid_is_unexpected
2025-10-26 18:36:52,224 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-10-26 18:36:52,224 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-10-26 18:36:52,226 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-10-26 18:36:52,228 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-10-26 18:36:52,230 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-10-26 18:36:52,233 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_auditlog.py, test_name: test_dml_requests_logged_when_sid_is_unexpected)
2025-10-26 18:36:52,235 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/70hy/0010c8/ydb/apps/ydbd/ydbd
2025-10-26 18:36:52,238 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/test_auditlog.py
2025-10-26 18:36:52,239 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 0a03c02a-1fe6-4907-8435-c891be13917f, localhost:30148): creating call state
2025-10-26 18:36:52,239 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 0a03c02a-1fe6-4907-8435-c891be13917f, localhost:30148): request = { database: "/Root/test_auditlog.py" }
2025-10-26 18:36:52,244 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 0a03c02a-1fe6-4907-8435-c891be13917f, localhost:30148): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-pqq4nwlsgu.auto.internal" port: 19182 service: "legacy" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" node_id: 50000 } self_location: "1" } } } }
2025-10-26 18:36:52,244 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/test_auditlog.py: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-pqq4nwlsgu.auto.internal:19182, location , ssl: False>]>
2025-10-26 18:36:52,245 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-10-26 18:36:52,249 - INFO - ydb.connection - close: Closing channel for endpoint localhost:30148
2025-10-26 18:36:52,880 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteSchemeQuery, 31d2b7ee-161b-476b-8c99-5d9166776668, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:52,881 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteSchemeQuery, 31d2b7ee-161b-476b-8c99-5d9166776668, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=MmJjOWVhZGMtN2E2MDMzOC05N2Y4YzM3Zi1jNGM1MGMzYw==" yql_text: "\n            grant \'ydb.generic.use\' on `/Root/test_auditlog.py` to `other-user@builtin`\n        " operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-26 18:36:52,900 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteSchemeQuery, 31d2b7ee-161b-476b-8c99-5d9166776668, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS } }
2025-10-26 18:36:52,901 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604000b25930>
2025-10-26 18:36:52,902 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-26 18:36:52,902 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x604001a1da30 state=pending>
2025-10-26 18:36:52,903 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 100). will create a new session.
2025-10-26 18:36:52,903 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:52,903 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:52,904 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, f1a42ba0-e2d2-462f-a40c-f66a407e4aa4, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:52,904 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, f1a42ba0-e2d2-462f-a40c-f66a407e4aa4, ghrun-pqq4nwlsgu.auto.internal:19182): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-26 18:36:52,909 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, f1a42ba0-e2d2-462f-a40c-f66a407e4aa4, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback started
2025-10-26 18:36:52,910 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, f1a42ba0-e2d2-462f-a40c-f66a407e4aa4, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" } } } }
2025-10-26 18:36:52,910 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:52,910 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:52,911 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, f1a42ba0-e2d2-462f-a40c-f66a407e4aa4, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback success
2025-10-26 18:36:52,911 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, ba3bbb92-79c4-423d-b8d3-04b2bad2503f, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:52,913 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, ba3bbb92-79c4-423d-b8d3-04b2bad2503f, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "insert into `/Root/test_auditlog.py/test-table` (id, value) values (100, 100), (101, 101)" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-26 18:36:53,050 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, ba3bbb92-79c4-423d-b8d3-04b2bad2503f, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-10-26 18:36:53,051 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:53,153 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 2c1cdbb5-483f-4f74-a506-1ddb5d1f8a2e, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:53,154 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 2c1cdbb5-483f-4f74-a506-1ddb5d1f8a2e, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "delete from `/Root/test_auditlog.py/test-table` where id = 100 or id = 101" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-26 18:36:53,250 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 2c1cdbb5-483f-4f74-a506-1ddb5d1f8a2e, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-10-26 18:36:53,251 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:53,353 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, fdbbc0c8-a4a3-4910-981a-6c6ed576069b, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:53,354 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, fdbbc0c8-a4a3-4910-981a-6c6ed576069b, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select id from `/Root/test_auditlog.py/test-table`" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-26 18:36:53,423 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, fdbbc0c8-a4a3-4910-981a-6c6ed576069b, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "id" type { optional_type { item { type_id: INT64 } } } } rows { items { int64_value: 2 } } rows { items { int64_value: 3 } } rows { items { int64_value: 4 } } rows { items { int64_value: 5 } } } tx_meta { } } } } }
2025-10-26 18:36:53,433 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:53,535 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 6c472568-bbfb-4b66-b969-f5177bbd18de, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:53,536 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 6c472568-bbfb-4b66-b969-f5177bbd18de, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "update `/Root/test_auditlog.py/test-table` set value = 0 where id = 1" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-26 18:36:53,632 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 6c472568-bbfb-4b66-b969-f5177bbd18de, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-10-26 18:36:53,633 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:53,735 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 5c9b40c6-73da-4c7a-ab41-83d9a656d554, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:53,736 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 5c9b40c6-73da-4c7a-ab41-83d9a656d554, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "replace into `/Root/test_auditlog.py/test-table` (id, value) values (2, 3), (3, 3)" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-26 18:36:53,801 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 5c9b40c6-73da-4c7a-ab41-83d9a656d554, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-10-26 18:36:53,802 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:53,904 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 797bc1d7-56ee-4de4-b793-21b6e7808efb, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:53,904 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 797bc1d7-56ee-4de4-b793-21b6e7808efb, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "upsert into `/Root/test_auditlog.py/test-table` (id, value) values (4, 4), (5, 5)" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-26 18:36:53,963 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 797bc1d7-56ee-4de4-b793-21b6e7808efb, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-10-26 18:36:53,964 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:54,066 - INFO - ya.test - pytest_runtest_teardown: Test teardown
2025-10-26 18:36:54,067 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-10-26 18:36:54,067 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-10-26 18:36:54,068 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-10-26 18:36:54,068 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-10-26 18:36:54,069 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x604001a1eab0>, reason: session-pool-terminated
2025-10-26 18:36:54,070 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x604001a1eab0> is no longer active. Current active count 0.
2025-10-26 18:36:54,070 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 50da5bae-6eeb-4bbc-a68e-f7e0518d9c49, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:54,071 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 50da5bae-6eeb-4bbc-a68e-f7e0518d9c49, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=OTNhMjE0NWEtNWU5MTI0MGUtYmFlNGE1MTctNmZhYjg0Yjc=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-26 18:36:54,073 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x604001a1eab0>
2025-10-26 18:36:54,073 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-10-26 18:36:54,074 - INFO - ydb.connection - close: Closing channel for endpoint localhost:30148
2025-10-26 18:36:54,074 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-pqq4nwlsgu.auto.internal:19182
2025-10-26 18:36:54,075 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 50da5bae-6eeb-4bbc-a68e-f7e0518d9c49, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback started
2025-10-26 18:36:54,076 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-10-26 18:36:54,076 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 50da5bae-6eeb-4bbc-a68e-f7e0518d9c49, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS } }
2025-10-26 18:36:54,077 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 50da5bae-6eeb-4bbc-a68e-f7e0518d9c49, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback success
2025-10-26 18:36:54,078 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-10-26 18:36:54,079 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-10-26 18:36:54,079 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-10-26 18:36:54,080 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-10-26 18:36:54,080 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x604000b25930>, reason: session-pool-terminated
2025-10-26 18:36:54,081 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x604000b25930> is no longer active. Current active count 0.
2025-10-26 18:36:54,081 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 8f9dc422-c44a-4b3e-b011-4d78f821cadd, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:54,082 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 8f9dc422-c44a-4b3e-b011-4d78f821cadd, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=MmJjOWVhZGMtN2E2MDMzOC05N2Y4YzM3Zi1jNGM1MGMzYw==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-26 18:36:54,084 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x604000b25930>
2025-10-26 18:36:54,094 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 8f9dc422-c44a-4b3e-b011-4d78f821cadd, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback started
2025-10-26 18:36:54,095 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-10-26 18:36:54,096 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 8f9dc422-c44a-4b3e-b011-4d78f821cadd, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS } }
2025-10-26 18:36:54,096 - INFO - ydb.connection - close: Closing channel for endpoint localhost:30148
2025-10-26 18:36:54,096 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-pqq4nwlsgu.auto.internal:19182
2025-10-26 18:36:54,097 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 8f9dc422-c44a-4b3e-b011-4d78f821cadd, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback success
2025-10-26 18:36:54,098 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-10-26 18:36:54,099 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-10-26 18:36:54,099 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-10-26 18:36:54,100 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-10-26 18:36:54,100 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-10-26 18:36:54,101 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x6040019c1730>, reason: session-pool-terminated
2025-10-26 18:36:54,101 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x6040019c1730> is no longer active. Current active count 0.
2025-10-26 18:36:54,101 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 7ff1c651-1cae-4da4-8073-cb5ed188085e, ghrun-pqq4nwlsgu.auto.internal:19182): creating call state
2025-10-26 18:36:54,102 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 7ff1c651-1cae-4da4-8073-cb5ed188085e, ghrun-pqq4nwlsgu.auto.internal:19182): request = { session_id: "ydb://session/3?node_id=50000&id=M2UwMDE3YmMtNjJlOThmN2QtMjM2NmY5NGYtZjRlNzk2YjI=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-26 18:36:54,103 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x6040019c1730>
2025-10-26 18:36:54,104 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-10-26 18:36:54,104 - INFO - ydb.connection - close: Closing channel for endpoint localhost:30148
2025-10-26 18:36:54,104 - INFO - ydb.connection - close: Closing channel for endpoint ghrun-pqq4nwlsgu.auto.internal:19182
2025-10-26 18:36:54,105 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 7ff1c651-1cae-4da4-8073-cb5ed188085e, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback started
2025-10-26 18:36:54,106 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-10-26 18:36:54,107 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 7ff1c651-1cae-4da4-8073-cb5ed188085e, ghrun-pqq4nwlsgu.auto.internal:19182): response = { operation { ready: true status: SUCCESS } }
2025-10-26 18:36:54,108 - DEBUG - ydb.tests.library.harness.ydb_fixtures - ydb_database_ctx: destroy database /Root/test_auditlog.py: remove path and dismantle internals
2025-10-26 18:36:54,108 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 7ff1c651-1cae-4da4-8073-cb5ed188085e, ghrun-pqq4nwlsgu.auto.internal:19182): on response callback success
2025-10-26 18:36:54,109 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - remove_database: /Root/test_auditlog.py
2025-10-26 18:36:54,111 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_auditlog.py: send console operation, token None
2025-10-26 18:36:54,119 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_send_op: /Root/test_auditlog.py: response from console: RemoveTenantResponse {
  Response {
    operation {
      id: "ydb://cmsrequest/5?tenant=/Root/test_auditlog.py&cmstid=72057594037936131&txid=1761503814115754&action=2"
    }
  }
}
Status {
  Code: STATUS_CODE_UNSPECIFIED
}

2025-10-26 18:36:54,120 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_auditlog.py: wait console operation done
2025-10-26 18:36:54,625 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_op: /Root/test_auditlog.py: console operation done
2025-10-26 18:36:54,626 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_auditlog.py: wait tenant gone
2025-10-26 18:36:54,631 - DEBUG - ydb.tests.library.harness.kikimr_cluster_interface - _remove_database_wait_tenant_gone: /Root/test_auditlog.py: tenant gone
2025-10-26 18:36:54,632 - DEBUG - ydb.tests.library.harness.ydb_fixtures - ydb_database_ctx: destroy database /Root/test_auditlog.py: stop nodes
2025-10-26 18:36:57,633 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:19182/1
2025-10-26 18:36:57,633 - DEBUG - ydb.tests.library.harness.ydb_fixtures - ydb_database_ctx: destroy database /Root/test_auditlog.py: database down
2025-10-26 18:36:57,634 - INFO - ydb.tests.library.harness.ydb_fixtures - ydb_cluster: destroy ydb_cluster for __tests__.test_auditlog
2025-10-26 18:37:04,635 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:30148/1
2025-10-26 18:37:04,635 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/11321
2025-10-26 18:37:04,636 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/4323
2025-10-26 18:37:04,636 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/64916
2025-10-26 18:37:04,636 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/19182
2025-10-26 18:37:04,636 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/22197
2025-10-26 18:37:04,637 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/26550
2025-10-26 18:37:04,637 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/30148
2025-10-26 18:37:04,637 - DEBUG - library.python.filelock - release: Ensuring filelock released: /home/runner/.ya/build/port_sync_dir/2589
