2026-08-19 13:41:49,680 - INFO - ya.test.1621738  - pytest_runtest_setup: ####################################################################################################
2026-08-19 13:41:49,680 - INFO - ya.test.1621738  - pytest_runtest_setup: test_session_pool_close_basic_logic_case_1
2026-08-19 13:41:49,680 - INFO - ya.test.1621738  - pytest_runtest_setup: ####################################################################################################
2026-08-19 13:41:49,681 - INFO - ya.test.1621738  - pytest_runtest_setup: Test setup
2026-08-19 13:41:49,682 - INFO - ya.test.1621738  - pytest_runtest_call: Test call (class_name: test_session_pool.py::TestSessionPool, test_name: test_session_pool_close_basic_logic_case_1)
2026-08-19 13:41:49,682 - DEBUG - ydb.table.SessionPool.1621738  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:49,683 - DEBUG - ydb.table.SessionPool.1621738  - subscribe: Subscribe waiter <Future at 0x7f74547b9b60 state=pending>
2026-08-19 13:41:49,684 - DEBUG - ydb.table.SessionPool.1621738  - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2026-08-19 13:41:49,685 - DEBUG - ydb.table.SessionPool.1621738  - _create: Created session <ydb.table.Session object at 0x7f74531ab8a0>
2026-08-19 13:41:49,685 - DEBUG - ydb.table.SessionPool.1621738  - _prepare: Preparing session <ydb.table.Session object at 0x7f74531ab8a0>
2026-08-19 13:41:49,685 - DEBUG - ydb.connection.1621738  - _prepare_call: RpcState(CreateSession, 1eb1bf2a-7aa8-46e6-bae2-e459d565aa5a, ghrun-4q22hfe2g4.auto.internal:32230): creating call state
2026-08-19 13:41:49,686 - DEBUG - ydb.connection.1621738  - _log_request: RpcState(CreateSession, 1eb1bf2a-7aa8-46e6-bae2-e459d565aa5a, ghrun-4q22hfe2g4.auto.internal:32230): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:49,688 - DEBUG - ydb.connection.1621738  - _on_response_callback: RpcState(CreateSession, 1eb1bf2a-7aa8-46e6-bae2-e459d565aa5a, ghrun-4q22hfe2g4.auto.internal:32230): on response callback started
2026-08-19 13:41:49,689 - DEBUG - ydb.connection.1621738  - _log_response: RpcState(CreateSession, 1eb1bf2a-7aa8-46e6-bae2-e459d565aa5a, ghrun-4q22hfe2g4.auto.internal:32230): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=YmQ3YzljMDgtNjEyOTAxNGItMjMwNDUyZWUtN2ZhODY2NTU=" } } } }
2026-08-19 13:41:49,689 - DEBUG - ydb.table.SessionPool.1621738  - put: Put on session <ydb.table.Session object at 0x7f74531ab8a0>
2026-08-19 13:41:49,690 - DEBUG - ydb.table.SessionPool.1621738  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f74531ab8a0>
2026-08-19 13:41:49,690 - DEBUG - ydb.connection.1621738  - _on_response_callback: RpcState(CreateSession, 1eb1bf2a-7aa8-46e6-bae2-e459d565aa5a, ghrun-4q22hfe2g4.auto.internal:32230): on response callback success
2026-08-19 13:41:49,690 - DEBUG - ydb.table.SessionPool.1621738  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:49,691 - DEBUG - ydb.table.SessionPool.1621738  - subscribe: Subscribe waiter <Future at 0x7f74547ba100 state=pending>
2026-08-19 13:41:49,691 - DEBUG - ydb.table.SessionPool.1621738  - stop: Requested session pool stop.
2026-08-19 13:41:49,691 - DEBUG - ydb.table.SessionPool.1621738  - stop: Session pool is under stop, cancelling all in flight waiters.
2026-08-19 13:41:49,691 - DEBUG - ydb.table.SessionPool.1621738  - _terminate_event: Terminated session pool.
2026-08-19 13:41:49,692 - DEBUG - ydb.table.SessionPool.1621738  - _create: Created session <ydb.table.Session object at 0x7f74531c1490>
2026-08-19 13:41:49,692 - DEBUG - ydb.table.SessionPool.1621738  - stop: Waiter <Future at 0x7f74547ba100 state=finished returned Session> has been replied with empty session info. Session details: <ydb.table.Session object at 0x7f74531c1490>.
2026-08-19 13:41:49,693 - DEBUG - ydb.table.SessionPool.1621738  - stop: Destroying sessions in active queue
2026-08-19 13:41:49,693 - DEBUG - ydb.table.SessionPool.1621738  - stop: Destroyed active sessions
2026-08-19 13:41:49,693 - ERROR - ydb.table.SessionPool.1621738  - acquire: Take session from closed session pool
2026-08-19 13:41:49,693 - DEBUG - ydb.table.SessionPool.1621738  - unsubscribe: Unsubscribe on waiter <Future at 0x7f74547ba100 state=finished returned Session>
2026-08-19 13:41:49,694 - DEBUG - ydb.table.SessionPool.1621738  - put: Put on session <ydb.table.Session object at 0x7f74531c1490>
2026-08-19 13:41:49,694 - DEBUG - ydb.table.SessionPool.1621738  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f74531c1490>, reason: not-initialized
2026-08-19 13:41:49,694 - DEBUG - ydb.table.SessionPool.1621738  - _destroy: Session <ydb.table.Session object at 0x7f74531c1490> is no longer active. Current active count 1.
2026-08-19 13:41:49,694 - DEBUG - ydb.table.SessionPool.1621738  - put: Put on session <ydb.table.Session object at 0x7f74531ab8a0>
2026-08-19 13:41:49,694 - DEBUG - ydb.table.SessionPool.1621738  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f74531ab8a0>, reason: not-initialized
2026-08-19 13:41:49,695 - DEBUG - ydb.table.SessionPool.1621738  - _destroy: Session <ydb.table.Session object at 0x7f74531ab8a0> is no longer active. Current active count 0.
2026-08-19 13:41:49,695 - DEBUG - ydb.connection.1621738  - _prepare_call: RpcState(DeleteSession, 6ead5fbc-78f2-42e2-b203-4213b43278e7, ghrun-4q22hfe2g4.auto.internal:32230): creating call state
2026-08-19 13:41:49,695 - DEBUG - ydb.connection.1621738  - _log_request: RpcState(DeleteSession, 6ead5fbc-78f2-42e2-b203-4213b43278e7, ghrun-4q22hfe2g4.auto.internal:32230): request = { session_id: "ydb://session/3?node_id=1&id=YmQ3YzljMDgtNjEyOTAxNGItMjMwNDUyZWUtN2ZhODY2NTU=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:49,696 - DEBUG - ydb.table.SessionPool.1621738  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f74531ab8a0>
2026-08-19 13:41:49,698 - DEBUG - ydb.connection.1621738  - _on_response_callback: RpcState(DeleteSession, 6ead5fbc-78f2-42e2-b203-4213b43278e7, ghrun-4q22hfe2g4.auto.internal:32230): on response callback started
2026-08-19 13:41:49,698 - DEBUG - ydb.connection.1621738  - _log_response: RpcState(DeleteSession, 6ead5fbc-78f2-42e2-b203-4213b43278e7, ghrun-4q22hfe2g4.auto.internal:32230): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:49,699 - INFO - ya.test.1621738  - pytest_runtest_teardown: Test teardown
2026-08-19 13:41:49,699 - DEBUG - ydb.connection.1621738  - _on_response_callback: RpcState(DeleteSession, 6ead5fbc-78f2-42e2-b203-4213b43278e7, ghrun-4q22hfe2g4.auto.internal:32230): on response callback success
