2026-08-19 13:41:19,729 - INFO - ya.test.1603316  - pytest_runtest_setup: ####################################################################################################
2026-08-19 13:41:19,729 - INFO - ya.test.1603316  - pytest_runtest_setup: test_grace_shutdown_of_session
2026-08-19 13:41:19,729 - INFO - ya.test.1603316  - pytest_runtest_setup: ####################################################################################################
2026-08-19 13:41:19,730 - INFO - ya.test.1603316  - pytest_runtest_setup: Test setup
2026-08-19 13:41:19,780 - DEBUG - ya.test.1603316  - get_binary: Binary was found by /home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd
2026-08-19 13:41:19,780 - DEBUG - library.python.filelock.1603316  - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/9223
2026-08-19 13:41:19,781 - DEBUG - ydb.tests.library.harness.kikimr_runner.1603316  - start: Working directory: /home/runner/.ya/build/build_root/rgvb/0029d2/r3tmp/kikimr_cluster_vf53_xy8
2026-08-19 13:41:19,806 - DEBUG - ya.test.1603316  - get_binary: Binary was found by /home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd
2026-08-19 13:41:19,806 - DEBUG - library.python.filelock.1603316  - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/16290
2026-08-19 13:41:19,807 - DEBUG - library.python.filelock.1603316  - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/32434
2026-08-19 13:41:19,807 - DEBUG - library.python.filelock.1603316  - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/14495
2026-08-19 13:41:19,807 - DEBUG - library.python.filelock.1603316  - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/7038
2026-08-19 13:41:19,808 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rgvb/0029d2/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"
2026-08-19 13:41:19,808 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - __make_run_command: Final command: /home/runner/.ya/build/build_root/rgvb/0029d2/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/rgvb/0029d2/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_9t94u2kl.log --grpc-port=16290 --mon-port=32434 --ic-port=9223
2026-08-19 13:41:19,808 - DEBUG - ydb.tests.library.harness.kikimr_runner.1603316  - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:16290/1, disk_size 68719476736
2026-08-19 13:41:19,808 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rgvb/0029d2/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"
2026-08-19 13:41:19,808 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - __make_run_command: Final command: /home/runner/.ya/build/build_root/rgvb/0029d2/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/rgvb/0029d2/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_9t94u2kl.log --grpc-port=16290 --mon-port=32434 --ic-port=9223
2026-08-19 13:41:19,809 - DEBUG - ya.test.1603316  - execute: Executing '('/home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rgvb/0029d2/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/rgvb/0029d2/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_9t94u2kl.log', '--grpc-port=16290', '--mon-port=32434', '--ic-port=9223')' in '/home/runner/.ya/build/build_root/rgvb/0029d2/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)
2026-08-19 13:41:19,810 - DEBUG - ya.test.1603316  - execute: Command pid: 1603696
2026-08-19 13:41:19,811 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - start: Started node localhost:16290/1
2026-08-19 13:41:19,812 - DEBUG - ya.test.1603316  - _get_command_output_file: Command out will be placed to ydbd.out
2026-08-19 13:41:19,812 - DEBUG - ya.test.1603316  - _get_command_output_file: Command err will be placed to ydbd.err
2026-08-19 13:41:19,812 - DEBUG - ya.test.1603316  - execute: Executing '['/home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2026-08-19 13:41:19,813 - DEBUG - ya.test.1603316  - execute: Command pid: 1603698
2026-08-19 13:41:20,117 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) rc: 0
2026-08-19 13:41:20,117 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) elapsed time (sec): 0.30391740798950195
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) idrss: 0
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) inblock: 0
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) isrss: 0
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) ixrss: 0
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) majflt: 0
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) maxrss: 595576
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) minflt: 17084
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) msgrcv: 0
2026-08-19 13:41:20,118 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) msgsnd: 0
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) nivcsw: 11
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) nsignals: 0
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) nswap: 0
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) nvcsw: 12
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) oublock: 8
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) stime: 0.163551
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) utime: 0.091748
2026-08-19 13:41:20,119 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) wtime: 0.305
2026-08-19 13:41:20,120 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) output:
Git info:
    Commit: 5fae958573e70d7e2b130b8590a4588387646044
    Branch: 
    Author: YDBot <ydbot@ydb.tech>
    Summary: Merge ecea273b4881a7a0260df1085258a5f62ba18467 into bc81a6c438b7b6224aa7f9fd5a8af371c7b4ca7e
Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-4q22hfe2g4    Host information: 
        Linux ghrun-4q22hfe2g4 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/10492077879/bin/clang++
    Compiler version: 
        clang version 20.1.8
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/10492077879/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++

2026-08-19 13:41:20,120 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1603698) errors:

2026-08-19 13:41:20,120 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - start: Node 1 version:
Git info:
    Commit: 5fae958573e70d7e2b130b8590a4588387646044
    Branch: 
    Author: YDBot <ydbot@ydb.tech>
    Summary: Merge ecea273b4881a7a0260df1085258a5f62ba18467 into bc81a6c438b7b6224aa7f9fd5a8af371c7b4ca7e
Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-4q22hfe2g4    Host information: 
        Linux ghrun-4q22hfe2g4 5.15.0-157-generic #167-Ubuntu SMP Wed Sep 17 21:35:53 UTC 2025 x86_64
2026-08-19 13:41:21,943 - DEBUG - ya.test.1603316  - get_binary: Binary was found by /home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd
2026-08-19 13:41:21,943 - DEBUG - ydb.tests.library.harness.kikimr_runner.1603316  - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:16290', '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: 9223\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2026-08-19 13:41:21,944 - DEBUG - ya.test.1603316  - _get_command_output_file: Command out will be placed to ydbd.out.0
2026-08-19 13:41:21,944 - DEBUG - ya.test.1603316  - _get_command_output_file: Command err will be placed to ydbd.err.0
2026-08-19 13:41:21,944 - DEBUG - ya.test.1603316  - execute: Executing '['/home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:16290', '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: 9223\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2026-08-19 13:41:21,945 - DEBUG - ya.test.1603316  - execute: Command pid: 1604352
2026-08-19 13:41:22,263 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) rc: 0
2026-08-19 13:41:22,263 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) elapsed time (sec): 0.31728243827819824
2026-08-19 13:41:22,263 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) idrss: 0
2026-08-19 13:41:22,264 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) inblock: 0
2026-08-19 13:41:22,264 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) isrss: 0
2026-08-19 13:41:22,264 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) ixrss: 0
2026-08-19 13:41:22,266 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) majflt: 0
2026-08-19 13:41:22,266 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) maxrss: 604020
2026-08-19 13:41:22,267 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) minflt: 19227
2026-08-19 13:41:22,267 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) msgrcv: 0
2026-08-19 13:41:22,267 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) msgsnd: 0
2026-08-19 13:41:22,267 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) nivcsw: 0
2026-08-19 13:41:22,268 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) nsignals: 0
2026-08-19 13:41:22,268 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) nswap: 0
2026-08-19 13:41:22,268 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) nvcsw: 136
2026-08-19 13:41:22,268 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) oublock: 8
2026-08-19 13:41:22,268 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) stime: 0.175568
2026-08-19 13:41:22,269 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) utime: 0.097991
2026-08-19 13:41:22,269 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) wtime: 0.318
2026-08-19 13:41:22,269 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2026-08-19 13:41:22,269 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604352) errors:

2026-08-19 13:41:22,270 - DEBUG - ya.test.1603316  - get_binary: Binary was found by /home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd
2026-08-19 13:41:22,270 - DEBUG - ydb.tests.library.harness.kikimr_runner.1603316  - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:16290', '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']
2026-08-19 13:41:22,271 - DEBUG - ya.test.1603316  - _get_command_output_file: Command out will be placed to ydbd.out.1
2026-08-19 13:41:22,272 - DEBUG - ya.test.1603316  - _get_command_output_file: Command err will be placed to ydbd.err.1
2026-08-19 13:41:22,272 - DEBUG - ya.test.1603316  - execute: Executing '['/home/runner/.ya/build/build_root/rgvb/0029d2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:16290', '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)
2026-08-19 13:41:22,273 - DEBUG - ya.test.1603316  - execute: Command pid: 1604408
2026-08-19 13:41:22,549 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) rc: 0
2026-08-19 13:41:22,549 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) elapsed time (sec): 0.275745153427124
2026-08-19 13:41:22,549 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) idrss: 0
2026-08-19 13:41:22,550 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) inblock: 0
2026-08-19 13:41:22,550 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) isrss: 0
2026-08-19 13:41:22,550 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) ixrss: 0
2026-08-19 13:41:22,550 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) majflt: 0
2026-08-19 13:41:22,550 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) maxrss: 604012
2026-08-19 13:41:22,550 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) minflt: 19226
2026-08-19 13:41:22,550 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) msgrcv: 0
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) msgsnd: 0
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) nivcsw: 1
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) nsignals: 0
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) nswap: 0
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) nvcsw: 140
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) oublock: 8
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) stime: 0.156045
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) utime: 0.072313
2026-08-19 13:41:22,551 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) wtime: 0.277
2026-08-19 13:41:22,552 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2026-08-19 13:41:22,552 - DEBUG - ya.test.1603316  - _save_outputs: Command (pid 1604408) errors:

2026-08-19 13:41:22,552 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2026-08-19 13:41:22,571 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - __run: Cluster started and initialized
2026-08-19 13:41:22,581 - DEBUG - ydb.connection.1603316  - 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', 10000), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2026-08-19 13:41:22,583 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver.1603316  - context_resolve: Preparing initial endpoint to resolve endpoints
2026-08-19 13:41:22,583 - DEBUG - ydb.connection.1603316  - 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', 10000), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2026-08-19 13:41:22,589 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver.1603316  - context_resolve: Resolving endpoints for database /Root
2026-08-19 13:41:22,590 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ListEndpoints, 4b5371c6-cb94-4bcc-9cab-057d0b1153d0, localhost:16290): creating call state
2026-08-19 13:41:22,590 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ListEndpoints, 4b5371c6-cb94-4bcc-9cab-057d0b1153d0, localhost:16290): request = { database: "/Root" }
2026-08-19 13:41:22,593 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ListEndpoints, 4b5371c6-cb94-4bcc-9cab-057d0b1153d0, localhost:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-4q22hfe2g4.auto.internal" port: 16290 service: "nbs" 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" } } } }
2026-08-19 13:41:22,593 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver.1603316  - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-4q22hfe2g4.auto.internal:16290, location 1, ssl: False>]>
2026-08-19 13:41:22,594 - DEBUG - ydb.connection.1603316  - 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', 10000), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2026-08-19 13:41:22,601 - INFO - ya.test.1603316  - pytest_runtest_call: Test call (class_name: test_session_grace_shutdown.py::Test, test_name: test_grace_shutdown_of_session)
2026-08-19 13:41:22,601 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,601 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af60d2420 state=pending>
2026-08-19 13:41:22,602 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 0 < 10). will create a new session.
2026-08-19 13:41:22,602 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af60d2580>
2026-08-19 13:41:22,602 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af60d2580>
2026-08-19 13:41:22,603 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, b571d805-62db-40cb-bbe4-dd3bed03856f, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,604 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, b571d805-62db-40cb-bbe4-dd3bed03856f, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,606 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, b571d805-62db-40cb-bbe4-dd3bed03856f, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,606 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, b571d805-62db-40cb-bbe4-dd3bed03856f, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=YmU2Y2VlZjQtZTcxZjZiOTgtOTQzMzcwNzUtYmQyMDkyZGQ=" } } } }
2026-08-19 13:41:22,606 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af60d2580>
2026-08-19 13:41:22,607 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af60d2580>
2026-08-19 13:41:22,607 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, b571d805-62db-40cb-bbe4-dd3bed03856f, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,607 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,607 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af88a6e50 state=pending>
2026-08-19 13:41:22,607 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 1 < 10). will create a new session.
2026-08-19 13:41:22,608 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af60d22c0>
2026-08-19 13:41:22,608 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af60d22c0>
2026-08-19 13:41:22,608 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, 0e8b3793-999b-48ba-bd02-47dfb411112f, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,608 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, 0e8b3793-999b-48ba-bd02-47dfb411112f, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,610 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 0e8b3793-999b-48ba-bd02-47dfb411112f, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,611 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, 0e8b3793-999b-48ba-bd02-47dfb411112f, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ODBjMDcyYmYtNjkzZDQ4NmYtYmJjNjcwZTEtOTk0OTNmYTI=" } } } }
2026-08-19 13:41:22,611 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af60d22c0>
2026-08-19 13:41:22,611 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af60d22c0>
2026-08-19 13:41:22,612 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 0e8b3793-999b-48ba-bd02-47dfb411112f, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,612 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,612 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af8987260 state=pending>
2026-08-19 13:41:22,613 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 2 < 10). will create a new session.
2026-08-19 13:41:22,613 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af88a6d00>
2026-08-19 13:41:22,613 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af88a6d00>
2026-08-19 13:41:22,613 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, 7e105f0c-e6e0-427d-a01b-8212d5937f1b, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,613 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, 7e105f0c-e6e0-427d-a01b-8212d5937f1b, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,615 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 7e105f0c-e6e0-427d-a01b-8212d5937f1b, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,615 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, 7e105f0c-e6e0-427d-a01b-8212d5937f1b, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=MWYyYmMwZTAtMzdhMGI5MTEtNmI2ZDU2ODUtMmM4MWVhNg==" } } } }
2026-08-19 13:41:22,616 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88a6d00>
2026-08-19 13:41:22,616 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af88a6d00>
2026-08-19 13:41:22,617 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 7e105f0c-e6e0-427d-a01b-8212d5937f1b, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,617 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,617 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af88ad920 state=pending>
2026-08-19 13:41:22,617 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 3 < 10). will create a new session.
2026-08-19 13:41:22,618 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af88a7240>
2026-08-19 13:41:22,618 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af88a7240>
2026-08-19 13:41:22,618 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, 5a060fb5-2033-4da7-a55a-64976dbd9a49, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,618 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, 5a060fb5-2033-4da7-a55a-64976dbd9a49, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,619 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 5a060fb5-2033-4da7-a55a-64976dbd9a49, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,620 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, 5a060fb5-2033-4da7-a55a-64976dbd9a49, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=NDg3MmI3MzUtNmRlODZhM2UtMjgyMDAzMTMtOTE3YTNhYTQ=" } } } }
2026-08-19 13:41:22,620 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88a7240>
2026-08-19 13:41:22,620 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af88a7240>
2026-08-19 13:41:22,621 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 5a060fb5-2033-4da7-a55a-64976dbd9a49, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,621 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,621 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af61a8170 state=pending>
2026-08-19 13:41:22,621 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 4 < 10). will create a new session.
2026-08-19 13:41:22,621 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af89874e0>
2026-08-19 13:41:22,621 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af89874e0>
2026-08-19 13:41:22,622 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, 13d7ca8c-ed16-4152-a516-b0fd8b89490e, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,622 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, 13d7ca8c-ed16-4152-a516-b0fd8b89490e, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,623 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 13d7ca8c-ed16-4152-a516-b0fd8b89490e, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,624 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, 13d7ca8c-ed16-4152-a516-b0fd8b89490e, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=MzI2OTU3ZjctMmQ0ZThjZDgtYWQ4MzBmYzMtYjJhZmI3ZTk=" } } } }
2026-08-19 13:41:22,624 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af89874e0>
2026-08-19 13:41:22,624 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af89874e0>
2026-08-19 13:41:22,624 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 13d7ca8c-ed16-4152-a516-b0fd8b89490e, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,625 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,625 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af6188760 state=pending>
2026-08-19 13:41:22,625 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 5 < 10). will create a new session.
2026-08-19 13:41:22,626 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af89879e0>
2026-08-19 13:41:22,626 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af89879e0>
2026-08-19 13:41:22,626 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, 4e4dd686-d231-4324-84b7-ef165959ebac, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,626 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, 4e4dd686-d231-4324-84b7-ef165959ebac, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,627 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 4e4dd686-d231-4324-84b7-ef165959ebac, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,628 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, 4e4dd686-d231-4324-84b7-ef165959ebac, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=OTk3YWE3MjYtNjRmNTNmN2YtMTVlMjA2MDQtZjJhYTNlOWE=" } } } }
2026-08-19 13:41:22,628 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af89879e0>
2026-08-19 13:41:22,628 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af89879e0>
2026-08-19 13:41:22,629 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, 4e4dd686-d231-4324-84b7-ef165959ebac, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,629 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,629 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af60f6d60 state=pending>
2026-08-19 13:41:22,629 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 6 < 10). will create a new session.
2026-08-19 13:41:22,630 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af6190650>
2026-08-19 13:41:22,630 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af6190650>
2026-08-19 13:41:22,630 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, edca43a3-c718-4c8b-bbc1-ed54f37c3609, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,630 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, edca43a3-c718-4c8b-bbc1-ed54f37c3609, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,631 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, edca43a3-c718-4c8b-bbc1-ed54f37c3609, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,632 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, edca43a3-c718-4c8b-bbc1-ed54f37c3609, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=NjUzY2IwNjktNzg1ZjlkZTUtZjg3MjZlMzYtMTY2YWY3ODM=" } } } }
2026-08-19 13:41:22,632 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af6190650>
2026-08-19 13:41:22,632 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af6190650>
2026-08-19 13:41:22,632 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, edca43a3-c718-4c8b-bbc1-ed54f37c3609, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,633 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,633 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af9c9ade0 state=pending>
2026-08-19 13:41:22,633 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 7 < 10). will create a new session.
2026-08-19 13:41:22,633 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af88ae340>
2026-08-19 13:41:22,633 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af88ae340>
2026-08-19 13:41:22,633 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, eab66e52-15b4-4cf4-b8d6-b2a736b95021, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,634 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, eab66e52-15b4-4cf4-b8d6-b2a736b95021, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,639 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, eab66e52-15b4-4cf4-b8d6-b2a736b95021, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,639 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, eab66e52-15b4-4cf4-b8d6-b2a736b95021, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZTJlNjdhNTMtNDg0ODA3Y2EtMjdhNTEzMzYtNzk0NzBlZGI=" } } } }
2026-08-19 13:41:22,640 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88ae340>
2026-08-19 13:41:22,640 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af88ae340>
2026-08-19 13:41:22,640 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, eab66e52-15b4-4cf4-b8d6-b2a736b95021, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,640 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,641 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af9c23ef0 state=pending>
2026-08-19 13:41:22,641 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 8 < 10). will create a new session.
2026-08-19 13:41:22,641 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af88ae460>
2026-08-19 13:41:22,641 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af88ae460>
2026-08-19 13:41:22,641 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, c257688e-fcca-412d-b0b9-fb9dfdf61f2a, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,641 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, c257688e-fcca-412d-b0b9-fb9dfdf61f2a, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,643 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, c257688e-fcca-412d-b0b9-fb9dfdf61f2a, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,643 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, c257688e-fcca-412d-b0b9-fb9dfdf61f2a, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZmNkMDE0Y2YtNTBkNDA3My04ZGVhNWE0MC0yMWMxMDY5MA==" } } } }
2026-08-19 13:41:22,643 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88ae460>
2026-08-19 13:41:22,643 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af88ae460>
2026-08-19 13:41:22,644 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, c257688e-fcca-412d-b0b9-fb9dfdf61f2a, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,644 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Active session queue is empty, subscribe waiter for a session
2026-08-19 13:41:22,644 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Subscribe waiter <Future at 0x7f6af60eee20 state=pending>
2026-08-19 13:41:22,644 - DEBUG - ydb.table.SessionPool.1603316  - subscribe: Session pool is not large enough (active_count < size: 9 < 10). will create a new session.
2026-08-19 13:41:22,644 - DEBUG - ydb.table.SessionPool.1603316  - _create: Created session <ydb.table.Session object at 0x7f6af61a8b00>
2026-08-19 13:41:22,645 - DEBUG - ydb.table.SessionPool.1603316  - _prepare: Preparing session <ydb.table.Session object at 0x7f6af61a8b00>
2026-08-19 13:41:22,645 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(CreateSession, adc2bb72-4901-46c9-ab42-c7ef5965e824, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,645 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(CreateSession, adc2bb72-4901-46c9-ab42-c7ef5965e824, ghrun-4q22hfe2g4.auto.internal:16290): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,646 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, adc2bb72-4901-46c9-ab42-c7ef5965e824, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,647 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(CreateSession, adc2bb72-4901-46c9-ab42-c7ef5965e824, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=OTk2NWQwZjQtMThiMGQ0OWUtZmVlNDUyYTEtODMwMjQ5MGY=" } } } }
2026-08-19 13:41:22,648 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af61a8b00>
2026-08-19 13:41:22,648 - DEBUG - ydb.table.SessionPool.1603316  - put: Replying to waiter with a session <ydb.table.Session object at 0x7f6af61a8b00>
2026-08-19 13:41:22,651 - DEBUG - urllib3.connectionpool.1603316  - _new_conn: Starting new HTTP connection (1): localhost:32434
2026-08-19 13:41:22,651 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(CreateSession, adc2bb72-4901-46c9-ab42-c7ef5965e824, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,653 - DEBUG - urllib3.connectionpool.1603316  - _make_request: http://localhost:32434 "GET /actors/kqp_proxy?force_shutdown=all HTTP/1.1" 200 416
2026-08-19 13:41:22,655 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, 36475a01-ae8e-4fd1-95dd-8df5920a3580, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,656 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, 36475a01-ae8e-4fd1-95dd-8df5920a3580, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=YmU2Y2VlZjQtZTcxZjZiOTgtOTQzMzcwNzUtYmQyMDkyZGQ=" 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 } } }
2026-08-19 13:41:22,692 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, 36475a01-ae8e-4fd1-95dd-8df5920a3580, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,693 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af60d2580>
2026-08-19 13:41:22,694 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af60d2580>, reason: session-close
2026-08-19 13:41:22,694 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af60d2580> is no longer active. Current active count 9.
2026-08-19 13:41:22,695 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, 06f8dfb8-b680-4aa7-b425-9a98fac103e0, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,695 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, 06f8dfb8-b680-4aa7-b425-9a98fac103e0, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=YmU2Y2VlZjQtZTcxZjZiOTgtOTQzMzcwNzUtYmQyMDkyZGQ=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,696 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af60d2580>
2026-08-19 13:41:22,696 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, 6f1ea376-aee3-4669-ae28-1366d1bafef5, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,697 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 06f8dfb8-b680-4aa7-b425-9a98fac103e0, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,698 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, 6f1ea376-aee3-4669-ae28-1366d1bafef5, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=ODBjMDcyYmYtNjkzZDQ4NmYtYmJjNjcwZTEtOTk0OTNmYTI=" 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 } } }
2026-08-19 13:41:22,698 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, 06f8dfb8-b680-4aa7-b425-9a98fac103e0, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,699 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 06f8dfb8-b680-4aa7-b425-9a98fac103e0, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,707 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, 6f1ea376-aee3-4669-ae28-1366d1bafef5, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,707 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af60d22c0>
2026-08-19 13:41:22,708 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af60d22c0>, reason: session-close
2026-08-19 13:41:22,708 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af60d22c0> is no longer active. Current active count 8.
2026-08-19 13:41:22,708 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, 9b326192-e376-4482-b74a-97d866abd812, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,708 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, 9b326192-e376-4482-b74a-97d866abd812, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=ODBjMDcyYmYtNjkzZDQ4NmYtYmJjNjcwZTEtOTk0OTNmYTI=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,709 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af60d22c0>
2026-08-19 13:41:22,709 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 9b326192-e376-4482-b74a-97d866abd812, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,710 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, 21092019-96d4-4de7-bb9c-e611a3bcb49e, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,710 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, 9b326192-e376-4482-b74a-97d866abd812, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,711 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, 21092019-96d4-4de7-bb9c-e611a3bcb49e, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=MWYyYmMwZTAtMzdhMGI5MTEtNmI2ZDU2ODUtMmM4MWVhNg==" 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 } } }
2026-08-19 13:41:22,711 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 9b326192-e376-4482-b74a-97d866abd812, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,718 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, 21092019-96d4-4de7-bb9c-e611a3bcb49e, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,719 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88a6d00>
2026-08-19 13:41:22,719 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af88a6d00>, reason: session-close
2026-08-19 13:41:22,719 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af88a6d00> is no longer active. Current active count 7.
2026-08-19 13:41:22,719 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, 146cd5e7-0039-44ca-b24c-b28c2fda38e9, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,720 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, 146cd5e7-0039-44ca-b24c-b28c2fda38e9, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=MWYyYmMwZTAtMzdhMGI5MTEtNmI2ZDU2ODUtMmM4MWVhNg==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,720 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af88a6d00>
2026-08-19 13:41:22,721 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, ee3433fe-64e8-4c70-9504-5085ca6c14e7, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,721 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, ee3433fe-64e8-4c70-9504-5085ca6c14e7, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=NDg3MmI3MzUtNmRlODZhM2UtMjgyMDAzMTMtOTE3YTNhYTQ=" 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 } } }
2026-08-19 13:41:22,721 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 146cd5e7-0039-44ca-b24c-b28c2fda38e9, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,722 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, 146cd5e7-0039-44ca-b24c-b28c2fda38e9, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,722 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 146cd5e7-0039-44ca-b24c-b28c2fda38e9, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,728 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, ee3433fe-64e8-4c70-9504-5085ca6c14e7, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,728 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88a7240>
2026-08-19 13:41:22,729 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af88a7240>, reason: session-close
2026-08-19 13:41:22,729 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af88a7240> is no longer active. Current active count 6.
2026-08-19 13:41:22,729 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, ca088afb-6775-4179-91f7-7f9688257634, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,729 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, ca088afb-6775-4179-91f7-7f9688257634, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=NDg3MmI3MzUtNmRlODZhM2UtMjgyMDAzMTMtOTE3YTNhYTQ=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,730 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af88a7240>
2026-08-19 13:41:22,730 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, ca088afb-6775-4179-91f7-7f9688257634, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,731 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, f0e23baf-7627-406d-8e41-5c77a42d12d0, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,731 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, ca088afb-6775-4179-91f7-7f9688257634, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,732 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, f0e23baf-7627-406d-8e41-5c77a42d12d0, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=MzI2OTU3ZjctMmQ0ZThjZDgtYWQ4MzBmYzMtYjJhZmI3ZTk=" 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 } } }
2026-08-19 13:41:22,732 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, ca088afb-6775-4179-91f7-7f9688257634, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,739 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, f0e23baf-7627-406d-8e41-5c77a42d12d0, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,740 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af89874e0>
2026-08-19 13:41:22,740 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af89874e0>, reason: session-close
2026-08-19 13:41:22,740 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af89874e0> is no longer active. Current active count 5.
2026-08-19 13:41:22,740 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, ae4f797c-c36c-4a46-9132-7513296a8e52, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,741 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, ae4f797c-c36c-4a46-9132-7513296a8e52, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=MzI2OTU3ZjctMmQ0ZThjZDgtYWQ4MzBmYzMtYjJhZmI3ZTk=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,742 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af89874e0>
2026-08-19 13:41:22,742 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, ae4f797c-c36c-4a46-9132-7513296a8e52, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,743 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, b2c8ac57-ac57-4f37-9067-1c7b1e7aad88, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,743 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, ae4f797c-c36c-4a46-9132-7513296a8e52, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,743 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, b2c8ac57-ac57-4f37-9067-1c7b1e7aad88, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=OTk3YWE3MjYtNjRmNTNmN2YtMTVlMjA2MDQtZjJhYTNlOWE=" 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 } } }
2026-08-19 13:41:22,744 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, ae4f797c-c36c-4a46-9132-7513296a8e52, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,750 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, b2c8ac57-ac57-4f37-9067-1c7b1e7aad88, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,750 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af89879e0>
2026-08-19 13:41:22,751 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af89879e0>, reason: session-close
2026-08-19 13:41:22,751 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af89879e0> is no longer active. Current active count 4.
2026-08-19 13:41:22,751 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, 79534507-01ad-4ce1-910a-4fdc98040791, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,751 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, 79534507-01ad-4ce1-910a-4fdc98040791, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=OTk3YWE3MjYtNjRmNTNmN2YtMTVlMjA2MDQtZjJhYTNlOWE=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,752 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af89879e0>
2026-08-19 13:41:22,752 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 79534507-01ad-4ce1-910a-4fdc98040791, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,753 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, 59df7c65-fb9f-4780-9754-803cefb26ec1, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,753 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, 79534507-01ad-4ce1-910a-4fdc98040791, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,754 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, 59df7c65-fb9f-4780-9754-803cefb26ec1, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=NjUzY2IwNjktNzg1ZjlkZTUtZjg3MjZlMzYtMTY2YWY3ODM=" 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 } } }
2026-08-19 13:41:22,754 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 79534507-01ad-4ce1-910a-4fdc98040791, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,761 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, 59df7c65-fb9f-4780-9754-803cefb26ec1, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,761 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af6190650>
2026-08-19 13:41:22,761 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af6190650>, reason: session-close
2026-08-19 13:41:22,761 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af6190650> is no longer active. Current active count 3.
2026-08-19 13:41:22,762 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, 673d4cc8-ad35-41f1-8046-4a3282d09d38, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,762 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, 673d4cc8-ad35-41f1-8046-4a3282d09d38, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=NjUzY2IwNjktNzg1ZjlkZTUtZjg3MjZlMzYtMTY2YWY3ODM=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,763 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af6190650>
2026-08-19 13:41:22,763 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 673d4cc8-ad35-41f1-8046-4a3282d09d38, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,764 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, ffe5f595-f23f-49e5-828e-34d5c42a830a, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,764 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, 673d4cc8-ad35-41f1-8046-4a3282d09d38, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,765 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, ffe5f595-f23f-49e5-828e-34d5c42a830a, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=ZTJlNjdhNTMtNDg0ODA3Y2EtMjdhNTEzMzYtNzk0NzBlZGI=" 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 } } }
2026-08-19 13:41:22,765 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 673d4cc8-ad35-41f1-8046-4a3282d09d38, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,772 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, ffe5f595-f23f-49e5-828e-34d5c42a830a, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,773 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88ae340>
2026-08-19 13:41:22,773 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af88ae340>, reason: session-close
2026-08-19 13:41:22,773 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af88ae340> is no longer active. Current active count 2.
2026-08-19 13:41:22,773 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, 8d6535bf-98f7-4eb4-9602-2021f63f213e, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,774 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, 8d6535bf-98f7-4eb4-9602-2021f63f213e, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=ZTJlNjdhNTMtNDg0ODA3Y2EtMjdhNTEzMzYtNzk0NzBlZGI=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,774 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af88ae340>
2026-08-19 13:41:22,775 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, 545870f3-13c5-48a3-8d34-27aa1823ab63, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,775 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 8d6535bf-98f7-4eb4-9602-2021f63f213e, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,776 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, 545870f3-13c5-48a3-8d34-27aa1823ab63, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=ZmNkMDE0Y2YtNTBkNDA3My04ZGVhNWE0MC0yMWMxMDY5MA==" 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 } } }
2026-08-19 13:41:22,776 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, 8d6535bf-98f7-4eb4-9602-2021f63f213e, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,777 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 8d6535bf-98f7-4eb4-9602-2021f63f213e, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,784 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, 545870f3-13c5-48a3-8d34-27aa1823ab63, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,784 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af88ae460>
2026-08-19 13:41:22,784 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af88ae460>, reason: session-close
2026-08-19 13:41:22,785 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af88ae460> is no longer active. Current active count 1.
2026-08-19 13:41:22,785 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, 58450f5f-1f2b-4007-a89f-d92f6690e027, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,785 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, 58450f5f-1f2b-4007-a89f-d92f6690e027, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=ZmNkMDE0Y2YtNTBkNDA3My04ZGVhNWE0MC0yMWMxMDY5MA==" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,786 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af88ae460>
2026-08-19 13:41:22,786 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 58450f5f-1f2b-4007-a89f-d92f6690e027, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,787 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(ExecuteDataQuery, 52cb8924-e6e6-46f7-a6e0-349e3105cd67, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,787 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, 58450f5f-1f2b-4007-a89f-d92f6690e027, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,788 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(ExecuteDataQuery, 52cb8924-e6e6-46f7-a6e0-349e3105cd67, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=OTk2NWQwZjQtMThiMGQ0OWUtZmVlNDUyYTEtODMwMjQ5MGY=" 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 } } }
2026-08-19 13:41:22,788 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, 58450f5f-1f2b-4007-a89f-d92f6690e027, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:22,796 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(ExecuteDataQuery, 52cb8924-e6e6-46f7-a6e0-349e3105cd67, ghrun-4q22hfe2g4.auto.internal:16290): 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 { } } } } }
2026-08-19 13:41:22,797 - DEBUG - ydb.table.SessionPool.1603316  - put: Put on session <ydb.table.Session object at 0x7f6af61a8b00>
2026-08-19 13:41:22,797 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Requested session destroy: <ydb.table.Session object at 0x7f6af61a8b00>, reason: session-close
2026-08-19 13:41:22,797 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Session <ydb.table.Session object at 0x7f6af61a8b00> is no longer active. Current active count 0.
2026-08-19 13:41:22,797 - DEBUG - ydb.connection.1603316  - _prepare_call: RpcState(DeleteSession, b3fdf686-8847-4647-b20e-3fc675ee24bb, ghrun-4q22hfe2g4.auto.internal:16290): creating call state
2026-08-19 13:41:22,798 - DEBUG - ydb.connection.1603316  - _log_request: RpcState(DeleteSession, b3fdf686-8847-4647-b20e-3fc675ee24bb, ghrun-4q22hfe2g4.auto.internal:16290): request = { session_id: "ydb://session/3?node_id=1&id=OTk2NWQwZjQtMThiMGQ0OWUtZmVlNDUyYTEtODMwMjQ5MGY=" operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2026-08-19 13:41:22,799 - DEBUG - ydb.table.SessionPool.1603316  - _destroy: Sent delete on session <ydb.table.Session object at 0x7f6af61a8b00>
2026-08-19 13:41:22,800 - INFO - ya.test.1603316  - pytest_runtest_teardown: Test teardown
2026-08-19 13:41:22,801 - DEBUG - ydb.topic.1603316  - close: Close topic client
2026-08-19 13:41:22,801 - DEBUG - ydb.topic.1603316  - close: Topic client was closed
2026-08-19 13:41:22,801 - DEBUG - ydb.connection.1603316  - close: Closing channel for endpoint localhost:16290
2026-08-19 13:41:22,801 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, b3fdf686-8847-4647-b20e-3fc675ee24bb, ghrun-4q22hfe2g4.auto.internal:16290): on response callback started
2026-08-19 13:41:22,802 - DEBUG - ydb.connection.1603316  - close: Closing channel for endpoint ghrun-4q22hfe2g4.auto.internal:16290
2026-08-19 13:41:22,802 - DEBUG - ydb.connection.1603316  - _log_response: RpcState(DeleteSession, b3fdf686-8847-4647-b20e-3fc675ee24bb, ghrun-4q22hfe2g4.auto.internal:16290): response = { operation { ready: true status: SUCCESS } }
2026-08-19 13:41:22,803 - INFO - ydb.pool.Discovery.1603316  - run: Successfully terminated discovery process
2026-08-19 13:41:22,803 - DEBUG - ydb.connection.1603316  - _on_response_callback: RpcState(DeleteSession, b3fdf686-8847-4647-b20e-3fc675ee24bb, ghrun-4q22hfe2g4.auto.internal:16290): on response callback success
2026-08-19 13:41:29,805 - INFO - ydb.tests.library.harness.kikimr_runner.1603316  - stop: Stopped node localhost:16290/1
2026-08-19 13:41:29,806 - DEBUG - library.python.filelock.1603316  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/7038
2026-08-19 13:41:29,806 - DEBUG - library.python.filelock.1603316  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/14495
2026-08-19 13:41:29,807 - DEBUG - library.python.filelock.1603316  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/32434
2026-08-19 13:41:29,807 - DEBUG - library.python.filelock.1603316  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16290
2026-08-19 13:41:29,807 - DEBUG - library.python.filelock.1603316  - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/9223
