2025-10-31 15:41:03,959 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-10-31 15:41:03,959 - INFO - ya.test - pytest_runtest_setup: test_grace_shutdown_of_session
2025-10-31 15:41:03,959 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-10-31 15:41:03,960 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-10-31 15:41:04,040 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd
2025-10-31 15:41:04,042 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/64888
2025-10-31 15:41:04,043 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/5f72/001e02/r3tmp/kikimr_cluster_le5wt8pf
2025-10-31 15:41:04,078 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd
2025-10-31 15:41:04,079 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/10827
2025-10-31 15:41:04,080 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/18784
2025-10-31 15:41:04,085 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/7639
2025-10-31 15:41:04,085 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/23158
2025-10-31 15:41:04,087 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/5f72/001e02/ydb/tests/functional/api/test-results/py3test/testing_out_stuff/test_session_grace_shutdown/testing_out_stuff/test_session_grace_shutdown.py.Test.test_grace_shutdown_of_session/cluster/kikimr_configs"
2025-10-31 15:41:04,087 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --log-file-name=/home/runner/.ya/build/build_root/5f72/001e02/ydb/tests/functional/api/test-results/py3test/testing_out_stuff/test_session_grace_shutdown/testing_out_stuff/test_session_grace_shutdown.py.Test.test_grace_shutdown_of_session/cluster/node_1/logfile_u6rwhfr4.log --grpc-port=10827 --mon-port=18784 --ic-port=64888
2025-10-31 15:41:04,088 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:10827/1, disk_size 68719476736
2025-10-31 15:41:04,097 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/5f72/001e02/ydb/tests/functional/api/test-results/py3test/testing_out_stuff/test_session_grace_shutdown/testing_out_stuff/test_session_grace_shutdown.py.Test.test_grace_shutdown_of_session/cluster/kikimr_configs"
2025-10-31 15:41:04,097 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --log-file-name=/home/runner/.ya/build/build_root/5f72/001e02/ydb/tests/functional/api/test-results/py3test/testing_out_stuff/test_session_grace_shutdown/testing_out_stuff/test_session_grace_shutdown.py.Test.test_grace_shutdown_of_session/cluster/node_1/logfile_u6rwhfr4.log --grpc-port=10827 --mon-port=18784 --ic-port=64888
2025-10-31 15:41:04,103 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/5f72/001e02/ydb/tests/functional/api/test-results/py3test/testing_out_stuff/test_session_grace_shutdown/testing_out_stuff/test_session_grace_shutdown.py.Test.test_grace_shutdown_of_session/cluster/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/5f72/001e02/ydb/tests/functional/api/test-results/py3test/testing_out_stuff/test_session_grace_shutdown/testing_out_stuff/test_session_grace_shutdown.py.Test.test_grace_shutdown_of_session/cluster/node_1/logfile_u6rwhfr4.log', '--grpc-port=10827', '--mon-port=18784', '--ic-port=64888')' in '/home/runner/.ya/build/build_root/5f72/001e02/ydb/tests/functional/api/test-results/py3test/testing_out_stuff/test_session_grace_shutdown/testing_out_stuff/test_session_grace_shutdown.py.Test.test_grace_shutdown_of_session/cluster/node_1' (no wait)
2025-10-31 15:41:04,105 - DEBUG - ya.test - execute: Command pid: 1634828
2025-10-31 15:41:04,113 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:10827/1
2025-10-31 15:41:04,115 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out
2025-10-31 15:41:04,115 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err
2025-10-31 15:41:04,116 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-10-31 15:41:04,116 - DEBUG - ya.test - execute: Command pid: 1634829
2025-10-31 15:41:04,600 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) rc: 0
2025-10-31 15:41:04,600 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) elapsed time (sec): 0.46514010429382324
2025-10-31 15:41:04,600 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) idrss: 0
2025-10-31 15:41:04,601 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) inblock: 0
2025-10-31 15:41:04,601 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) isrss: 0
2025-10-31 15:41:04,601 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) ixrss: 0
2025-10-31 15:41:04,601 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) majflt: 0
2025-10-31 15:41:04,601 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) maxrss: 538340
2025-10-31 15:41:04,611 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) minflt: 16132
2025-10-31 15:41:04,612 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) msgrcv: 0
2025-10-31 15:41:04,614 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) msgsnd: 0
2025-10-31 15:41:04,614 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) nivcsw: 84
2025-10-31 15:41:04,615 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) nsignals: 0
2025-10-31 15:41:04,624 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) nswap: 0
2025-10-31 15:41:04,625 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) nvcsw: 15
2025-10-31 15:41:04,625 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) oublock: 8
2025-10-31 15:41:04,625 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) stime: 0.275821
2025-10-31 15:41:04,625 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) utime: 0.115298
2025-10-31 15:41:04,625 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) wtime: 0.484
2025-10-31 15:41:04,626 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) output:
Git info:
    Commit: f77d4c0db8e29b711e291c6e811417b1705d98de
    Branch: 
    Author: Andrey Zaspa <zacpa@ya.ru>
    Summary: Merge 8194541ce3db03442342000f56fca16c047713d3 into 4af0266bcdc7df80879f060afb0976424f2118ed

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-xldpwfo7ey
    Host information: 
        Linux ghrun-xldpwfo7ey 5.15.0-157-generic #167-Ubuntu SMP Wed Sep 17 21:35:53 UTC 2025 x86_64

    
Build info:
    Compiler: /home/runner/.ya/tools/v4/9944335923/bin/clang++
    Compiler version: 
        clang version 20.1.8
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/9944335923/bin
    Compile flags: -Xclang -fdebug-compilation-dir -Xclang /tmp -pipe -m64 -O3 -gline-tables-only -fno-common -ffunction-sections -fdata-sections -fsized-deallocation -fexceptions -fuse-init-array -fcolor-diagnostics -faligned-allocation -Werror -Wall -Wextra -Wno-parentheses -Wno-implicit-const-int-float-conversion -Wno-unknown-warning-option -D_THREAD_SAFE -D_PTHREADS -D_REENTRANT -D_LARGEFILE_SOURCE -D__STDC_CONSTANT_MACROS -D__STDC_FORMAT_MACROS -D_FILE_OFFSET_BITS=64 -D_GNU_SOURCE -D_YNDX_LIBUNWIND_ENABLE_EXCEPTION_BACKTRACE -D__LONG_LONG_SUPPORTED -fno-omit-frame-pointer -Wno-unknown-argument -UNDEBUG -Wno-array-parameter -Wno-deprecate-lax-vec-conv-all -Wno-unqualified-std-cast-call -Wno-unused-but-set-parameter -Wno-implicit-function-declaration -Wno-int-conversion -Wno-incompatible-function-pointer-types -Wno-address-of-packed-member -Wno-deprecated-this-capture -Wno-missing-designated-field-initializers -Wno-format -Wno-vla-cxx-extension -Wno-invalid-offsetof -Wno-alias-template-in-declaration-name -Wno-cast-function-type-mismatch -Wno-explicit-specialization-storage-class -Wno-extraneous-template-head -Wno-missing-template-arg-list-after-template-kw -Wno-nontrivial-memcall -Wno-strict-primary-template-shadow -DCATBOOST_OPENSOURCE=yes -msse2 -msse3 -mssse3 -msse4.1 -msse4.2 -mpopcnt -mcx16 -UNDEBUG -Wno-array-parameter -Wno-deprecate-lax-vec-conv-all -Wno-unqualified-std-cast-call -Wno-unused-but-set-parameter -Wno-implicit-function-declaration -Wno-int-conversion -Wno-incompatible-function-pointer-types -Wno-address-of-packed-member -Wno-deprecated-this-capture -Wno-missing-designated-field-initializers -Wno-format -Wno-vla-cxx-extension -Wno-invalid-offsetof -Wno-alias-template-in-declaration-name -Wno-cast-function-type-mismatch -Wno-explicit-specialization-storage-class -Wno-extraneous-template-head -Wno-missing-template-arg-list-after-template-kw -Wno-nontrivial-memcall -Wno-strict-primary-template-shadow -std=c++20 -Wimport-preprocessor-directive-pedantic -Woverloaded-virtual -Wno-ambiguous-reversed-operator -Wno-defaulted-function-deleted -Wno-deprecated-anon-enum-enum-conversion -Wno-deprecated-enum-enum-conversion -Wno-deprecated-enum-float-conversion -Wno-deprecated-volatile -Wno-pessimizing-move -Wno-undefined-var-template -nostdinc++ -DCATBOOST_OPENSOURCE=yes -nostdinc++

2025-10-31 15:41:04,626 - DEBUG - ya.test - _save_outputs: Command (pid 1634829) errors:

2025-10-31 15:41:04,626 - INFO - ydb.tests.library.harness.kikimr_runner - start: Node 1 version:
Git info:
    Commit: f77d4c0db8e29b711e291c6e811417b1705d98de
    Branch: 
    Author: Andrey Zaspa <zacpa@ya.ru>
    Summary: Merge 8194541ce3db03442342000f56fca16c047713d3 into 4af0266bcdc7df80879f060afb0976424f2118ed
2025-10-31 15:41:06,668 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd
2025-10-31 15:41:06,668 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10827', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineHostConfig {\n    HostConfigId: 1\n    Drive {\n      Path: "SectorMap:1:64"\n    }\n  }\n}\nCommand {\n  DefineBox {\n    BoxId: 1\n    Host {\n      Key {\n        Fqdn: "localhost"\n        IcPort: 64888\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-10-31 15:41:06,669 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.0
2025-10-31 15:41:06,670 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.0
2025-10-31 15:41:06,670 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10827', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineHostConfig {\n    HostConfigId: 1\n    Drive {\n      Path: "SectorMap:1:64"\n    }\n  }\n}\nCommand {\n  DefineBox {\n    BoxId: 1\n    Host {\n      Key {\n        Fqdn: "localhost"\n        IcPort: 64888\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-10-31 15:41:06,671 - DEBUG - ya.test - execute: Command pid: 1635727
2025-10-31 15:41:07,200 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) rc: 0
2025-10-31 15:41:07,201 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) elapsed time (sec): 0.5285458564758301
2025-10-31 15:41:07,201 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) idrss: 0
2025-10-31 15:41:07,201 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) inblock: 0
2025-10-31 15:41:07,201 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) isrss: 0
2025-10-31 15:41:07,201 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) ixrss: 0
2025-10-31 15:41:07,201 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) majflt: 0
2025-10-31 15:41:07,202 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) maxrss: 546816
2025-10-31 15:41:07,202 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) minflt: 18273
2025-10-31 15:41:07,202 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) msgrcv: 0
2025-10-31 15:41:07,202 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) msgsnd: 0
2025-10-31 15:41:07,202 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) nivcsw: 86
2025-10-31 15:41:07,203 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) nsignals: 0
2025-10-31 15:41:07,203 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) nswap: 0
2025-10-31 15:41:07,203 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) nvcsw: 135
2025-10-31 15:41:07,203 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) oublock: 8
2025-10-31 15:41:07,203 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) stime: 0.29025
2025-10-31 15:41:07,203 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) utime: 0.130972
2025-10-31 15:41:07,203 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) wtime: 0.53
2025-10-31 15:41:07,204 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2025-10-31 15:41:07,204 - DEBUG - ya.test - _save_outputs: Command (pid 1635727) errors:

2025-10-31 15:41:07,205 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd
2025-10-31 15:41:07,205 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10827', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 1\n    Name: "dynamic_storage_pool:1"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "hdd"\n    NumGroups: 2\n    PDiskFilter {\n      Property {\n        Type: ROT\n      }\n      Property {\n        Kind: 0\n      }\n    }\n  }\n}\n']
2025-10-31 15:41:07,208 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.1
2025-10-31 15:41:07,209 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.1
2025-10-31 15:41:07,209 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/5f72/001e02/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10827', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 1\n    Name: "dynamic_storage_pool:1"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "hdd"\n    NumGroups: 2\n    PDiskFilter {\n      Property {\n        Type: ROT\n      }\n      Property {\n        Kind: 0\n      }\n    }\n  }\n}\n']' in 'None' (waiting)
2025-10-31 15:41:07,210 - DEBUG - ya.test - execute: Command pid: 1635901
2025-10-31 15:41:07,965 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) rc: 0
2025-10-31 15:41:07,965 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) elapsed time (sec): 0.7324256896972656
2025-10-31 15:41:07,966 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) idrss: 0
2025-10-31 15:41:07,966 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) inblock: 0
2025-10-31 15:41:07,966 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) isrss: 0
2025-10-31 15:41:07,970 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) ixrss: 0
2025-10-31 15:41:07,971 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) majflt: 0
2025-10-31 15:41:07,971 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) maxrss: 546784
2025-10-31 15:41:07,971 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) minflt: 18272
2025-10-31 15:41:07,971 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) msgrcv: 0
2025-10-31 15:41:07,971 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) msgsnd: 0
2025-10-31 15:41:07,971 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) nivcsw: 127
2025-10-31 15:41:07,972 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) nsignals: 0
2025-10-31 15:41:07,972 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) nswap: 0
2025-10-31 15:41:07,972 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) nvcsw: 137
2025-10-31 15:41:07,972 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) oublock: 8
2025-10-31 15:41:07,972 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) stime: 0.291385
2025-10-31 15:41:07,972 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) utime: 0.145751
2025-10-31 15:41:07,973 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) wtime: 0.741
2025-10-31 15:41:07,973 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-10-31 15:41:07,973 - DEBUG - ya.test - _save_outputs: Command (pid 1635901) errors:

2025-10-31 15:41:07,973 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-10-31 15:41:07,988 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-10-31 15:41:07,999 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-10-31 15:41:08,001 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-10-31 15:41:08,004 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-10-31 15:41:08,016 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-10-31 15:41:08,016 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 2e32b840-2881-445d-a19d-ada44a792bbc, localhost:10827): creating call state
2025-10-31 15:41:08,017 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 2e32b840-2881-445d-a19d-ada44a792bbc, localhost:10827): request = { database: "/Root" }
2025-10-31 15:41:08,024 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 2e32b840-2881-445d-a19d-ada44a792bbc, localhost:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-xldpwfo7ey.auto.internal" port: 10827 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-10-31 15:41:08,054 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-xldpwfo7ey.auto.internal:10827, location 1, ssl: False>]>
2025-10-31 15:41:08,054 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-10-31 15:41:08,077 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_session_grace_shutdown.py::Test, test_name: test_grace_shutdown_of_session)
2025-10-31 15:41:08,078 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,078 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604ac600 state=pending>
2025-10-31 15:41:08,079 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 10). will create a new session.
2025-10-31 15:41:08,079 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604adfa0>
2025-10-31 15:41:08,079 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604adfa0>
2025-10-31 15:41:08,080 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 5dd11a8d-aa32-41d3-b48d-07671d2b068f, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,081 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 5dd11a8d-aa32-41d3-b48d-07671d2b068f, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,083 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 5dd11a8d-aa32-41d3-b48d-07671d2b068f, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,084 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 5dd11a8d-aa32-41d3-b48d-07671d2b068f, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZDI0NDU4MmEtZmUzYmE5ZTAtMmJhMGUzNTAtNzljY2U4Mzc=" } } } }
2025-10-31 15:41:08,084 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604adfa0>
2025-10-31 15:41:08,084 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604adfa0>
2025-10-31 15:41:08,085 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 5dd11a8d-aa32-41d3-b48d-07671d2b068f, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,085 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,086 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604af6c0 state=pending>
2025-10-31 15:41:08,086 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 1 < 10). will create a new session.
2025-10-31 15:41:08,086 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604ae8b0>
2025-10-31 15:41:08,086 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604ae8b0>
2025-10-31 15:41:08,087 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 381ec868-e9c2-4cfd-a89a-c0bf1201bf96, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,087 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 381ec868-e9c2-4cfd-a89a-c0bf1201bf96, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,089 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 381ec868-e9c2-4cfd-a89a-c0bf1201bf96, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,090 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 381ec868-e9c2-4cfd-a89a-c0bf1201bf96, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZWJiNmEwZjUtZTdhNmIxMTItOTFhYzhkMDMtZjZmMWU3MGY=" } } } }
2025-10-31 15:41:08,090 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604ae8b0>
2025-10-31 15:41:08,090 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604ae8b0>
2025-10-31 15:41:08,091 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 381ec868-e9c2-4cfd-a89a-c0bf1201bf96, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,091 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,091 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604a4b00 state=pending>
2025-10-31 15:41:08,091 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 2 < 10). will create a new session.
2025-10-31 15:41:08,092 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604a6db0>
2025-10-31 15:41:08,092 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604a6db0>
2025-10-31 15:41:08,092 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, d5b9d495-9aed-4754-a3ec-304177f15287, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,093 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, d5b9d495-9aed-4754-a3ec-304177f15287, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,094 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, d5b9d495-9aed-4754-a3ec-304177f15287, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,095 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, d5b9d495-9aed-4754-a3ec-304177f15287, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=N2I2OTk3Mi1iNzNkNjdkZi0zN2I2NTJhYy1mMzFiNDY5Yw==" } } } }
2025-10-31 15:41:08,095 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a6db0>
2025-10-31 15:41:08,096 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604a6db0>
2025-10-31 15:41:08,096 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, d5b9d495-9aed-4754-a3ec-304177f15287, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,096 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,097 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604c4150 state=pending>
2025-10-31 15:41:08,097 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 3 < 10). will create a new session.
2025-10-31 15:41:08,097 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604a4e20>
2025-10-31 15:41:08,098 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604a4e20>
2025-10-31 15:41:08,098 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 20784682-0767-44ef-8491-ab8960404e9c, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,098 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 20784682-0767-44ef-8491-ab8960404e9c, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,100 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 20784682-0767-44ef-8491-ab8960404e9c, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,101 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 20784682-0767-44ef-8491-ab8960404e9c, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZTE4MTdjZTItYzUwZGJiZjMtYWY2ZDE1ZjktZDI3ZDg5NjE=" } } } }
2025-10-31 15:41:08,101 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a4e20>
2025-10-31 15:41:08,101 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604a4e20>
2025-10-31 15:41:08,102 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 20784682-0767-44ef-8491-ab8960404e9c, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,102 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,102 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604a6c70 state=pending>
2025-10-31 15:41:08,103 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 4 < 10). will create a new session.
2025-10-31 15:41:08,103 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc60495370>
2025-10-31 15:41:08,103 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc60495370>
2025-10-31 15:41:08,103 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 2ce3861e-1cd9-4873-8498-dff317464790, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,104 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 2ce3861e-1cd9-4873-8498-dff317464790, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,106 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 2ce3861e-1cd9-4873-8498-dff317464790, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,106 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 2ce3861e-1cd9-4873-8498-dff317464790, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZWRiNWIwNTctMzZiZjY3MWUtN2QzYmZkNzEtMTkzNzA0ZmY=" } } } }
2025-10-31 15:41:08,107 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc60495370>
2025-10-31 15:41:08,107 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc60495370>
2025-10-31 15:41:08,107 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 2ce3861e-1cd9-4873-8498-dff317464790, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,107 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,108 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604969a0 state=pending>
2025-10-31 15:41:08,108 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 5 < 10). will create a new session.
2025-10-31 15:41:08,108 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604961d0>
2025-10-31 15:41:08,109 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604961d0>
2025-10-31 15:41:08,109 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, ea6504ff-1a3d-4559-82b8-a54cc9e5c6f3, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,109 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, ea6504ff-1a3d-4559-82b8-a54cc9e5c6f3, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,111 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, ea6504ff-1a3d-4559-82b8-a54cc9e5c6f3, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,112 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, ea6504ff-1a3d-4559-82b8-a54cc9e5c6f3, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=OWVlZWFhNTgtYzRjNzVlN2EtZDQ1OTdlMTUtNGZjZWJlNQ==" } } } }
2025-10-31 15:41:08,112 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604961d0>
2025-10-31 15:41:08,112 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604961d0>
2025-10-31 15:41:08,113 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, ea6504ff-1a3d-4559-82b8-a54cc9e5c6f3, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,113 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,114 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc60497ad0 state=pending>
2025-10-31 15:41:08,114 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 6 < 10). will create a new session.
2025-10-31 15:41:08,114 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc60497300>
2025-10-31 15:41:08,114 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc60497300>
2025-10-31 15:41:08,115 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 78a545c9-7af3-468e-be63-8822c1e9bc25, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,115 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 78a545c9-7af3-468e-be63-8822c1e9bc25, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,117 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 78a545c9-7af3-468e-be63-8822c1e9bc25, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,118 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 78a545c9-7af3-468e-be63-8822c1e9bc25, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=NTI5NThkMTEtOWY4MjdkMjgtNzFmNzJiNjgtNWQxODgxYzc=" } } } }
2025-10-31 15:41:08,118 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc60497300>
2025-10-31 15:41:08,118 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc60497300>
2025-10-31 15:41:08,118 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 78a545c9-7af3-468e-be63-8822c1e9bc25, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,119 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,119 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604950a0 state=pending>
2025-10-31 15:41:08,119 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 7 < 10). will create a new session.
2025-10-31 15:41:08,119 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604946f0>
2025-10-31 15:41:08,120 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604946f0>
2025-10-31 15:41:08,120 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 703d8f93-97a9-471e-b9b0-5d7694d194a9, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,120 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 703d8f93-97a9-471e-b9b0-5d7694d194a9, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,122 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 703d8f93-97a9-471e-b9b0-5d7694d194a9, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,123 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 703d8f93-97a9-471e-b9b0-5d7694d194a9, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=YWQ1MjMyMDgtNmNhNGM3ZWMtMTM3ZjEwZjUtYmEwOWE0MDU=" } } } }
2025-10-31 15:41:08,123 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604946f0>
2025-10-31 15:41:08,123 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604946f0>
2025-10-31 15:41:08,124 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 703d8f93-97a9-471e-b9b0-5d7694d194a9, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,124 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,124 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc60497990 state=pending>
2025-10-31 15:41:08,125 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 8 < 10). will create a new session.
2025-10-31 15:41:08,125 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604a2810>
2025-10-31 15:41:08,125 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604a2810>
2025-10-31 15:41:08,125 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 13ba51cf-2818-423a-9ebb-cd40b3d05bb2, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,126 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 13ba51cf-2818-423a-9ebb-cd40b3d05bb2, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,134 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 13ba51cf-2818-423a-9ebb-cd40b3d05bb2, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,136 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 13ba51cf-2818-423a-9ebb-cd40b3d05bb2, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=YjdhMGU4OWQtN2JjZDM2ZjgtNGEzZGViODMtODljNDgyNw==" } } } }
2025-10-31 15:41:08,136 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a2810>
2025-10-31 15:41:08,137 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604a2810>
2025-10-31 15:41:08,137 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 13ba51cf-2818-423a-9ebb-cd40b3d05bb2, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,137 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-10-31 15:41:08,140 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7efc604a0f60 state=pending>
2025-10-31 15:41:08,140 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 9 < 10). will create a new session.
2025-10-31 15:41:08,141 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7efc604a0740>
2025-10-31 15:41:08,142 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7efc604a0740>
2025-10-31 15:41:08,142 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, e922083d-03d3-4a40-8107-b14bf4455490, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,143 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, e922083d-03d3-4a40-8107-b14bf4455490, ghrun-xldpwfo7ey.auto.internal:10827): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,145 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, e922083d-03d3-4a40-8107-b14bf4455490, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,149 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, e922083d-03d3-4a40-8107-b14bf4455490, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=NmI1ZTAyZTYtMjlkMzgxOTAtZmU2ZDRhM2UtYWU4MDQxYTI=" } } } }
2025-10-31 15:41:08,163 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a0740>
2025-10-31 15:41:08,163 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7efc604a0740>
2025-10-31 15:41:08,168 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:18784
2025-10-31 15:41:08,172 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, e922083d-03d3-4a40-8107-b14bf4455490, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,181 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:18784 "GET /actors/kqp_proxy?force_shutdown=all HTTP/1.1" 200 416
2025-10-31 15:41:08,188 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, cf73a826-d452-4612-bb98-66b6bdcdd070, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,188 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, cf73a826-d452-4612-bb98-66b6bdcdd070, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZDI0NDU4MmEtZmUzYmE5ZTAtMmJhMGUzNTAtNzljY2U4Mzc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,204 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, cf73a826-d452-4612-bb98-66b6bdcdd070, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,211 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604adfa0>
2025-10-31 15:41:08,211 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604adfa0>, reason: session-close
2025-10-31 15:41:08,211 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604adfa0> is no longer active. Current active count 9.
2025-10-31 15:41:08,212 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 95668d62-38f0-4f86-80ec-8cf9b775b3d0, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,220 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 95668d62-38f0-4f86-80ec-8cf9b775b3d0, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZDI0NDU4MmEtZmUzYmE5ZTAtMmJhMGUzNTAtNzljY2U4Mzc=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,230 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 95668d62-38f0-4f86-80ec-8cf9b775b3d0, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,233 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 95668d62-38f0-4f86-80ec-8cf9b775b3d0, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,234 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 95668d62-38f0-4f86-80ec-8cf9b775b3d0, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,234 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604adfa0>
2025-10-31 15:41:08,235 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 57cc33b1-098a-48c7-afa3-efe643867b12, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,235 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 57cc33b1-098a-48c7-afa3-efe643867b12, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZWJiNmEwZjUtZTdhNmIxMTItOTFhYzhkMDMtZjZmMWU3MGY=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,250 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 57cc33b1-098a-48c7-afa3-efe643867b12, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,251 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604ae8b0>
2025-10-31 15:41:08,251 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604ae8b0>, reason: session-close
2025-10-31 15:41:08,251 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604ae8b0> is no longer active. Current active count 8.
2025-10-31 15:41:08,252 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 9c216729-5db3-46f9-932a-7f2ba860476a, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,252 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 9c216729-5db3-46f9-932a-7f2ba860476a, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZWJiNmEwZjUtZTdhNmIxMTItOTFhYzhkMDMtZjZmMWU3MGY=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,255 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 9c216729-5db3-46f9-932a-7f2ba860476a, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,261 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 9c216729-5db3-46f9-932a-7f2ba860476a, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,262 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 9c216729-5db3-46f9-932a-7f2ba860476a, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,263 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604ae8b0>
2025-10-31 15:41:08,263 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 3c631282-a335-4002-b1d2-8c82240552ca, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,265 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 3c631282-a335-4002-b1d2-8c82240552ca, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=N2I2OTk3Mi1iNzNkNjdkZi0zN2I2NTJhYy1mMzFiNDY5Yw==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,282 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 3c631282-a335-4002-b1d2-8c82240552ca, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,285 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a6db0>
2025-10-31 15:41:08,286 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604a6db0>, reason: session-close
2025-10-31 15:41:08,286 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604a6db0> is no longer active. Current active count 7.
2025-10-31 15:41:08,296 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, d39e5566-d1b2-4833-9d33-ea10d7cb0053, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,296 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, d39e5566-d1b2-4833-9d33-ea10d7cb0053, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=N2I2OTk3Mi1iNzNkNjdkZi0zN2I2NTJhYy1mMzFiNDY5Yw==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,299 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604a6db0>
2025-10-31 15:41:08,300 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 7cb06f38-b993-45e4-8e86-31c3f91c6e11, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,300 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 7cb06f38-b993-45e4-8e86-31c3f91c6e11, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZTE4MTdjZTItYzUwZGJiZjMtYWY2ZDE1ZjktZDI3ZDg5NjE=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,301 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, d39e5566-d1b2-4833-9d33-ea10d7cb0053, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,302 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, d39e5566-d1b2-4833-9d33-ea10d7cb0053, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,302 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, d39e5566-d1b2-4833-9d33-ea10d7cb0053, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,313 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 7cb06f38-b993-45e4-8e86-31c3f91c6e11, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,313 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a4e20>
2025-10-31 15:41:08,314 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604a4e20>, reason: session-close
2025-10-31 15:41:08,314 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604a4e20> is no longer active. Current active count 6.
2025-10-31 15:41:08,315 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 98302d19-aa06-4c0f-b011-e756f0836993, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,321 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 98302d19-aa06-4c0f-b011-e756f0836993, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZTE4MTdjZTItYzUwZGJiZjMtYWY2ZDE1ZjktZDI3ZDg5NjE=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,322 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604a4e20>
2025-10-31 15:41:08,323 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 98302d19-aa06-4c0f-b011-e756f0836993, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,323 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 12c276f9-d159-4115-a097-e27bdaad7bb5, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,324 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 98302d19-aa06-4c0f-b011-e756f0836993, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,325 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 12c276f9-d159-4115-a097-e27bdaad7bb5, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZWRiNWIwNTctMzZiZjY3MWUtN2QzYmZkNzEtMTkzNzA0ZmY=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,328 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 98302d19-aa06-4c0f-b011-e756f0836993, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,343 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 12c276f9-d159-4115-a097-e27bdaad7bb5, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,352 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc60495370>
2025-10-31 15:41:08,352 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc60495370>, reason: session-close
2025-10-31 15:41:08,352 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc60495370> is no longer active. Current active count 5.
2025-10-31 15:41:08,358 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, f71122d3-2e92-4475-9648-483dcd8f3b43, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,379 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, f71122d3-2e92-4475-9648-483dcd8f3b43, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=ZWRiNWIwNTctMzZiZjY3MWUtN2QzYmZkNzEtMTkzNzA0ZmY=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,382 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, f71122d3-2e92-4475-9648-483dcd8f3b43, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,403 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, f71122d3-2e92-4475-9648-483dcd8f3b43, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,403 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, f71122d3-2e92-4475-9648-483dcd8f3b43, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,404 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc60495370>
2025-10-31 15:41:08,404 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 6a38b9dc-d271-4e79-b0aa-7a0783cd6d0e, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,405 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 6a38b9dc-d271-4e79-b0aa-7a0783cd6d0e, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=OWVlZWFhNTgtYzRjNzVlN2EtZDQ1OTdlMTUtNGZjZWJlNQ==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,421 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 6a38b9dc-d271-4e79-b0aa-7a0783cd6d0e, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,434 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604961d0>
2025-10-31 15:41:08,434 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604961d0>, reason: session-close
2025-10-31 15:41:08,434 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604961d0> is no longer active. Current active count 4.
2025-10-31 15:41:08,434 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 222f2c2a-9e9b-4237-860f-33f224324121, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,435 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 222f2c2a-9e9b-4237-860f-33f224324121, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=OWVlZWFhNTgtYzRjNzVlN2EtZDQ1OTdlMTUtNGZjZWJlNQ==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,436 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604961d0>
2025-10-31 15:41:08,436 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 183f1029-1308-45d1-9b08-3f2e0b9dde62, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,437 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 183f1029-1308-45d1-9b08-3f2e0b9dde62, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=NTI5NThkMTEtOWY4MjdkMjgtNzFmNzJiNjgtNWQxODgxYzc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,440 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 222f2c2a-9e9b-4237-860f-33f224324121, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,444 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 222f2c2a-9e9b-4237-860f-33f224324121, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,444 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 222f2c2a-9e9b-4237-860f-33f224324121, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,453 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 183f1029-1308-45d1-9b08-3f2e0b9dde62, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,470 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc60497300>
2025-10-31 15:41:08,470 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc60497300>, reason: session-close
2025-10-31 15:41:08,470 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc60497300> is no longer active. Current active count 3.
2025-10-31 15:41:08,470 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, a616932b-f8f6-405a-965d-63ec0f842163, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,471 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, a616932b-f8f6-405a-965d-63ec0f842163, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=NTI5NThkMTEtOWY4MjdkMjgtNzFmNzJiNjgtNWQxODgxYzc=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,473 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc60497300>
2025-10-31 15:41:08,473 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 38493c24-17d4-41f4-ab14-4407708c1b64, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,474 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 38493c24-17d4-41f4-ab14-4407708c1b64, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=YWQ1MjMyMDgtNmNhNGM3ZWMtMTM3ZjEwZjUtYmEwOWE0MDU=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,475 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, a616932b-f8f6-405a-965d-63ec0f842163, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,475 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, a616932b-f8f6-405a-965d-63ec0f842163, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,475 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, a616932b-f8f6-405a-965d-63ec0f842163, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,486 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 38493c24-17d4-41f4-ab14-4407708c1b64, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,487 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604946f0>
2025-10-31 15:41:08,487 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604946f0>, reason: session-close
2025-10-31 15:41:08,487 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604946f0> is no longer active. Current active count 2.
2025-10-31 15:41:08,487 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, c87ff6d3-921c-45e8-b73b-96bf233d3b0d, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,488 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, c87ff6d3-921c-45e8-b73b-96bf233d3b0d, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=YWQ1MjMyMDgtNmNhNGM3ZWMtMTM3ZjEwZjUtYmEwOWE0MDU=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,489 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604946f0>
2025-10-31 15:41:08,489 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 1ed14d9e-cf16-49e5-bb43-5cb983a26c5c, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,490 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 1ed14d9e-cf16-49e5-bb43-5cb983a26c5c, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=YjdhMGU4OWQtN2JjZDM2ZjgtNGEzZGViODMtODljNDgyNw==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,492 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, c87ff6d3-921c-45e8-b73b-96bf233d3b0d, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,493 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, c87ff6d3-921c-45e8-b73b-96bf233d3b0d, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,493 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, c87ff6d3-921c-45e8-b73b-96bf233d3b0d, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,505 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 1ed14d9e-cf16-49e5-bb43-5cb983a26c5c, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,515 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a2810>
2025-10-31 15:41:08,515 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604a2810>, reason: session-close
2025-10-31 15:41:08,515 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604a2810> is no longer active. Current active count 1.
2025-10-31 15:41:08,516 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, 997960aa-5961-444b-8a76-4eb60820b049, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,516 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, 997960aa-5961-444b-8a76-4eb60820b049, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=YjdhMGU4OWQtN2JjZDM2ZjgtNGEzZGViODMtODljNDgyNw==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,528 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 997960aa-5961-444b-8a76-4eb60820b049, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,529 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, 997960aa-5961-444b-8a76-4eb60820b049, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,550 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, 997960aa-5961-444b-8a76-4eb60820b049, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,551 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604a2810>
2025-10-31 15:41:08,551 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, ea8798fb-983f-49e7-9a0a-13ed61480df9, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,552 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, ea8798fb-983f-49e7-9a0a-13ed61480df9, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=NmI1ZTAyZTYtMjlkMzgxOTAtZmU2ZDRhM2UtYWU4MDQxYTI=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "select 1;" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-10-31 15:41:08,564 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, ea8798fb-983f-49e7-9a0a-13ed61480df9, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { result_sets { columns { name: "column0" type { type_id: INT32 } } rows { items { int32_value: 1 } } format: FORMAT_VALUE } tx_meta { } } } } }
2025-10-31 15:41:08,565 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7efc604a0740>
2025-10-31 15:41:08,576 - DEBUG - ydb.table.SessionPool - _destroy: Requested session destroy: <ydb.table.Session object at 0x7efc604a0740>, reason: session-close
2025-10-31 15:41:08,576 - DEBUG - ydb.table.SessionPool - _destroy: Session <ydb.table.Session object at 0x7efc604a0740> is no longer active. Current active count 0.
2025-10-31 15:41:08,577 - DEBUG - ydb.connection - _prepare_call: RpcState(DeleteSession, df37a5b3-1b05-47bd-95b0-d297019e0b12, ghrun-xldpwfo7ey.auto.internal:10827): creating call state
2025-10-31 15:41:08,577 - DEBUG - ydb.connection - _log_request: RpcState(DeleteSession, df37a5b3-1b05-47bd-95b0-d297019e0b12, ghrun-xldpwfo7ey.auto.internal:10827): request = { session_id: "ydb://session/3?node_id=1&id=NmI1ZTAyZTYtMjlkMzgxOTAtZmU2ZDRhM2UtYWU4MDQxYTI=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-10-31 15:41:08,586 - DEBUG - ydb.table.SessionPool - _destroy: Sent delete on session <ydb.table.Session object at 0x7efc604a0740>
2025-10-31 15:41:08,587 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, df37a5b3-1b05-47bd-95b0-d297019e0b12, ghrun-xldpwfo7ey.auto.internal:10827): on response callback started
2025-10-31 15:41:08,589 - DEBUG - ydb.connection - _log_response: RpcState(DeleteSession, df37a5b3-1b05-47bd-95b0-d297019e0b12, ghrun-xldpwfo7ey.auto.internal:10827): response = { operation { ready: true status: SUCCESS } }
2025-10-31 15:41:08,597 - INFO - ya.test - pytest_runtest_teardown: Test teardown
2025-10-31 15:41:08,597 - DEBUG - ydb.connection - _on_response_callback: RpcState(DeleteSession, df37a5b3-1b05-47bd-95b0-d297019e0b12, ghrun-xldpwfo7ey.auto.internal:10827): on response callback success
2025-10-31 15:41:08,598 - DEBUG - ydb.topic - close: Close topic client
2025-10-31 15:41:08,599 - DEBUG - ydb.topic - close: Topic client was closed
2025-10-31 15:41:08,599 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:10827
2025-10-31 15:41:08,599 - DEBUG - ydb.connection - close: Closing channel for endpoint ghrun-xldpwfo7ey.auto.internal:10827
2025-10-31 15:41:08,600 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-10-31 15:41:15,605 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:10827/1
2025-10-31 15:41:15,606 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/23158
2025-10-31 15:41:15,614 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/7639
2025-10-31 15:41:15,614 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/18784
2025-10-31 15:41:15,615 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/10827
2025-10-31 15:41:15,615 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/64888
