2025-11-26 18:39:17,908 - INFO - ya.test.2254636  - pytest_runtest_setup: ####################################################################################################
2025-11-26 18:39:17,910 - INFO - ya.test.2254636  - pytest_runtest_setup: test_session_pool_release_logic
2025-11-26 18:39:17,910 - INFO - ya.test.2254636  - pytest_runtest_setup: ####################################################################################################
2025-11-26 18:39:17,918 - INFO - ya.test.2254636  - pytest_runtest_setup: Test setup
2025-11-26 18:39:17,922 - INFO - ya.test.2254636  - pytest_runtest_call: Test call (class_name: test_session_pool.py::TestSessionPool, test_name: test_session_pool_release_logic)
2025-11-26 18:39:17,930 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-26 18:39:17,931 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Subscribe waiter <Future at 0x7f2c8104bd00 state=pending>
2025-11-26 18:39:17,931 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-11-26 18:39:17,934 - DEBUG - ydb.table.SessionPool.2254636  - _create: Created session <ydb.table.Session object at 0x7f2c8104a770>
2025-11-26 18:39:17,935 - DEBUG - ydb.table.SessionPool.2254636  - _prepare: Preparing session <ydb.table.Session object at 0x7f2c8104a770>
2025-11-26 18:39:17,936 - DEBUG - ydb.connection.2254636  - _prepare_call: RpcState(CreateSession, 9e334e15-3a83-4a9a-b989-752d9552f515, ghrun-ihttfokzrq.auto.internal:12792): creating call state
2025-11-26 18:39:17,937 - DEBUG - ydb.connection.2254636  - _log_request: RpcState(CreateSession, 9e334e15-3a83-4a9a-b989-752d9552f515, ghrun-ihttfokzrq.auto.internal:12792): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-26 18:39:17,940 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(CreateSession, 9e334e15-3a83-4a9a-b989-752d9552f515, ghrun-ihttfokzrq.auto.internal:12792): on response callback started
2025-11-26 18:39:17,940 - DEBUG - ydb.connection.2254636  - _log_response: RpcState(CreateSession, 9e334e15-3a83-4a9a-b989-752d9552f515, ghrun-ihttfokzrq.auto.internal:12792): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZjcwZWIzNTAtNGUxMWJjOS02YzI3M2UzMS1mZGFjOTc1NA==" } } } }
2025-11-26 18:39:17,941 - DEBUG - ydb.table.SessionPool.2254636  - put: Put on session <ydb.table.Session object at 0x7f2c8104a770>
2025-11-26 18:39:17,941 - DEBUG - ydb.table.SessionPool.2254636  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f2c8104a770>
2025-11-26 18:39:17,941 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(CreateSession, 9e334e15-3a83-4a9a-b989-752d9552f515, ghrun-ihttfokzrq.auto.internal:12792): on response callback success
2025-11-26 18:39:17,942 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-26 18:39:17,943 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Subscribe waiter <Future at 0x7f2c7ec32ef0 state=pending>
2025-11-26 18:39:17,943 - DEBUG - ydb.table.SessionPool.2254636  - put: Put on session <ydb.table.Session object at 0x7f2c8104a770>
2025-11-26 18:39:17,948 - DEBUG - ydb.table.SessionPool.2254636  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f2c8104a770>, reason: not-initialized
2025-11-26 18:39:17,949 - DEBUG - ydb.table.SessionPool.2254636  - _destroy: Session <ydb.table.Session object at 0x7f2c8104a770> is no longer active. Current active count 0.
2025-11-26 18:39:17,958 - DEBUG - ydb.table.SessionPool.2254636  - _destroy: In flight waiters: 1, preparing session <ydb.table.Session object at 0x7f2c8104a770> replacement.
2025-11-26 18:39:17,964 - DEBUG - ydb.table.SessionPool.2254636  - _create: Created session <ydb.table.Session object at 0x7f2c7ec33490>
2025-11-26 18:39:17,965 - DEBUG - ydb.table.SessionPool.2254636  - _prepare: Preparing session <ydb.table.Session object at 0x7f2c7ec33490>
2025-11-26 18:39:17,965 - DEBUG - ydb.connection.2254636  - _prepare_call: RpcState(CreateSession, 4cb0fa4a-6b33-4f6a-89e8-7561ff55488d, ghrun-ihttfokzrq.auto.internal:12792): creating call state
2025-11-26 18:39:17,965 - DEBUG - ydb.connection.2254636  - _log_request: RpcState(CreateSession, 4cb0fa4a-6b33-4f6a-89e8-7561ff55488d, ghrun-ihttfokzrq.auto.internal:12792): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-26 18:39:17,977 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(CreateSession, 4cb0fa4a-6b33-4f6a-89e8-7561ff55488d, ghrun-ihttfokzrq.auto.internal:12792): on response callback started
2025-11-26 18:39:17,978 - DEBUG - ydb.connection.2254636  - _log_response: RpcState(CreateSession, 4cb0fa4a-6b33-4f6a-89e8-7561ff55488d, ghrun-ihttfokzrq.auto.internal:12792): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ODVmNzM1ZjctZWNmNjgyOGYtYzA0ZWIxZWUtMmFiMDZmMGI=" } } } }
2025-11-26 18:39:17,978 - DEBUG - ydb.table.SessionPool.2254636  - put: Put on session <ydb.table.Session object at 0x7f2c7ec33490>
2025-11-26 18:39:17,979 - DEBUG - ydb.table.SessionPool.2254636  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f2c7ec33490>
2025-11-26 18:39:17,980 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(CreateSession, 4cb0fa4a-6b33-4f6a-89e8-7561ff55488d, ghrun-ihttfokzrq.auto.internal:12792): on response callback success
2025-11-26 18:39:17,980 - DEBUG - ydb.table.SessionPool.2254636  - stop: Requested session pool stop.
2025-11-26 18:39:17,984 - DEBUG - ydb.table.SessionPool.2254636  - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-26 18:39:17,984 - DEBUG - ydb.table.SessionPool.2254636  - _terminate_event: Terminated session pool.
2025-11-26 18:39:17,985 - DEBUG - ydb.table.SessionPool.2254636  - stop: Destroying sessions in active queue
2025-11-26 18:39:17,986 - DEBUG - ydb.table.SessionPool.2254636  - stop: Destroyed active sessions
2025-11-26 18:39:17,987 - INFO - ya.test.2254636  - pytest_runtest_teardown: Test teardown
