2025-12-12 10:05:21,054 - INFO - ya.test.2075013  - pytest_runtest_setup: ####################################################################################################
2025-12-12 10:05:21,062 - INFO - ya.test.2075013  - pytest_runtest_setup: test_session_pool_release_logic
2025-12-12 10:05:21,063 - INFO - ya.test.2075013  - pytest_runtest_setup: ####################################################################################################
2025-12-12 10:05:21,063 - INFO - ya.test.2075013  - pytest_runtest_setup: Test setup
2025-12-12 10:05:21,070 - INFO - ya.test.2075013  - pytest_runtest_call: Test call (class_name: test_session_pool.py::TestSessionPool, test_name: test_session_pool_release_logic)
2025-12-12 10:05:21,071 - DEBUG - ydb.table.SessionPool.2075013  - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-12 10:05:21,087 - DEBUG - ydb.table.SessionPool.2075013  - subscribe: Subscribe waiter <Future at 0x7fc509379460 state=pending>
2025-12-12 10:05:21,087 - DEBUG - ydb.table.SessionPool.2075013  - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-12-12 10:05:21,093 - DEBUG - ydb.table.SessionPool.2075013  - _create: Created session <ydb.table.Session object at 0x7fc5093790f0>
2025-12-12 10:05:21,097 - DEBUG - ydb.table.SessionPool.2075013  - _prepare: Preparing session <ydb.table.Session object at 0x7fc5093790f0>
2025-12-12 10:05:21,104 - DEBUG - ydb.connection.2075013  - _prepare_call: RpcState(CreateSession, 69b5ce5d-b766-4a8e-a049-4c8168fd726c, ghrun-llwi4fnhxu.auto.internal:15935): creating call state
2025-12-12 10:05:21,124 - DEBUG - ydb.connection.2075013  - _log_request: RpcState(CreateSession, 69b5ce5d-b766-4a8e-a049-4c8168fd726c, ghrun-llwi4fnhxu.auto.internal:15935): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-12 10:05:21,137 - DEBUG - ydb.connection.2075013  - _on_response_callback: RpcState(CreateSession, 69b5ce5d-b766-4a8e-a049-4c8168fd726c, ghrun-llwi4fnhxu.auto.internal:15935): on response callback started
2025-12-12 10:05:21,161 - DEBUG - ydb.connection.2075013  - _log_response: RpcState(CreateSession, 69b5ce5d-b766-4a8e-a049-4c8168fd726c, ghrun-llwi4fnhxu.auto.internal:15935): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZTE4N2Y1ZmYtNTdlZWFhM2UtYjM0M2JiNzMtMmE0MjFjZDY=" } } } }
2025-12-12 10:05:21,161 - DEBUG - ydb.table.SessionPool.2075013  - put: Put on session <ydb.table.Session object at 0x7fc5093790f0>
2025-12-12 10:05:21,166 - DEBUG - ydb.table.SessionPool.2075013  - put: Replying to waiter with a session <ydb.table.Session object at 0x7fc5093790f0>
2025-12-12 10:05:21,166 - DEBUG - ydb.connection.2075013  - _on_response_callback: RpcState(CreateSession, 69b5ce5d-b766-4a8e-a049-4c8168fd726c, ghrun-llwi4fnhxu.auto.internal:15935): on response callback success
2025-12-12 10:05:21,167 - DEBUG - ydb.table.SessionPool.2075013  - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-12 10:05:21,168 - DEBUG - ydb.table.SessionPool.2075013  - subscribe: Subscribe waiter <Future at 0x7fc509378470 state=pending>
2025-12-12 10:05:21,168 - DEBUG - ydb.table.SessionPool.2075013  - put: Put on session <ydb.table.Session object at 0x7fc5093790f0>
2025-12-12 10:05:21,177 - DEBUG - ydb.table.SessionPool.2075013  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7fc5093790f0>, reason: not-initialized
2025-12-12 10:05:21,177 - DEBUG - ydb.table.SessionPool.2075013  - _destroy: Session <ydb.table.Session object at 0x7fc5093790f0> is no longer active. Current active count 0.
2025-12-12 10:05:21,178 - DEBUG - ydb.table.SessionPool.2075013  - _destroy: In flight waiters: 1, preparing session <ydb.table.Session object at 0x7fc5093790f0> replacement.
2025-12-12 10:05:21,180 - DEBUG - ydb.table.SessionPool.2075013  - _create: Created session <ydb.table.Session object at 0x7fc508a7b0d0>
2025-12-12 10:05:21,202 - DEBUG - ydb.table.SessionPool.2075013  - _prepare: Preparing session <ydb.table.Session object at 0x7fc508a7b0d0>
2025-12-12 10:05:21,217 - DEBUG - ydb.connection.2075013  - _prepare_call: RpcState(CreateSession, c0263f77-eaad-49e5-b2f2-0a8fc908d62b, ghrun-llwi4fnhxu.auto.internal:15935): creating call state
2025-12-12 10:05:21,236 - DEBUG - ydb.connection.2075013  - _log_request: RpcState(CreateSession, c0263f77-eaad-49e5-b2f2-0a8fc908d62b, ghrun-llwi4fnhxu.auto.internal:15935): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-12 10:05:21,257 - DEBUG - ydb.connection.2075013  - _on_response_callback: RpcState(CreateSession, c0263f77-eaad-49e5-b2f2-0a8fc908d62b, ghrun-llwi4fnhxu.auto.internal:15935): on response callback started
2025-12-12 10:05:21,261 - DEBUG - ydb.connection.2075013  - _log_response: RpcState(CreateSession, c0263f77-eaad-49e5-b2f2-0a8fc908d62b, ghrun-llwi4fnhxu.auto.internal:15935): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=MTVkOWIzMDQtZjc5MGE3MjEtNjJmOTMzZjUtNTBmY2U5NDg=" } } } }
2025-12-12 10:05:21,262 - DEBUG - ydb.table.SessionPool.2075013  - put: Put on session <ydb.table.Session object at 0x7fc508a7b0d0>
2025-12-12 10:05:21,262 - DEBUG - ydb.table.SessionPool.2075013  - put: Replying to waiter with a session <ydb.table.Session object at 0x7fc508a7b0d0>
2025-12-12 10:05:21,262 - DEBUG - ydb.connection.2075013  - _on_response_callback: RpcState(CreateSession, c0263f77-eaad-49e5-b2f2-0a8fc908d62b, ghrun-llwi4fnhxu.auto.internal:15935): on response callback success
2025-12-12 10:05:21,264 - DEBUG - ydb.table.SessionPool.2075013  - stop: Requested session pool stop.
2025-12-12 10:05:21,266 - DEBUG - ydb.table.SessionPool.2075013  - stop: Session pool is under stop, cancelling all in flight waiters.
2025-12-12 10:05:21,266 - DEBUG - ydb.table.SessionPool.2075013  - stop: Destroying sessions in active queue
2025-12-12 10:05:21,266 - DEBUG - ydb.table.SessionPool.2075013  - stop: Destroyed active sessions
2025-12-12 10:05:21,266 - DEBUG - ydb.table.SessionPool.2075013  - _terminate_event: Terminated session pool.
2025-12-12 10:05:21,278 - INFO - ya.test.2075013  - pytest_runtest_teardown: Test teardown
