2025-12-08 23:28:04,417 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-08 23:28:04,425 - INFO - ya.test - pytest_runtest_setup: test_session_pool_release_logic
2025-12-08 23:28:04,426 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-08 23:28:04,427 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-12-08 23:28:04,431 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_session_pool.py::TestSessionPool, test_name: test_session_pool_release_logic)
2025-12-08 23:28:04,432 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-08 23:28:04,434 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f082557acc0 state=pending>
2025-12-08 23:28:04,435 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-12-08 23:28:04,435 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f082557a630>
2025-12-08 23:28:04,438 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f082557a630>
2025-12-08 23:28:04,441 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 7019bc06-153d-4e70-bfe5-2e7122e473d0, ghrun-sfoiezpm3a.auto.internal:1785): creating call state
2025-12-08 23:28:04,442 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 7019bc06-153d-4e70-bfe5-2e7122e473d0, ghrun-sfoiezpm3a.auto.internal:1785): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-08 23:28:04,447 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 7019bc06-153d-4e70-bfe5-2e7122e473d0, ghrun-sfoiezpm3a.auto.internal:1785): on response callback started
2025-12-08 23:28:04,447 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 7019bc06-153d-4e70-bfe5-2e7122e473d0, ghrun-sfoiezpm3a.auto.internal:1785): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=MjJmZTgyNWQtNWJlMzBmYjQtZjA4YzE1NTYtOTA0NGY2ZTc=" } } } }
2025-12-08 23:28:04,451 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f082557a630>
2025-12-08 23:28:04,454 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f082557a630>
2025-12-08 23:28:04,458 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 7019bc06-153d-4e70-bfe5-2e7122e473d0, ghrun-sfoiezpm3a.auto.internal:1785): on response callback success
2025-12-08 23:28:04,458 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-08 23:28:04,463 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7f0825579820 state=pending>
2025-12-08 23:28:04,465 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f082557a630>
2025-12-08 23:28:04,466 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f082557a630>, reason: not-initialized
2025-12-08 23:28:04,466 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7f082557a630> is no longer active. Current active count 0.
2025-12-08 23:28:04,467 - DEBUG - ydb.table.SessionPool - _destroy: In flight waiters: 1, preparing session <ydb.table.Session object at 0x7f082557a630> replacement.
2025-12-08 23:28:04,468 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7f0827305af0>
2025-12-08 23:28:04,470 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7f0827305af0>
2025-12-08 23:28:04,471 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 6fc2abcf-06d0-435c-bb07-2af9b4799a18, ghrun-sfoiezpm3a.auto.internal:1785): creating call state
2025-12-08 23:28:04,486 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 6fc2abcf-06d0-435c-bb07-2af9b4799a18, ghrun-sfoiezpm3a.auto.internal:1785): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-08 23:28:04,495 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 6fc2abcf-06d0-435c-bb07-2af9b4799a18, ghrun-sfoiezpm3a.auto.internal:1785): on response callback started
2025-12-08 23:28:04,501 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 6fc2abcf-06d0-435c-bb07-2af9b4799a18, ghrun-sfoiezpm3a.auto.internal:1785): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=NWYwYWQ0ZWYtMWViZmU5NGYtMmZkZjdkYTUtYmU3NGRjZGU=" } } } }
2025-12-08 23:28:04,504 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7f0827305af0>
2025-12-08 23:28:04,514 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7f0827305af0>
2025-12-08 23:28:04,514 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 6fc2abcf-06d0-435c-bb07-2af9b4799a18, ghrun-sfoiezpm3a.auto.internal:1785): on response callback success
2025-12-08 23:28:04,515 - DEBUG - ydb.table.SessionPool - stop: Requested session pool stop.
2025-12-08 23:28:04,522 - DEBUG - ydb.table.SessionPool - stop: Session pool is under stop, cancelling all in flight waiters.
2025-12-08 23:28:04,522 - DEBUG - ydb.table.SessionPool - _terminate_event: Terminated session pool.
2025-12-08 23:28:04,524 - DEBUG - ydb.table.SessionPool - stop: Destroying sessions in active queue
2025-12-08 23:28:04,532 - DEBUG - ydb.table.SessionPool - stop: Destroyed active sessions
2025-12-08 23:28:04,537 - INFO - ya.test - pytest_runtest_teardown: Test teardown
