2025-11-11 15:38:15,821 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-11 15:38:15,821 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[1051200]
2025-11-11 15:38:15,822 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-11 15:38:15,822 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-11 15:38:15,868 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.7
2025-11-11 15:38:15,869 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.7
2025-11-11 15:38:15,870 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-11 15:38:15,891 - DEBUG - ya.test - execute: Command pid: 870464
2025-11-11 15:38:17,402 - DEBUG - ya.test - _save_outputs: Command (pid 870464) rc: 0
2025-11-11 15:38:17,402 - DEBUG - ya.test - _save_outputs: Command (pid 870464) elapsed time (sec): 1.509566068649292
2025-11-11 15:38:17,402 - DEBUG - ya.test - _save_outputs: Command (pid 870464) idrss: 0
2025-11-11 15:38:17,403 - DEBUG - ya.test - _save_outputs: Command (pid 870464) inblock: 0
2025-11-11 15:38:17,403 - DEBUG - ya.test - _save_outputs: Command (pid 870464) isrss: 0
2025-11-11 15:38:17,403 - DEBUG - ya.test - _save_outputs: Command (pid 870464) ixrss: 0
2025-11-11 15:38:17,403 - DEBUG - ya.test - _save_outputs: Command (pid 870464) majflt: 0
2025-11-11 15:38:17,403 - DEBUG - ya.test - _save_outputs: Command (pid 870464) maxrss: 541140
2025-11-11 15:38:17,403 - DEBUG - ya.test - _save_outputs: Command (pid 870464) minflt: 16169
2025-11-11 15:38:17,404 - DEBUG - ya.test - _save_outputs: Command (pid 870464) msgrcv: 0
2025-11-11 15:38:17,404 - DEBUG - ya.test - _save_outputs: Command (pid 870464) msgsnd: 0
2025-11-11 15:38:17,412 - DEBUG - ya.test - _save_outputs: Command (pid 870464) nivcsw: 124
2025-11-11 15:38:17,412 - DEBUG - ya.test - _save_outputs: Command (pid 870464) nsignals: 0
2025-11-11 15:38:17,412 - DEBUG - ya.test - _save_outputs: Command (pid 870464) nswap: 0
2025-11-11 15:38:17,412 - DEBUG - ya.test - _save_outputs: Command (pid 870464) nvcsw: 21
2025-11-11 15:38:17,413 - DEBUG - ya.test - _save_outputs: Command (pid 870464) oublock: 8
2025-11-11 15:38:17,413 - DEBUG - ya.test - _save_outputs: Command (pid 870464) stime: 0.269557
2025-11-11 15:38:17,413 - DEBUG - ya.test - _save_outputs: Command (pid 870464) utime: 0.14445
2025-11-11 15:38:17,413 - DEBUG - ya.test - _save_outputs: Command (pid 870464) wtime: 1.532
2025-11-11 15:38:17,413 - DEBUG - ya.test - _save_outputs: Command (pid 870464) output:
Git info:
    Commit: b1fe97d9d8127d8f2b1d0c3f6dfd6bba81272e1b
    Branch: 
    Author: Nikolay Shestakov <n.shestakov@gmail.com>
    Summary: Merge 50d8af9ebc780945b43536873ee711ed2559af4b into c6a8dfb1a22b05b4afbbf1cd50c1ca5a0dcd4305

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-3ynj4chmly
    Host information: 
        Linux ghrun-3ynj4chmly 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/10226725676/bin/clang++
    Compiler version: 
        clang version 20.1.8
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/10226725676/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-11-11 15:38:17,414 - DEBUG - ya.test - _save_outputs: Command (pid 870464) errors:

2025-11-11 15:38:17,414 - INFO - __tests__.test_log_scenario - _setup_ydb: Git info:
    Commit: b1fe97d9d8127d8f2b1d0c3f6dfd6bba81272e1b
    Branch: 
    Author: Nikolay Shestakov <n.shestakov@gmail.com>
    Summary: Merge 50d8af9ebc780945b43536873ee711ed2559af4b into c6a8dfb1a22b05b4afbbf1cd50c1ca5a0dcd4305

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-3ynj4chmly
    Host information: 
        Linux ghrun-3ynj4chmly 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/10226725676/bin/clang++
    Compiler version: 
        clang version 20.1.8
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/10226725676/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-11-11 15:38:17,648 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd
2025-11-11 15:38:17,649 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/11396
2025-11-11 15:38:17,650 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/iofl/001ef6/r3tmp/kikimr_cluster_iji5pc71
2025-11-11 15:38:17,718 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd
2025-11-11 15:38:17,719 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22586
2025-11-11 15:38:17,723 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/7109
2025-11-11 15:38:17,724 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4845
2025-11-11 15:38:17,724 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/12999
2025-11-11 15:38:17,725 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/iofl/001ef6/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk3/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/kikimr_configs"
2025-11-11 15:38:17,725 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/iofl/001ef6/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/iofl/001ef6/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk3/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1/logfile_a8vbl6sy.log --grpc-port=22586 --mon-port=7109 --ic-port=11396
2025-11-11 15:38:17,726 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:22586/1, disk_size 68719476736
2025-11-11 15:38:17,726 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/iofl/001ef6/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk3/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/kikimr_configs"
2025-11-11 15:38:17,726 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/iofl/001ef6/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/iofl/001ef6/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk3/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1/logfile_a8vbl6sy.log --grpc-port=22586 --mon-port=7109 --ic-port=11396
2025-11-11 15:38:17,748 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/iofl/001ef6/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk3/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/iofl/001ef6/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk3/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1/logfile_a8vbl6sy.log', '--grpc-port=22586', '--mon-port=7109', '--ic-port=11396')' in '/home/runner/.ya/build/build_root/iofl/001ef6/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk3/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1' (no wait)
2025-11-11 15:38:17,759 - DEBUG - ya.test - execute: Command pid: 871641
2025-11-11 15:38:17,760 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:22586/1
2025-11-11 15:38:17,761 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.8
2025-11-11 15:38:17,761 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.8
2025-11-11 15:38:17,762 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-11 15:38:17,771 - DEBUG - ya.test - execute: Command pid: 871642
2025-11-11 15:38:19,006 - DEBUG - ya.test - _save_outputs: Command (pid 871642) rc: 0
2025-11-11 15:38:19,006 - DEBUG - ya.test - _save_outputs: Command (pid 871642) elapsed time (sec): 1.2339251041412354
2025-11-11 15:38:19,007 - DEBUG - ya.test - _save_outputs: Command (pid 871642) idrss: 0
2025-11-11 15:38:19,007 - DEBUG - ya.test - _save_outputs: Command (pid 871642) inblock: 0
2025-11-11 15:38:19,007 - DEBUG - ya.test - _save_outputs: Command (pid 871642) isrss: 0
2025-11-11 15:38:19,007 - DEBUG - ya.test - _save_outputs: Command (pid 871642) ixrss: 0
2025-11-11 15:38:19,007 - DEBUG - ya.test - _save_outputs: Command (pid 871642) majflt: 0
2025-11-11 15:38:19,007 - DEBUG - ya.test - _save_outputs: Command (pid 871642) maxrss: 541136
2025-11-11 15:38:19,008 - DEBUG - ya.test - _save_outputs: Command (pid 871642) minflt: 16167
2025-11-11 15:38:19,008 - DEBUG - ya.test - _save_outputs: Command (pid 871642) msgrcv: 0
2025-11-11 15:38:19,008 - DEBUG - ya.test - _save_outputs: Command (pid 871642) msgsnd: 0
2025-11-11 15:38:19,008 - DEBUG - ya.test - _save_outputs: Command (pid 871642) nivcsw: 107
2025-11-11 15:38:19,008 - DEBUG - ya.test - _save_outputs: Command (pid 871642) nsignals: 0
2025-11-11 15:38:19,009 - DEBUG - ya.test - _save_outputs: Command (pid 871642) nswap: 0
2025-11-11 15:38:19,009 - DEBUG - ya.test - _save_outputs: Command (pid 871642) nvcsw: 18
2025-11-11 15:38:19,009 - DEBUG - ya.test - _save_outputs: Command (pid 871642) oublock: 8
2025-11-11 15:38:19,009 - DEBUG - ya.test - _save_outputs: Command (pid 871642) stime: 0.260953
2025-11-11 15:38:19,009 - DEBUG - ya.test - _save_outputs: Command (pid 871642) utime: 0.12475699999999999
2025-11-11 15:38:19,010 - DEBUG - ya.test - _save_outputs: Command (pid 871642) wtime: 1.244
2025-11-11 15:38:19,010 - DEBUG - ya.test - _save_outputs: Command (pid 871642) output:
Git info:
    Commit: b1fe97d9d8127d8f2b1d0c3f6dfd6bba81272e1b
    Branch: 
    Author: Nikolay Shestakov <n.shestakov@gmail.com>
    Summary: Merge 50d8af9ebc780945b43536873ee711ed2559af4b into c6a8dfb1a22b05b4afbbf1cd50c1ca5a0dcd4305

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-3ynj4chmly
    Host information: 
        Linux ghrun-3ynj4chmly 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/10226725676/bin/clang++
    Compiler version: 
        clang version 20.1.8
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/10226725676/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-11-11 15:38:19,010 - DEBUG - ya.test - _save_outputs: Command (pid 871642) errors:

2025-11-11 15:38:19,010 - INFO - ydb.tests.library.harness.kikimr_runner - start: Node 1 version:
Git info:
    Commit: b1fe97d9d8127d8f2b1d0c3f6dfd6bba81272e1b
    Branch: 
    Author: Nikolay Shestakov <n.shestakov@gmail.com>
    Summary: Merge 50d8af9ebc780945b43536873ee711ed2559af4b into c6a8dfb1a22b05b4afbbf1cd50c1ca5a0dcd4305
2025-11-11 15:38:21,620 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd
2025-11-11 15:38:21,621 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:22586', '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: 11396\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-11 15:38:21,622 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.9
2025-11-11 15:38:21,622 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.9
2025-11-11 15:38:21,623 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:22586', '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: 11396\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-11 15:38:21,652 - DEBUG - ya.test - execute: Command pid: 874025
2025-11-11 15:38:23,291 - DEBUG - ya.test - _save_outputs: Command (pid 874025) rc: 0
2025-11-11 15:38:23,292 - DEBUG - ya.test - _save_outputs: Command (pid 874025) elapsed time (sec): 1.6389925479888916
2025-11-11 15:38:23,292 - DEBUG - ya.test - _save_outputs: Command (pid 874025) idrss: 0
2025-11-11 15:38:23,292 - DEBUG - ya.test - _save_outputs: Command (pid 874025) inblock: 0
2025-11-11 15:38:23,292 - DEBUG - ya.test - _save_outputs: Command (pid 874025) isrss: 0
2025-11-11 15:38:23,293 - DEBUG - ya.test - _save_outputs: Command (pid 874025) ixrss: 0
2025-11-11 15:38:23,293 - DEBUG - ya.test - _save_outputs: Command (pid 874025) majflt: 0
2025-11-11 15:38:23,293 - DEBUG - ya.test - _save_outputs: Command (pid 874025) maxrss: 549376
2025-11-11 15:38:23,293 - DEBUG - ya.test - _save_outputs: Command (pid 874025) minflt: 18309
2025-11-11 15:38:23,293 - DEBUG - ya.test - _save_outputs: Command (pid 874025) msgrcv: 0
2025-11-11 15:38:23,293 - DEBUG - ya.test - _save_outputs: Command (pid 874025) msgsnd: 0
2025-11-11 15:38:23,293 - DEBUG - ya.test - _save_outputs: Command (pid 874025) nivcsw: 146
2025-11-11 15:38:23,294 - DEBUG - ya.test - _save_outputs: Command (pid 874025) nsignals: 0
2025-11-11 15:38:23,294 - DEBUG - ya.test - _save_outputs: Command (pid 874025) nswap: 0
2025-11-11 15:38:23,294 - DEBUG - ya.test - _save_outputs: Command (pid 874025) nvcsw: 76
2025-11-11 15:38:23,294 - DEBUG - ya.test - _save_outputs: Command (pid 874025) oublock: 8
2025-11-11 15:38:23,294 - DEBUG - ya.test - _save_outputs: Command (pid 874025) stime: 0.25843299999999997
2025-11-11 15:38:23,294 - DEBUG - ya.test - _save_outputs: Command (pid 874025) utime: 0.14554899999999998
2025-11-11 15:38:23,294 - DEBUG - ya.test - _save_outputs: Command (pid 874025) wtime: 1.667
2025-11-11 15:38:23,295 - DEBUG - ya.test - _save_outputs: Command (pid 874025) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2025-11-11 15:38:23,295 - DEBUG - ya.test - _save_outputs: Command (pid 874025) errors:

2025-11-11 15:38:23,301 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd
2025-11-11 15:38:23,319 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:22586', '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-11-11 15:38:23,321 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.10
2025-11-11 15:38:23,321 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.10
2025-11-11 15:38:23,321 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:22586', '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-11-11 15:38:23,332 - DEBUG - ya.test - execute: Command pid: 874845
2025-11-11 15:38:25,265 - DEBUG - ya.test - _save_outputs: Command (pid 874845) rc: 0
2025-11-11 15:38:25,266 - DEBUG - ya.test - _save_outputs: Command (pid 874845) elapsed time (sec): 1.9060144424438477
2025-11-11 15:38:25,269 - DEBUG - ya.test - _save_outputs: Command (pid 874845) idrss: 0
2025-11-11 15:38:25,270 - DEBUG - ya.test - _save_outputs: Command (pid 874845) inblock: 0
2025-11-11 15:38:25,270 - DEBUG - ya.test - _save_outputs: Command (pid 874845) isrss: 0
2025-11-11 15:38:25,270 - DEBUG - ya.test - _save_outputs: Command (pid 874845) ixrss: 0
2025-11-11 15:38:25,270 - DEBUG - ya.test - _save_outputs: Command (pid 874845) majflt: 0
2025-11-11 15:38:25,270 - DEBUG - ya.test - _save_outputs: Command (pid 874845) maxrss: 549396
2025-11-11 15:38:25,270 - DEBUG - ya.test - _save_outputs: Command (pid 874845) minflt: 18309
2025-11-11 15:38:25,271 - DEBUG - ya.test - _save_outputs: Command (pid 874845) msgrcv: 0
2025-11-11 15:38:25,271 - DEBUG - ya.test - _save_outputs: Command (pid 874845) msgsnd: 0
2025-11-11 15:38:25,275 - DEBUG - ya.test - _save_outputs: Command (pid 874845) nivcsw: 224
2025-11-11 15:38:25,275 - DEBUG - ya.test - _save_outputs: Command (pid 874845) nsignals: 0
2025-11-11 15:38:25,276 - DEBUG - ya.test - _save_outputs: Command (pid 874845) nswap: 0
2025-11-11 15:38:25,276 - DEBUG - ya.test - _save_outputs: Command (pid 874845) nvcsw: 75
2025-11-11 15:38:25,276 - DEBUG - ya.test - _save_outputs: Command (pid 874845) oublock: 8
2025-11-11 15:38:25,276 - DEBUG - ya.test - _save_outputs: Command (pid 874845) stime: 0.25626099999999996
2025-11-11 15:38:25,276 - DEBUG - ya.test - _save_outputs: Command (pid 874845) utime: 0.141098
2025-11-11 15:38:25,287 - DEBUG - ya.test - _save_outputs: Command (pid 874845) wtime: 1.917
2025-11-11 15:38:25,288 - DEBUG - ya.test - _save_outputs: Command (pid 874845) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-11 15:38:25,288 - DEBUG - ya.test - _save_outputs: Command (pid 874845) errors:

2025-11-11 15:38:25,288 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-11-11 15:38:25,330 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-11 15:38:25,356 - 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-11-11 15:38:25,387 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-11 15:38:25,392 - 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-11-11 15:38:25,429 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-11 15:38:25,429 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 51767ec8-3509-486c-8364-bdb1c6463163, localhost:22586): creating call state
2025-11-11 15:38:25,429 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 51767ec8-3509-486c-8364-bdb1c6463163, localhost:22586): request = { database: "/Root" }
2025-11-11 15:38:25,450 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 51767ec8-3509-486c-8364-bdb1c6463163, localhost:22586): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-3ynj4chmly.auto.internal" port: 22586 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-11-11 15:38:25,469 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-3ynj4chmly.auto.internal:22586, location 1, ssl: False>]>
2025-11-11 15:38:25,476 - 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-11-11 15:38:25,519 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:22586
2025-11-11 15:38:25,524 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[1051200])
2025-11-11 15:38:25,525 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb
2025-11-11 15:38:25,525 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-11 15:38:25,526 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out
2025-11-11 15:38:25,539 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err
2025-11-11 15:38:25,539 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-11 15:38:25,554 - DEBUG - ya.test - execute: Command pid: 875985
2025-11-11 15:38:26,607 - DEBUG - ya.test - _save_outputs: Command (pid 875985) rc: 0
2025-11-11 15:38:26,607 - DEBUG - ya.test - _save_outputs: Command (pid 875985) elapsed time (sec): 1.0423943996429443
2025-11-11 15:38:26,608 - DEBUG - ya.test - _save_outputs: Command (pid 875985) idrss: 0
2025-11-11 15:38:26,608 - DEBUG - ya.test - _save_outputs: Command (pid 875985) inblock: 0
2025-11-11 15:38:26,608 - DEBUG - ya.test - _save_outputs: Command (pid 875985) isrss: 0
2025-11-11 15:38:26,608 - DEBUG - ya.test - _save_outputs: Command (pid 875985) ixrss: 0
2025-11-11 15:38:26,608 - DEBUG - ya.test - _save_outputs: Command (pid 875985) majflt: 0
2025-11-11 15:38:26,608 - DEBUG - ya.test - _save_outputs: Command (pid 875985) maxrss: 180276
2025-11-11 15:38:26,609 - DEBUG - ya.test - _save_outputs: Command (pid 875985) minflt: 3543
2025-11-11 15:38:26,609 - DEBUG - ya.test - _save_outputs: Command (pid 875985) msgrcv: 0
2025-11-11 15:38:26,609 - DEBUG - ya.test - _save_outputs: Command (pid 875985) msgsnd: 0
2025-11-11 15:38:26,609 - DEBUG - ya.test - _save_outputs: Command (pid 875985) nivcsw: 42
2025-11-11 15:38:26,609 - DEBUG - ya.test - _save_outputs: Command (pid 875985) nsignals: 0
2025-11-11 15:38:26,609 - DEBUG - ya.test - _save_outputs: Command (pid 875985) nswap: 0
2025-11-11 15:38:26,609 - DEBUG - ya.test - _save_outputs: Command (pid 875985) nvcsw: 127
2025-11-11 15:38:26,610 - DEBUG - ya.test - _save_outputs: Command (pid 875985) oublock: 8
2025-11-11 15:38:26,610 - DEBUG - ya.test - _save_outputs: Command (pid 875985) stime: 0.023575
2025-11-11 15:38:26,610 - DEBUG - ya.test - _save_outputs: Command (pid 875985) utime: 0.051864999999999994
2025-11-11 15:38:26,610 - DEBUG - ya.test - _save_outputs: Command (pid 875985) wtime: 1.062
2025-11-11 15:38:26,610 - DEBUG - ya.test - _save_outputs: Command (pid 875985) output:
Init tables ...
Init tables ...Ok

2025-11-11 15:38:26,610 - DEBUG - ya.test - _save_outputs: Command (pid 875985) errors:

2025-11-11 15:38:26,611 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 0 < 100, will create new one.
2025-11-11 15:38:26,624 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 81c045a5-2b22-455d-a153-ed69e8a498c4, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:26,624 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 81c045a5-2b22-455d-a153-ed69e8a498c4, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:26,636 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 81c045a5-2b22-455d-a153-ed69e8a498c4, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" node_id: 1 }
2025-11-11 15:38:26,654 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 3c948638-2a3b-4068-8270-1fd1eab9fe6e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:26,655 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 3c948638-2a3b-4068-8270-1fd1eab9fe6e, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" }
2025-11-11 15:38:26,704 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 3c948638-2a3b-4068-8270-1fd1eab9fe6e, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:26,740 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:26,740 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fcccd59f-1333-4fa2-96cb-1a044b1e8627, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:26,741 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fcccd59f-1333-4fa2-96cb-1a044b1e8627, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "ALTER OBJECT `//Root/log` (TYPE TABLE) SET (ACTION=UPSERT_OPTIONS, `SCAN_READER_POLICY_NAME`=`SIMPLE`) " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:26,741 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fcccd59f-1333-4fa2-96cb-1a044b1e8627, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:26,808 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:26,809 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-11 15:38:26,809 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-11 15:38:26,810 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.0
2025-11-11 15:38:26,810 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.0
2025-11-11 15:38:26,810 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-11 15:38:26,820 - DEBUG - ya.test - execute: Command pid: 876656
2025-11-11 15:38:32,115 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:38:32,116 - DEBUG - ya.test - _save_outputs: Command (pid 876656) rc: 0
2025-11-11 15:38:32,116 - DEBUG - ya.test - _save_outputs: Command (pid 876656) elapsed time (sec): 5.295226335525513
2025-11-11 15:38:32,116 - DEBUG - ya.test - _save_outputs: Command (pid 876656) wtime: 5.305
2025-11-11 15:38:32,117 - DEBUG - ya.test - _save_outputs: Command (pid 876656) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      4	4	0	0	1815	1871	1871	1871
3	     16	16	0	0	2191	2527	2527	2527

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     20	6.66667	0	0	2127	2527	2527	2527

2025-11-11 15:38:32,117 - DEBUG - ya.test - _save_outputs: Command (pid 876656) errors:

2025-11-11 15:38:32,117 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:32,118 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, be15ab0f-b709-4f9b-9f01-ddef8868ce7f, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:32,118 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, be15ab0f-b709-4f9b-9f01-ddef8868ce7f, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:32,119 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, be15ab0f-b709-4f9b-9f01-ddef8868ce7f, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:33,565 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:33,566 - INFO - root - test_log_deviation: Count rows after insert 10000 before wait
2025-11-11 15:38:33,566 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:33,566 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d0449152-a817-45c0-88fd-a5eb9c0ad0a1, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:33,567 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d0449152-a817-45c0-88fd-a5eb9c0ad0a1, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:33,568 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d0449152-a817-45c0-88fd-a5eb9c0ad0a1, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,125 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:34,126 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:34,126 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a9d530ed-3b85-4e80-9838-220559b73576, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,127 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a9d530ed-3b85-4e80-9838-220559b73576, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:34,127 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a9d530ed-3b85-4e80-9838-220559b73576, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,460 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:34,492 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-11 15:38:34,495 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-11 15:38:34,497 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.1
2025-11-11 15:38:34,497 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.1
2025-11-11 15:38:34,497 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-11 15:38:34,510 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-11 15:38:34,515 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-11 15:38:34,510 - DEBUG - ya.test - execute: Command pid: 879475
2025-11-11 15:38:34,524 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-11 15:38:34,524 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb -e grpc://localhost:22586 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-11 15:38:34,525 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.3
2025-11-11 15:38:34,526 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.2
2025-11-11 15:38:34,526 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-11 15:38:34,523 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.2
2025-11-11 15:38:34,548 - DEBUG - ya.test - execute: Command pid: 879493
2025-11-11 15:38:34,559 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.3
2025-11-11 15:38:34,567 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-11 15:38:34,559 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:34,612 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6e4b3a17-fa3c-4664-bc2b-d884e89cfc4e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,613 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6e4b3a17-fa3c-4664-bc2b-d884e89cfc4e, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:34,585 - DEBUG - ya.test - execute: Command pid: 879509
2025-11-11 15:38:34,613 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 1 < 100, will create new one.
2025-11-11 15:38:34,619 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 75343e2c-877c-4ac4-99de-ad6f94e89ce8, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,619 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 75343e2c-877c-4ac4-99de-ad6f94e89ce8, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:34,618 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6e4b3a17-fa3c-4664-bc2b-d884e89cfc4e, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,628 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 75343e2c-877c-4ac4-99de-ad6f94e89ce8, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" node_id: 1 }
2025-11-11 15:38:34,644 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 63226874-24b5-4f56-bbe6-d6c4ebeff853, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,645 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 63226874-24b5-4f56-bbe6-d6c4ebeff853, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" }
2025-11-11 15:38:34,646 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 63226874-24b5-4f56-bbe6-d6c4ebeff853, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,656 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:38:34,657 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, aac8da68-5c61-4226-90c4-a268ca25c7cb, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,657 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, aac8da68-5c61-4226-90c4-a268ca25c7cb, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:34,658 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, aac8da68-5c61-4226-90c4-a268ca25c7cb, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,658 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 2 < 100, will create new one.
2025-11-11 15:38:34,659 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 35fd3102-0039-452c-9ffe-cb9185582988, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,659 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 35fd3102-0039-452c-9ffe-cb9185582988, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:34,665 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 35fd3102-0039-452c-9ffe-cb9185582988, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" node_id: 1 }
2025-11-11 15:38:34,666 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 1c83dbc6-c725-4a3d-817b-88b68b0e3661, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,666 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 1c83dbc6-c725-4a3d-817b-88b68b0e3661, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" }
2025-11-11 15:38:34,667 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 1c83dbc6-c725-4a3d-817b-88b68b0e3661, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,720 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:38:34,720 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 450b6678-0190-4779-84be-caff4441ebfa, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,721 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 450b6678-0190-4779-84be-caff4441ebfa, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:34,721 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 450b6678-0190-4779-84be-caff4441ebfa, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,722 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 3 < 100, will create new one.
2025-11-11 15:38:34,723 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, b5262419-f797-4d0c-a762-2fd0a3403a78, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,723 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, b5262419-f797-4d0c-a762-2fd0a3403a78, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:34,733 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, b5262419-f797-4d0c-a762-2fd0a3403a78, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" node_id: 1 }
2025-11-11 15:38:34,733 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 3cc117e0-d11c-435d-95f7-709f2a7c1b0b, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,734 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 3cc117e0-d11c-435d-95f7-709f2a7c1b0b, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" }
2025-11-11 15:38:34,734 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 3cc117e0-d11c-435d-95f7-709f2a7c1b0b, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,783 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:38:34,784 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 37c5bcb3-ae57-407f-9cd9-3f48e8cd63b0, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,784 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 37c5bcb3-ae57-407f-9cd9-3f48e8cd63b0, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:34,785 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 37c5bcb3-ae57-407f-9cd9-3f48e8cd63b0, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,785 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 4 < 100, will create new one.
2025-11-11 15:38:34,786 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 9eb7af70-66ea-439b-ae5b-ca188295da9c, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,786 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 9eb7af70-66ea-439b-ae5b-ca188295da9c, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:34,828 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 9eb7af70-66ea-439b-ae5b-ca188295da9c, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" node_id: 1 }
2025-11-11 15:38:34,829 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, bb200ddd-6b3c-4d65-9373-b5b0e0549718, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,829 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, bb200ddd-6b3c-4d65-9373-b5b0e0549718, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" }
2025-11-11 15:38:34,830 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, bb200ddd-6b3c-4d65-9373-b5b0e0549718, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,870 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:38:34,871 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, dd7936f8-8804-422b-bb49-83b099436b63, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,871 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, dd7936f8-8804-422b-bb49-83b099436b63, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:34,872 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, dd7936f8-8804-422b-bb49-83b099436b63, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:34,873 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 5 < 100, will create new one.
2025-11-11 15:38:34,873 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 2a214edc-8609-4e4b-8dc0-8e4d23a2de9d, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,874 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 2a214edc-8609-4e4b-8dc0-8e4d23a2de9d, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:34,992 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 2a214edc-8609-4e4b-8dc0-8e4d23a2de9d, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" node_id: 1 }
2025-11-11 15:38:34,992 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 990ce70b-ec69-43de-823d-ec62456e508e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:34,993 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 990ce70b-ec69-43de-823d-ec62456e508e, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" }
2025-11-11 15:38:34,994 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 990ce70b-ec69-43de-823d-ec62456e508e, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:35,076 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:38:35,077 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 97a1f3a7-c371-4b9c-9b68-1ccc3713d8a0, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,078 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 97a1f3a7-c371-4b9c-9b68-1ccc3713d8a0, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:35,079 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 97a1f3a7-c371-4b9c-9b68-1ccc3713d8a0, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:35,077 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 6 < 100, will create new one.
2025-11-11 15:38:35,080 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, cedda4e3-b167-45af-a560-e775177dfe4e, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,080 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, cedda4e3-b167-45af-a560-e775177dfe4e, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:35,140 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, cedda4e3-b167-45af-a560-e775177dfe4e, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" node_id: 1 }
2025-11-11 15:38:35,140 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, d4326eeb-7381-4d2b-b90f-69bdc83975ac, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,141 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, d4326eeb-7381-4d2b-b90f-69bdc83975ac, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" }
2025-11-11 15:38:35,142 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, d4326eeb-7381-4d2b-b90f-69bdc83975ac, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:35,196 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:38:35,196 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d9f26f10-5ed4-488e-8c9a-24c6b24a8edb, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,197 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d9f26f10-5ed4-488e-8c9a-24c6b24a8edb, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:35,198 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d9f26f10-5ed4-488e-8c9a-24c6b24a8edb, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:35,198 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 7 < 100, will create new one.
2025-11-11 15:38:35,199 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 2c164a0b-c964-4edf-ba4c-ce8098e8de39, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,199 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 2c164a0b-c964-4edf-ba4c-ce8098e8de39, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:35,304 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 2c164a0b-c964-4edf-ba4c-ce8098e8de39, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" node_id: 1 }
2025-11-11 15:38:35,305 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 0546c0fe-28b4-41b6-b007-bd0491d2d4b5, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,305 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 0546c0fe-28b4-41b6-b007-bd0491d2d4b5, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" }
2025-11-11 15:38:35,306 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 0546c0fe-28b4-41b6-b007-bd0491d2d4b5, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:35,462 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:38:35,463 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fde29e9f-0e32-49ef-acdd-07ed1602c60a, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,472 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fde29e9f-0e32-49ef-acdd-07ed1602c60a, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:35,473 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fde29e9f-0e32-49ef-acdd-07ed1602c60a, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:35,463 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 8 < 100, will create new one.
2025-11-11 15:38:35,480 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 377134ee-a1c8-4f1c-af8a-15905b86863b, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:35,481 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 377134ee-a1c8-4f1c-af8a-15905b86863b, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:36,078 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 377134ee-a1c8-4f1c-af8a-15905b86863b, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" node_id: 1 }
2025-11-11 15:38:36,078 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 44859534-7f0d-4864-bd0d-2d81c6e91bee, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:36,079 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 44859534-7f0d-4864-bd0d-2d81c6e91bee, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" }
2025-11-11 15:38:36,079 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 44859534-7f0d-4864-bd0d-2d81c6e91bee, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:37,340 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:38:37,340 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ecba2d61-9e75-4207-9aea-1abbed2fd2a7, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:37,341 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ecba2d61-9e75-4207-9aea-1abbed2fd2a7, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:37,342 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ecba2d61-9e75-4207-9aea-1abbed2fd2a7, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:37,343 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 9 < 100, will create new one.
2025-11-11 15:38:37,370 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, a2a02a4f-4cb4-4350-b949-bd6d3dfe6e8a, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:37,370 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, a2a02a4f-4cb4-4350-b949-bd6d3dfe6e8a, ghrun-3ynj4chmly.auto.internal:22586): request = {  }
2025-11-11 15:38:37,535 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, a2a02a4f-4cb4-4350-b949-bd6d3dfe6e8a, ghrun-3ynj4chmly.auto.internal:22586): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" node_id: 1 }
2025-11-11 15:38:37,568 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 1e2539a3-caa1-456f-b053-cbc10d1e6a34, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:37,568 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 1e2539a3-caa1-456f-b053-cbc10d1e6a34, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" }
2025-11-11 15:38:37,570 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 1e2539a3-caa1-456f-b053-cbc10d1e6a34, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:37,996 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:38:37,997 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3e7769bd-dbcb-4e44-9385-0cb027f6681b, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:37,997 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3e7769bd-dbcb-4e44-9385-0cb027f6681b, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:38,041 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3e7769bd-dbcb-4e44-9385-0cb027f6681b, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:38,979 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:38:38,980 - DEBUG - ya.test - _save_outputs: Command (pid 879509) rc: 0
2025-11-11 15:38:38,980 - DEBUG - ya.test - _save_outputs: Command (pid 879509) elapsed time (sec): 4.36161994934082
2025-11-11 15:38:38,980 - DEBUG - ya.test - _save_outputs: Command (pid 879509) wtime: 4.412
2025-11-11 15:38:38,980 - DEBUG - ya.test - _save_outputs: Command (pid 879509) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	9	0	0	0	0
3	      0	0	0	10	0	0	0	0

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	      0	0	0	19	0	0	0	0

2025-11-11 15:38:38,989 - DEBUG - ya.test - _save_outputs: Command (pid 879509) errors:

2025-11-11 15:38:39,156 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:38:39,156 - DEBUG - ya.test - _save_outputs: Command (pid 879493) rc: 0
2025-11-11 15:38:39,157 - DEBUG - ya.test - _save_outputs: Command (pid 879493) elapsed time (sec): 4.591416597366333
2025-11-11 15:38:39,157 - DEBUG - ya.test - _save_outputs: Command (pid 879493) wtime: 4.63
2025-11-11 15:38:39,157 - DEBUG - ya.test - _save_outputs: Command (pid 879493) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	10	0	0	0	0
3	      0	0	0	10	0	0	0	0

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	      0	0	0	20	0	0	0	0

2025-11-11 15:38:39,157 - DEBUG - ya.test - _save_outputs: Command (pid 879493) errors:

2025-11-11 15:38:43,321 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:38:43,321 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:38:43,322 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8cda9bfe-684e-4c72-9db7-fa205df25834, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:43,322 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8cda9bfe-684e-4c72-9db7-fa205df25834, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:43,325 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8cda9bfe-684e-4c72-9db7-fa205df25834, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:43,827 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:43,828 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:43,856 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ea8bf917-5374-4642-a723-7dddf436affb, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:43,857 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ea8bf917-5374-4642-a723-7dddf436affb, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:43,858 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ea8bf917-5374-4642-a723-7dddf436affb, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:43,861 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:38:43,862 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:38:43,862 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f34b129d-a9f3-41b0-bc18-f83ac2ac3656, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:43,863 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f34b129d-a9f3-41b0-bc18-f83ac2ac3656, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:43,864 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f34b129d-a9f3-41b0-bc18-f83ac2ac3656, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:44,056 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:38:44,057 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:38:44,057 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 56f9a371-db48-45bd-b86b-9540a4f1f9d3, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:44,058 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 56f9a371-db48-45bd-b86b-9540a4f1f9d3, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:44,058 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 56f9a371-db48-45bd-b86b-9540a4f1f9d3, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:44,059 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:38:44,059 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:38:44,059 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ecfe4191-8882-4641-9e6b-1efa22de6867, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:44,060 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ecfe4191-8882-4641-9e6b-1efa22de6867, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:44,060 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ecfe4191-8882-4641-9e6b-1efa22de6867, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:44,184 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:38:44,184 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:38:44,184 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b02ad30d-78d4-4ebe-8119-837228606fb9, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:44,185 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b02ad30d-78d4-4ebe-8119-837228606fb9, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:44,186 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b02ad30d-78d4-4ebe-8119-837228606fb9, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:44,358 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:38:44,358 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:38:44,359 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ba140e61-64f4-4ed2-97c8-db44c1c8665b, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:44,359 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ba140e61-64f4-4ed2-97c8-db44c1c8665b, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:44,360 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ba140e61-64f4-4ed2-97c8-db44c1c8665b, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:44,403 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:38:44,403 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:38:44,404 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3734007a-8acf-4b50-9f92-314df4f9ef87, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:44,404 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3734007a-8acf-4b50-9f92-314df4f9ef87, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:44,405 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3734007a-8acf-4b50-9f92-314df4f9ef87, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:44,772 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:38:44,773 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:38:44,773 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e9885734-c0be-48ed-af75-69db5e687bd5, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:44,774 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e9885734-c0be-48ed-af75-69db5e687bd5, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:44,774 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e9885734-c0be-48ed-af75-69db5e687bd5, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:45,043 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:38:45,044 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:38:45,045 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 326d2dc8-a9f6-4131-a971-f85baaab669c, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:45,045 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 326d2dc8-a9f6-4131-a971-f85baaab669c, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:45,046 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 326d2dc8-a9f6-4131-a971-f85baaab669c, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:55,362 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-11 15:38:55,379 - DEBUG - ya.test - _save_outputs: Command (pid 879475) rc: 0
2025-11-11 15:38:55,380 - DEBUG - ya.test - _save_outputs: Command (pid 879475) elapsed time (sec): 20.83896255493164
2025-11-11 15:38:55,381 - DEBUG - ya.test - _save_outputs: Command (pid 879475) wtime: 20.865
2025-11-11 15:38:55,381 - DEBUG - ya.test - _save_outputs: Command (pid 879475) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      0	0	0	0	0	0	0	0
2	      0	0	0	0	0	0	0	0
3	      0	0	0	10	0	0	0	0

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	      0	0	0	10	0	0	0	0

2025-11-11 15:38:55,382 - DEBUG - ya.test - _save_outputs: Command (pid 879475) errors:

2025-11-11 15:38:57,316 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:57,412 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:38:57,412 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f1b1f84b-0d15-4cbf-a7bc-ef4704e37f97, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:57,413 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f1b1f84b-0d15-4cbf-a7bc-ef4704e37f97, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:57,434 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f1b1f84b-0d15-4cbf-a7bc-ef4704e37f97, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:57,491 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:38:57,577 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:38:57,577 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bcd22f4e-9add-4bcb-bfe9-e6e21774bc04, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:57,578 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bcd22f4e-9add-4bcb-bfe9-e6e21774bc04, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:57,582 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bcd22f4e-9add-4bcb-bfe9-e6e21774bc04, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:57,599 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:38:57,648 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:38:57,649 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 561a7338-1183-4381-9bb8-11325bc95141, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:57,649 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 561a7338-1183-4381-9bb8-11325bc95141, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:57,650 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 561a7338-1183-4381-9bb8-11325bc95141, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:57,803 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:38:57,886 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:38:57,941 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:38:57,942 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 92c5b0d3-6bd5-4f3d-b5ff-fac6767cf295, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:57,943 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 92c5b0d3-6bd5-4f3d-b5ff-fac6767cf295, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:57,943 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:38:57,943 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9964f32b-9035-40be-a030-d60276cde3e4, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:57,944 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9964f32b-9035-40be-a030-d60276cde3e4, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:57,962 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 92c5b0d3-6bd5-4f3d-b5ff-fac6767cf295, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:57,963 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9964f32b-9035-40be-a030-d60276cde3e4, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:58,019 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:38:58,104 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:38:58,172 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:38:58,173 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 60585259-8e06-405f-b2f2-d8ba6deeb715, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:58,173 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 60585259-8e06-405f-b2f2-d8ba6deeb715, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:58,174 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:38:58,174 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5dd6a20e-7e28-4b3f-a537-f5794b68fe05, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:58,174 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5dd6a20e-7e28-4b3f-a537-f5794b68fe05, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:58,195 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 60585259-8e06-405f-b2f2-d8ba6deeb715, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:58,196 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5dd6a20e-7e28-4b3f-a537-f5794b68fe05, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:58,202 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:38:58,273 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:38:58,356 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:38:58,356 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 43abd2d7-5af1-4840-9a57-2bb6b0835b83, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:58,357 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 43abd2d7-5af1-4840-9a57-2bb6b0835b83, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:58,358 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 43abd2d7-5af1-4840-9a57-2bb6b0835b83, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:58,359 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:38:58,359 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 23a38374-d821-4cae-aaa3-0be718773813, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:58,359 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 23a38374-d821-4cae-aaa3-0be718773813, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:58,360 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 23a38374-d821-4cae-aaa3-0be718773813, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:38:58,429 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:38:58,531 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:38:58,539 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 10f6f236-14c1-4fd0-b219-e13361ba3475, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:38:58,539 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 10f6f236-14c1-4fd0-b219-e13361ba3475, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:38:58,540 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 10f6f236-14c1-4fd0-b219-e13361ba3475, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:04,944 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:04,945 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:04,945 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c48616c5-24a9-4a77-af7f-c76556c59d46, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:04,946 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c48616c5-24a9-4a77-af7f-c76556c59d46, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:04,946 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c48616c5-24a9-4a77-af7f-c76556c59d46, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,015 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:05,016 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:05,016 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 36f11094-c91c-4d71-85da-ad53c5a83c2a, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,017 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 36f11094-c91c-4d71-85da-ad53c5a83c2a, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,018 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 36f11094-c91c-4d71-85da-ad53c5a83c2a, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,020 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:05,020 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:05,021 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 319e6e95-fac6-4942-8451-2f1ed9d124e6, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,021 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 319e6e95-fac6-4942-8451-2f1ed9d124e6, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,022 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 319e6e95-fac6-4942-8451-2f1ed9d124e6, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,028 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:05,029 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:05,029 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3c74bd2a-ce52-4018-9203-31570980ad9b, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,030 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3c74bd2a-ce52-4018-9203-31570980ad9b, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,031 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3c74bd2a-ce52-4018-9203-31570980ad9b, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,036 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:05,037 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:05,037 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3fa971b5-708c-4d9e-bca6-d0d1953bce31, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,038 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3fa971b5-708c-4d9e-bca6-d0d1953bce31, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,039 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3fa971b5-708c-4d9e-bca6-d0d1953bce31, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,040 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:05,041 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:05,041 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 38582094-b95d-4739-8a49-74ec868a5704, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,041 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 38582094-b95d-4739-8a49-74ec868a5704, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,042 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 38582094-b95d-4739-8a49-74ec868a5704, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,044 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:05,044 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:05,045 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f3e7da3e-3cf5-4b97-a0ee-11a4071f13d8, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,045 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f3e7da3e-3cf5-4b97-a0ee-11a4071f13d8, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,046 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f3e7da3e-3cf5-4b97-a0ee-11a4071f13d8, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,064 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:05,065 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:05,065 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f167abc5-4669-4379-a946-328e41309aac, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,066 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f167abc5-4669-4379-a946-328e41309aac, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,066 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f167abc5-4669-4379-a946-328e41309aac, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,071 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:05,072 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:05,072 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1f4bcfc6-2eeb-4c80-bb45-d0dc2069e757, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,073 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1f4bcfc6-2eeb-4c80-bb45-d0dc2069e757, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,073 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1f4bcfc6-2eeb-4c80-bb45-d0dc2069e757, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:05,078 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:05,078 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:05,079 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 57f83d4a-a5c8-43c0-8a61-46ba1561db40, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:05,080 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 57f83d4a-a5c8-43c0-8a61-46ba1561db40, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(8)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7))" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:05,080 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 57f83d4a-a5c8-43c0-8a61-46ba1561db40, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:06,977 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:06,983 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjM3MzUwYTAtNjlhNTdhY2YtZWVkOTkxYWYtZmU5MDBkYzY=
2025-11-11 15:39:07,001 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDQ4ZjdmNzctOTMxMGM2ZWEtOWM0ZGFhMTYtODI3YzYxNzM=
2025-11-11 15:39:07,002 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OTMwMmMwNTEtNDBlYzEwYzQtNGQ0Y2YxYzYtOTNjYTVjZWI=
2025-11-11 15:39:07,007 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODc3YmViZjAtZWJmYzcwNTItZTMyZTE4NzItMzNkYWRkYjI=
2025-11-11 15:39:07,010 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZmJkM2E0YWItYzU5YWM2MmUtYzUzYjJlNTYtM2ZiYmY2MzA=
2025-11-11 15:39:07,010 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjM5MjdhMGYtY2NlYmE1MDctOWM3MjI3NGEtOWMzMDVjZTA=
2025-11-11 15:39:07,011 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZWQ4MzM4YmQtOTAyZmI2NmItYzFiZTNmODUtZDVmNTVjZTI=
2025-11-11 15:39:07,012 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OWY3MjIxNzEtYmMxOTc5YTYtMmExNTJlMGMtMzcxNzRlYmM=
2025-11-11 15:39:07,018 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmNjYjZkMWItMjJkNTUwN2YtYTU4ZjgwNmUtY2E2YjZlNzU=
2025-11-11 15:39:07,019 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:07,023 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e93a1d8a-4e74-4ff3-869b-8e0dcae9948c, ghrun-3ynj4chmly.auto.internal:22586): creating call state
2025-11-11 15:39:07,024 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e93a1d8a-4e74-4ff3-869b-8e0dcae9948c, ghrun-3ynj4chmly.auto.internal:22586): request = { session_id: "ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "select count(*) as Rows from `log`" } stats_mode: STATS_MODE_NONE }
2025-11-11 15:39:07,025 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e93a1d8a-4e74-4ff3-869b-8e0dcae9948c, ghrun-3ynj4chmly.auto.internal:22586): response = { <_MultiThreadedRendezvous object> }
2025-11-11 15:39:07,404 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjJkNTI5YWEtNWE5ZjdlNTQtZjIzMjNmOGMtNWUwZWVhZjk=
2025-11-11 15:39:07,404 - INFO - root - test_log_deviation: check insert: 15000 10000
2025-11-11 15:39:07,405 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.4
2025-11-11 15:39:07,406 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.4
2025-11-11 15:39:07,406 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/iofl/001ef6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:22586', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-11 15:39:07,421 - DEBUG - ya.test - execute: Command pid: 892056
2025-11-11 15:39:08,044 - DEBUG - ya.test - _save_outputs: Command (pid 892056) rc: 0
2025-11-11 15:39:08,045 - DEBUG - ya.test - _save_outputs: Command (pid 892056) elapsed time (sec): 0.621929407119751
2025-11-11 15:39:08,045 - DEBUG - ya.test - _save_outputs: Command (pid 892056) idrss: 0
2025-11-11 15:39:08,045 - DEBUG - ya.test - _save_outputs: Command (pid 892056) inblock: 0
2025-11-11 15:39:08,045 - DEBUG - ya.test - _save_outputs: Command (pid 892056) isrss: 0
2025-11-11 15:39:08,046 - DEBUG - ya.test - _save_outputs: Command (pid 892056) ixrss: 0
2025-11-11 15:39:08,046 - DEBUG - ya.test - _save_outputs: Command (pid 892056) majflt: 0
2025-11-11 15:39:08,046 - DEBUG - ya.test - _save_outputs: Command (pid 892056) maxrss: 474620
2025-11-11 15:39:08,046 - DEBUG - ya.test - _save_outputs: Command (pid 892056) minflt: 3534
2025-11-11 15:39:08,046 - DEBUG - ya.test - _save_outputs: Command (pid 892056) msgrcv: 0
2025-11-11 15:39:08,046 - DEBUG - ya.test - _save_outputs: Command (pid 892056) msgsnd: 0
2025-11-11 15:39:08,047 - DEBUG - ya.test - _save_outputs: Command (pid 892056) nivcsw: 54
2025-11-11 15:39:08,047 - DEBUG - ya.test - _save_outputs: Command (pid 892056) nsignals: 0
2025-11-11 15:39:08,051 - DEBUG - ya.test - _save_outputs: Command (pid 892056) nswap: 0
2025-11-11 15:39:08,052 - DEBUG - ya.test - _save_outputs: Command (pid 892056) nvcsw: 106
2025-11-11 15:39:08,052 - DEBUG - ya.test - _save_outputs: Command (pid 892056) oublock: 8
2025-11-11 15:39:08,052 - DEBUG - ya.test - _save_outputs: Command (pid 892056) stime: 0.01986
2025-11-11 15:39:08,052 - DEBUG - ya.test - _save_outputs: Command (pid 892056) utime: 0.064206
2025-11-11 15:39:08,052 - DEBUG - ya.test - _save_outputs: Command (pid 892056) wtime: 0.637
2025-11-11 15:39:08,053 - DEBUG - ya.test - _save_outputs: Command (pid 892056) output:
Remove path log...
Remove path log...Ok

2025-11-11 15:39:08,053 - DEBUG - ya.test - _save_outputs: Command (pid 892056) errors:

2025-11-11 15:39:08,054 - INFO - ya.test - pytest_runtest_teardown: Test teardown
