2025-10-31 15:41:04,186 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-10-31 15:41:04,186 - INFO - ya.test - pytest_runtest_setup: test_session_pool_no_race_after_future_cancel_case_2
2025-10-31 15:41:04,186 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-10-31 15:41:04,186 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-10-31 15:41:04,187 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_session_pool.py::TestSessionPool, test_name: test_session_pool_no_race_after_future_cancel_case_2)
2025-10-31 15:41:04,188 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:04,189 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fc36ed46c70 state=pending>
2025-10-31 15:41:04,189 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-10-31 15:41:04,189 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,189 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,189 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 75c6e5a5-bd59-42d1-97a0-2e309aa5bf8c, ghrun-xldpwfo7ey.auto.internal:2526): creating call state
2025-10-31 15:41:04,190 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 75c6e5a5-bd59-42d1-97a0-2e309aa5bf8c, ghrun-xldpwfo7ey.auto.internal:2526): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:04,192 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 75c6e5a5-bd59-42d1-97a0-2e309aa5bf8c, ghrun-xldpwfo7ey.auto.internal:2526): on response callback started
2025-10-31 15:41:04,193 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 75c6e5a5-bd59-42d1-97a0-2e309aa5bf8c, ghrun-xldpwfo7ey.auto.internal:2526): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZDdmZjlmNjEtOTY1Zjg0OGQtZjkyMTc5ZWYtMThkNTRkYTc=" } } } }
2025-10-31 15:41:04,193 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,193 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,193 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 75c6e5a5-bd59-42d1-97a0-2e309aa5bf8c, ghrun-xldpwfo7ey.auto.internal:2526): on response callback success
2025-10-31 15:41:04,194 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:04,194 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fc36ed44f10 state=pending>
2025-10-31 15:41:04,195 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,195 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,195 - DEBUG - ydb.table.SessionPool - unsubscribe: Unsubscribe on waiter <Future at 0x7fc36ed44f10 state=finished returned Session>
2025-10-31 15:41:04,195 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,196 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-10-31 15:41:04,196 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-10-31 15:41:04,196 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-10-31 15:41:04,196 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fc370eb5870>, reason: session-pool-terminated
2025-10-31 15:41:04,197 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-10-31 15:41:04,197 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7fc370eb5870> is no longer active. Current active count 0.
2025-10-31 15:41:04,198 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 60696543-1e38-4c2d-884f-2884164e0fae, ghrun-xldpwfo7ey.auto.internal:2526): creating call state
2025-10-31 15:41:04,198 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 60696543-1e38-4c2d-884f-2884164e0fae, ghrun-xldpwfo7ey.auto.internal:2526): request = { session_id: "ydb://session/3?node_id=1&id=ZDdmZjlmNjEtOTY1Zjg0OGQtZjkyMTc5ZWYtMThkNTRkYTc=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:04,199 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7fc370eb5870>
2025-10-31 15:41:04,200 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-10-31 15:41:04,201 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 60696543-1e38-4c2d-884f-2884164e0fae, ghrun-xldpwfo7ey.auto.internal:2526): on response callback started
2025-10-31 15:41:04,201 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 60696543-1e38-4c2d-884f-2884164e0fae, ghrun-xldpwfo7ey.auto.internal:2526): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:04,201 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 60696543-1e38-4c2d-884f-2884164e0fae, ghrun-xldpwfo7ey.auto.internal:2526): on response callback success
2025-10-31 15:41:04,202 - INFO - ya.test - pytest_runtest_teardown: Test teardown
