2025-11-26 18:39:17,606 - INFO - ya.test.2254636  - pytest_runtest_setup: ####################################################################################################
2025-11-26 18:39:17,608 - INFO - ya.test.2254636  - pytest_runtest_setup: test_session_pool_keep_alive
2025-11-26 18:39:17,608 - INFO - ya.test.2254636  - pytest_runtest_setup: ####################################################################################################
2025-11-26 18:39:17,608 - INFO - ya.test.2254636  - pytest_runtest_setup: Test setup
2025-11-26 18:39:17,617 - INFO - ya.test.2254636  - pytest_runtest_call: Test call (class_name: test_session_pool.py::TestSessionPool, test_name: test_session_pool_keep_alive)
2025-11-26 18:39:17,618 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-26 18:39:17,632 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Subscribe waiter <Future at 0x7f2c7f6726d0 state=pending>
2025-11-26 18:39:17,666 - 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,667 - DEBUG - ydb.table.SessionPool.2254636  - _create: Created session <ydb.table.Session object at 0x7f2c7f672d10>
2025-11-26 18:39:17,675 - DEBUG - ydb.table.SessionPool.2254636  - _prepare: Preparing session <ydb.table.Session object at 0x7f2c7f672d10>
2025-11-26 18:39:17,676 - DEBUG - ydb.connection.2254636  - _prepare_call: RpcState(CreateSession, ebffdf28-c9a2-478c-9d50-62fd04e93e73, ghrun-ihttfokzrq.auto.internal:12792): creating call state
2025-11-26 18:39:17,699 - DEBUG - ydb.connection.2254636  - _log_request: RpcState(CreateSession, ebffdf28-c9a2-478c-9d50-62fd04e93e73, ghrun-ihttfokzrq.auto.internal:12792): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-26 18:39:17,702 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(CreateSession, ebffdf28-c9a2-478c-9d50-62fd04e93e73, ghrun-ihttfokzrq.auto.internal:12792): on response callback started
2025-11-26 18:39:17,711 - DEBUG - ydb.connection.2254636  - _log_response: RpcState(CreateSession, ebffdf28-c9a2-478c-9d50-62fd04e93e73, 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=YTcyMzc0NjktMTQ2NDViMjgtY2Q1MGY5NmQtZGZmNjgwZTg=" } } } }
2025-11-26 18:39:17,715 - DEBUG - ydb.table.SessionPool.2254636  - put: Put on session <ydb.table.Session object at 0x7f2c7f672d10>
2025-11-26 18:39:17,719 - DEBUG - ydb.table.SessionPool.2254636  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f2c7f672d10>
2025-11-26 18:39:17,720 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(CreateSession, ebffdf28-c9a2-478c-9d50-62fd04e93e73, ghrun-ihttfokzrq.auto.internal:12792): on response callback success
2025-11-26 18:39:17,723 - DEBUG - ydb.table.SessionPool.2254636  - put: Put on session <ydb.table.Session object at 0x7f2c7f672d10>
2025-11-26 18:39:17,734 - DEBUG - ydb.connection.2254636  - _prepare_call: RpcState(KeepAlive, 40555a7d-8ec7-4d1b-87ae-f6d4247994a6, ghrun-ihttfokzrq.auto.internal:12792): creating call state
2025-11-26 18:39:17,738 - DEBUG - ydb.connection.2254636  - _log_request: RpcState(KeepAlive, 40555a7d-8ec7-4d1b-87ae-f6d4247994a6, ghrun-ihttfokzrq.auto.internal:12792): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzc0NjktMTQ2NDViMjgtY2Q1MGY5NmQtZGZmNjgwZTg=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-26 18:39:17,747 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-26 18:39:17,749 - DEBUG - ydb.table.SessionPool.2254636  - subscribe: Subscribe waiter <Future at 0x7f2c7ec33e40 state=pending>
2025-11-26 18:39:17,751 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(KeepAlive, 40555a7d-8ec7-4d1b-87ae-f6d4247994a6, ghrun-ihttfokzrq.auto.internal:12792): on response callback started
2025-11-26 18:39:17,756 - DEBUG - ydb.connection.2254636  - _log_response: RpcState(KeepAlive, 40555a7d-8ec7-4d1b-87ae-f6d4247994a6, ghrun-ihttfokzrq.auto.internal:12792): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.KeepAliveResult] { session_status: SESSION_STATUS_READY } } } }
2025-11-26 18:39:17,759 - DEBUG - ydb.table.SessionPool.2254636  - put: Put on session <ydb.table.Session object at 0x7f2c7f672d10>
2025-11-26 18:39:17,764 - DEBUG - ydb.table.SessionPool.2254636  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f2c7f672d10>
2025-11-26 18:39:17,764 - DEBUG - ydb.connection.2254636  - _on_response_callback: RpcState(KeepAlive, 40555a7d-8ec7-4d1b-87ae-f6d4247994a6, ghrun-ihttfokzrq.auto.internal:12792): on response callback success
2025-11-26 18:39:17,765 - DEBUG - ydb.table.SessionPool.2254636  - stop: Requested session pool stop.
2025-11-26 18:39:17,771 - DEBUG - ydb.table.SessionPool.2254636  - stop: Session pool is under stop, cancelling all in flight waiters.
2025-11-26 18:39:17,771 - DEBUG - ydb.table.SessionPool.2254636  - _terminate_event: Terminated session pool.
2025-11-26 18:39:17,772 - DEBUG - ydb.table.SessionPool.2254636  - stop: Destroying sessions in active queue
2025-11-26 18:39:17,773 - DEBUG - ydb.table.SessionPool.2254636  - stop: Destroyed active sessions
2025-11-26 18:39:17,775 - INFO - ya.test.2254636  - pytest_runtest_teardown: Test teardown
