2025-11-01 16:45:20,468 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-01 16:45:20,468 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[1051200]
2025-11-01 16:45:20,468 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-01 16:45:20,468 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-01 16:45:20,471 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.3
2025-11-01 16:45:20,472 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.3
2025-11-01 16:45:20,473 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-01 16:45:20,474 - DEBUG - ya.test - execute: Command pid: 3035416
2025-11-01 16:45:21,115 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) rc: 0
2025-11-01 16:45:21,115 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) elapsed time (sec): 0.6397984027862549
2025-11-01 16:45:21,115 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) idrss: 0
2025-11-01 16:45:21,118 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) inblock: 0
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) isrss: 0
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) ixrss: 0
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) majflt: 0
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) maxrss: 538512
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) minflt: 16137
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) msgrcv: 0
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) msgsnd: 0
2025-11-01 16:45:21,119 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) nivcsw: 81
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) nsignals: 0
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) nswap: 0
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) nvcsw: 23
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) oublock: 8
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) stime: 0.361076
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) utime: 0.111622
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) wtime: 0.641
2025-11-01 16:45:21,120 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) output:
Git info:
    Commit: 34ddad56c8a7bb530ecf731d374c04f98d3d2aca
    Branch: 
    Author: azevaykin <145343289+azevaykin@users.noreply.github.com>
    Summary: Merge f53a17d638f4ee7a8f08354cd76c33a88c4925c5 into 5dbd26ce2068671edb74bb9f072505a44ea73d1e

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

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

2025-11-01 16:45:21,121 - DEBUG - ya.test - _save_outputs: Command (pid 3035416) errors:

2025-11-01 16:45:21,121 - INFO - __tests__.test_log_scenario - _setup_ydb: Git info:
    Commit: 34ddad56c8a7bb530ecf731d374c04f98d3d2aca
    Branch: 
    Author: azevaykin <145343289+azevaykin@users.noreply.github.com>
    Summary: Merge f53a17d638f4ee7a8f08354cd76c33a88c4925c5 into 5dbd26ce2068671edb74bb9f072505a44ea73d1e

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

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

2025-11-01 16:45:21,222 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd
2025-11-01 16:45:21,223 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/7508
2025-11-01 16:45:21,224 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/q6a6/0020b8/r3tmp/kikimr_cluster_sagsj0lj
2025-11-01 16:45:21,262 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd
2025-11-01 16:45:21,263 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/10083
2025-11-01 16:45:21,263 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13186
2025-11-01 16:45:21,264 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/26804
2025-11-01 16:45:21,264 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/19808
2025-11-01 16:45:21,265 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/q6a6/0020b8/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-01 16:45:21,265 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/q6a6/0020b8/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/q6a6/0020b8/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_e9jf4_y7.log --grpc-port=10083 --mon-port=13186 --ic-port=7508
2025-11-01 16:45:21,265 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:10083/1, disk_size 68719476736
2025-11-01 16:45:21,265 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/q6a6/0020b8/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-01 16:45:21,266 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/q6a6/0020b8/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/q6a6/0020b8/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_e9jf4_y7.log --grpc-port=10083 --mon-port=13186 --ic-port=7508
2025-11-01 16:45:21,266 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/q6a6/0020b8/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/q6a6/0020b8/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_e9jf4_y7.log', '--grpc-port=10083', '--mon-port=13186', '--ic-port=7508')' in '/home/runner/.ya/build/build_root/q6a6/0020b8/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-01 16:45:21,268 - DEBUG - ya.test - execute: Command pid: 3035953
2025-11-01 16:45:21,268 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:10083/1
2025-11-01 16:45:21,269 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.4
2025-11-01 16:45:21,270 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.4
2025-11-01 16:45:21,270 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-01 16:45:21,274 - DEBUG - ya.test - execute: Command pid: 3035955
2025-11-01 16:45:21,770 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) rc: 0
2025-11-01 16:45:21,771 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) elapsed time (sec): 0.49524450302124023
2025-11-01 16:45:21,771 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) idrss: 0
2025-11-01 16:45:21,772 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) inblock: 0
2025-11-01 16:45:21,772 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) isrss: 0
2025-11-01 16:45:21,772 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) ixrss: 0
2025-11-01 16:45:21,773 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) majflt: 0
2025-11-01 16:45:21,773 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) maxrss: 538512
2025-11-01 16:45:21,773 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) minflt: 16130
2025-11-01 16:45:21,773 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) msgrcv: 0
2025-11-01 16:45:21,773 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) msgsnd: 0
2025-11-01 16:45:21,773 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) nivcsw: 81
2025-11-01 16:45:21,774 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) nsignals: 0
2025-11-01 16:45:21,774 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) nswap: 0
2025-11-01 16:45:21,774 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) nvcsw: 14
2025-11-01 16:45:21,774 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) oublock: 8
2025-11-01 16:45:21,783 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) stime: 0.28102499999999997
2025-11-01 16:45:21,783 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) utime: 0.128469
2025-11-01 16:45:21,783 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) wtime: 0.5
2025-11-01 16:45:21,783 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) output:
Git info:
    Commit: 34ddad56c8a7bb530ecf731d374c04f98d3d2aca
    Branch: 
    Author: azevaykin <145343289+azevaykin@users.noreply.github.com>
    Summary: Merge f53a17d638f4ee7a8f08354cd76c33a88c4925c5 into 5dbd26ce2068671edb74bb9f072505a44ea73d1e

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

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

2025-11-01 16:45:21,783 - DEBUG - ya.test - _save_outputs: Command (pid 3035955) errors:

2025-11-01 16:45:21,785 - INFO - ydb.tests.library.harness.kikimr_runner - start: Node 1 version:
Git info:
    Commit: 34ddad56c8a7bb530ecf731d374c04f98d3d2aca
    Branch: 
    Author: azevaykin <145343289+azevaykin@users.noreply.github.com>
    Summary: Merge f53a17d638f4ee7a8f08354cd76c33a88c4925c5 into 5dbd26ce2068671edb74bb9f072505a44ea73d1e
2025-11-01 16:45:23,694 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd
2025-11-01 16:45:23,694 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10083', '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: 7508\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-01 16:45:23,695 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.5
2025-11-01 16:45:23,697 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.5
2025-11-01 16:45:23,697 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10083', '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: 7508\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-01 16:45:23,698 - DEBUG - ya.test - execute: Command pid: 3037535
2025-11-01 16:45:24,182 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) rc: 0
2025-11-01 16:45:24,182 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) elapsed time (sec): 0.4829425811767578
2025-11-01 16:45:24,182 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) idrss: 0
2025-11-01 16:45:24,183 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) inblock: 0
2025-11-01 16:45:24,183 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) isrss: 0
2025-11-01 16:45:24,183 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) ixrss: 0
2025-11-01 16:45:24,183 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) majflt: 0
2025-11-01 16:45:24,183 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) maxrss: 546964
2025-11-01 16:45:24,184 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) minflt: 18271
2025-11-01 16:45:24,184 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) msgrcv: 0
2025-11-01 16:45:24,184 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) msgsnd: 0
2025-11-01 16:45:24,184 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) nivcsw: 75
2025-11-01 16:45:24,184 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) nsignals: 0
2025-11-01 16:45:24,184 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) nswap: 0
2025-11-01 16:45:24,185 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) nvcsw: 121
2025-11-01 16:45:24,185 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) oublock: 8
2025-11-01 16:45:24,185 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) stime: 0.241947
2025-11-01 16:45:24,185 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) utime: 0.123469
2025-11-01 16:45:24,186 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) wtime: 0.484
2025-11-01 16:45:24,186 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2025-11-01 16:45:24,197 - DEBUG - ya.test - _save_outputs: Command (pid 3037535) errors:

2025-11-01 16:45:24,198 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd
2025-11-01 16:45:24,198 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10083', '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-01 16:45:24,201 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.6
2025-11-01 16:45:24,205 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.6
2025-11-01 16:45:24,205 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:10083', '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-01 16:45:24,206 - DEBUG - ya.test - execute: Command pid: 3037678
2025-11-01 16:45:24,629 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) rc: 0
2025-11-01 16:45:24,629 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) elapsed time (sec): 0.4220855236053467
2025-11-01 16:45:24,629 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) idrss: 0
2025-11-01 16:45:24,630 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) inblock: 0
2025-11-01 16:45:24,630 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) isrss: 0
2025-11-01 16:45:24,631 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) ixrss: 0
2025-11-01 16:45:24,631 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) majflt: 0
2025-11-01 16:45:24,631 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) maxrss: 546988
2025-11-01 16:45:24,633 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) minflt: 18272
2025-11-01 16:45:24,633 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) msgrcv: 0
2025-11-01 16:45:24,633 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) msgsnd: 0
2025-11-01 16:45:24,633 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) nivcsw: 120
2025-11-01 16:45:24,633 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) nsignals: 0
2025-11-01 16:45:24,634 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) nswap: 0
2025-11-01 16:45:24,634 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) nvcsw: 123
2025-11-01 16:45:24,634 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) oublock: 8
2025-11-01 16:45:24,634 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) stime: 0.228796
2025-11-01 16:45:24,634 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) utime: 0.132217
2025-11-01 16:45:24,635 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) wtime: 0.423
2025-11-01 16:45:24,635 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-01 16:45:24,636 - DEBUG - ya.test - _save_outputs: Command (pid 3037678) errors:

2025-11-01 16:45:24,636 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-11-01 16:45:24,661 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-01 16:45:24,674 - 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-01 16:45:24,676 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-01 16:45:24,677 - 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-01 16:45:24,682 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-01 16:45:24,682 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, ccc5aed1-154b-4575-a779-3def8611d2e5, localhost:10083): creating call state
2025-11-01 16:45:24,682 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, ccc5aed1-154b-4575-a779-3def8611d2e5, localhost:10083): request = { database: "/Root" }
2025-11-01 16:45:24,686 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, ccc5aed1-154b-4575-a779-3def8611d2e5, localhost:10083): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-tvlw7frnpa.auto.internal" port: 10083 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-01 16:45:24,686 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-tvlw7frnpa.auto.internal:10083, location 1, ssl: False>]>
2025-11-01 16:45:24,687 - 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-01 16:45:24,702 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:10083
2025-11-01 16:45:24,704 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[1051200])
2025-11-01 16:45:24,705 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb
2025-11-01 16:45:24,705 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-01 16:45:24,706 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out
2025-11-01 16:45:24,707 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err
2025-11-01 16:45:24,707 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-01 16:45:24,708 - DEBUG - ya.test - execute: Command pid: 3037887
2025-11-01 16:45:25,168 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) rc: 0
2025-11-01 16:45:25,169 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) elapsed time (sec): 0.45769619941711426
2025-11-01 16:45:25,169 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) idrss: 0
2025-11-01 16:45:25,186 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) inblock: 0
2025-11-01 16:45:25,194 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) isrss: 0
2025-11-01 16:45:25,194 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) ixrss: 0
2025-11-01 16:45:25,196 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) majflt: 0
2025-11-01 16:45:25,196 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) maxrss: 169160
2025-11-01 16:45:25,198 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) minflt: 3546
2025-11-01 16:45:25,200 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) msgrcv: 0
2025-11-01 16:45:25,201 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) msgsnd: 0
2025-11-01 16:45:25,201 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) nivcsw: 31
2025-11-01 16:45:25,204 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) nsignals: 0
2025-11-01 16:45:25,204 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) nswap: 0
2025-11-01 16:45:25,204 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) nvcsw: 176
2025-11-01 16:45:25,211 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) oublock: 8
2025-11-01 16:45:25,211 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) stime: 0.032365
2025-11-01 16:45:25,211 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) utime: 0.046557999999999995
2025-11-01 16:45:25,212 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) wtime: 0.459
2025-11-01 16:45:25,212 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) output:
Init tables ...
Init tables ...Ok

2025-11-01 16:45:25,212 - DEBUG - ya.test - _save_outputs: Command (pid 3037887) errors:

2025-11-01 16:45:25,212 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 0 < 100, will create new one.
2025-11-01 16:45:25,214 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 09bfb2b1-254e-4038-b915-59136b13b1c2, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:25,224 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 09bfb2b1-254e-4038-b915-59136b13b1c2, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:25,228 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 09bfb2b1-254e-4038-b915-59136b13b1c2, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" node_id: 1 }
2025-11-01 16:45:25,229 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 0b8dd469-db25-4157-87d5-fb708e9ba568, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:25,240 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 0b8dd469-db25-4157-87d5-fb708e9ba568, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" }
2025-11-01 16:45:25,245 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 0b8dd469-db25-4157-87d5-fb708e9ba568, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:25,254 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:25,255 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2a3ad4a1-f0c2-4080-a718-7b4db0f73a22, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:25,256 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2a3ad4a1-f0c2-4080-a718-7b4db0f73a22, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" 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-01 16:45:25,260 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2a3ad4a1-f0c2-4080-a718-7b4db0f73a22, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:25,290 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:25,290 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-01 16:45:25,290 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-01 16:45:25,292 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.0
2025-11-01 16:45:25,293 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.0
2025-11-01 16:45:25,294 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-01 16:45:25,305 - DEBUG - ya.test - execute: Command pid: 3038303
2025-11-01 16:45:29,258 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:45:29,259 - DEBUG - ya.test - _save_outputs: Command (pid 3038303) rc: 0
2025-11-01 16:45:29,267 - DEBUG - ya.test - _save_outputs: Command (pid 3038303) elapsed time (sec): 3.9531726837158203
2025-11-01 16:45:29,279 - DEBUG - ya.test - _save_outputs: Command (pid 3038303) wtime: 3.964
2025-11-01 16:45:29,280 - DEBUG - ya.test - _save_outputs: Command (pid 3038303) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	     10	10	0	0	567	763	763	763
2	     17	17	0	0	607	679	679	679
3	     22	22	0	0	767	851	871	871

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     49	16.3333	0	0	671	851	871	871

2025-11-01 16:45:29,280 - DEBUG - ya.test - _save_outputs: Command (pid 3038303) errors:

2025-11-01 16:45:29,280 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:29,282 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, de22b647-8114-4e82-9eb2-8d7caa166d26, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:29,283 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, de22b647-8114-4e82-9eb2-8d7caa166d26, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" 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-01 16:45:29,284 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, de22b647-8114-4e82-9eb2-8d7caa166d26, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:29,719 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:29,719 - INFO - root - test_log_deviation: Count rows after insert 24500 before wait
2025-11-01 16:45:29,720 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:29,721 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6bf07c54-106f-442c-8354-d3ce27d3cdbe, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:29,722 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6bf07c54-106f-442c-8354-d3ce27d3cdbe, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" 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-01 16:45:29,722 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6bf07c54-106f-442c-8354-d3ce27d3cdbe, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:29,988 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:29,994 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:29,995 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f1901fef-a500-4dbd-b280-5655eeb98192, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:29,995 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f1901fef-a500-4dbd-b280-5655eeb98192, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" 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-01 16:45:29,996 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f1901fef-a500-4dbd-b280-5655eeb98192, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,267 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:30,268 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-01 16:45:30,269 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-01 16:45:30,270 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.1
2025-11-01 16:45:30,270 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.1
2025-11-01 16:45:30,271 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-01 16:45:30,274 - DEBUG - ya.test - execute: Command pid: 3041558
2025-11-01 16:45:30,275 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-01 16:45:30,276 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-01 16:45:30,285 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-01 16:45:30,286 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.2
2025-11-01 16:45:30,277 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:30,286 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.2
2025-11-01 16:45:30,280 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb -e grpc://localhost:10083 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-01 16:45:30,289 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e90c61a6-aa16-48fc-9125-da608165810e, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,289 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 1 < 100, will create new one.
2025-11-01 16:45:30,291 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e90c61a6-aa16-48fc-9125-da608165810e, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,291 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-01 16:45:30,292 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, fe7cec29-04a6-4bff-a3fe-677e36e85a66, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,293 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.3
2025-11-01 16:45:30,299 - DEBUG - ya.test - execute: Command pid: 3041572
2025-11-01 16:45:30,299 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e90c61a6-aa16-48fc-9125-da608165810e, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,300 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, fe7cec29-04a6-4bff-a3fe-677e36e85a66, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,302 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.3
2025-11-01 16:45:30,304 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-01 16:45:30,311 - DEBUG - ya.test - execute: Command pid: 3041573
2025-11-01 16:45:30,312 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, fe7cec29-04a6-4bff-a3fe-677e36e85a66, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" node_id: 1 }
2025-11-01 16:45:30,313 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 6b6f63a4-a0c1-47f0-a34a-265443a78287, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,313 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 6b6f63a4-a0c1-47f0-a34a-265443a78287, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" }
2025-11-01 16:45:30,315 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 6b6f63a4-a0c1-47f0-a34a-265443a78287, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,317 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:30,320 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 3e2b0b8f-be65-48c5-a2be-a1f560f6f522, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,320 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 3e2b0b8f-be65-48c5-a2be-a1f560f6f522, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,321 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 3e2b0b8f-be65-48c5-a2be-a1f560f6f522, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,320 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 2 < 100, will create new one.
2025-11-01 16:45:30,322 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 980abdaf-68da-400c-a616-3b20d34a451d, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,323 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 980abdaf-68da-400c-a616-3b20d34a451d, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,326 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 980abdaf-68da-400c-a616-3b20d34a451d, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" node_id: 1 }
2025-11-01 16:45:30,326 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, a390a082-06d5-4483-8087-b189e4ffa2c1, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,327 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, a390a082-06d5-4483-8087-b189e4ffa2c1, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" }
2025-11-01 16:45:30,327 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, a390a082-06d5-4483-8087-b189e4ffa2c1, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,329 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:30,330 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b77926ac-e3c3-4640-967b-44e8ab98bd9b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,330 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 3 < 100, will create new one.
2025-11-01 16:45:30,335 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, b8c5783d-85b3-4eb5-abb2-0261d4129c42, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,334 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b77926ac-e3c3-4640-967b-44e8ab98bd9b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,335 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, b8c5783d-85b3-4eb5-abb2-0261d4129c42, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,336 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b77926ac-e3c3-4640-967b-44e8ab98bd9b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,339 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, b8c5783d-85b3-4eb5-abb2-0261d4129c42, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" node_id: 1 }
2025-11-01 16:45:30,339 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 0b3bd356-3e26-49ea-86a0-2d94fd6a04fc, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,340 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 0b3bd356-3e26-49ea-86a0-2d94fd6a04fc, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" }
2025-11-01 16:45:30,340 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 0b3bd356-3e26-49ea-86a0-2d94fd6a04fc, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,342 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:30,343 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a926c495-05a9-4786-9093-25a2dd7856e2, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,344 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a926c495-05a9-4786-9093-25a2dd7856e2, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,345 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a926c495-05a9-4786-9093-25a2dd7856e2, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,346 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 4 < 100, will create new one.
2025-11-01 16:45:30,347 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, c2222e23-2d43-49ed-ab92-8a5d8e5c68be, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,347 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, c2222e23-2d43-49ed-ab92-8a5d8e5c68be, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,353 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, c2222e23-2d43-49ed-ab92-8a5d8e5c68be, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" node_id: 1 }
2025-11-01 16:45:30,354 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, d9e601bd-ffd5-4a44-8ba9-40fbda78a792, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,354 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, d9e601bd-ffd5-4a44-8ba9-40fbda78a792, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" }
2025-11-01 16:45:30,356 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, d9e601bd-ffd5-4a44-8ba9-40fbda78a792, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,357 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:30,358 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1dde2d1d-6c88-422d-85bf-be567db02453, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,359 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1dde2d1d-6c88-422d-85bf-be567db02453, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,358 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 5 < 100, will create new one.
2025-11-01 16:45:30,360 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1dde2d1d-6c88-422d-85bf-be567db02453, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,361 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 9f50c0e8-58a0-4a95-b125-ad5f2c83f303, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,362 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 9f50c0e8-58a0-4a95-b125-ad5f2c83f303, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,404 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 9f50c0e8-58a0-4a95-b125-ad5f2c83f303, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" node_id: 1 }
2025-11-01 16:45:30,405 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 46d970e6-cc53-405e-bb2a-d4b091cae0cf, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,405 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 46d970e6-cc53-405e-bb2a-d4b091cae0cf, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" }
2025-11-01 16:45:30,409 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 46d970e6-cc53-405e-bb2a-d4b091cae0cf, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,427 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:30,428 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a3bc633b-d25c-42a8-9827-0dfad3b62c21, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,428 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a3bc633b-d25c-42a8-9827-0dfad3b62c21, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,429 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a3bc633b-d25c-42a8-9827-0dfad3b62c21, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,430 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 6 < 100, will create new one.
2025-11-01 16:45:30,430 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 42bd6210-89b1-497e-9d26-4d227b9e1e06, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,430 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 42bd6210-89b1-497e-9d26-4d227b9e1e06, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,455 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 42bd6210-89b1-497e-9d26-4d227b9e1e06, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" node_id: 1 }
2025-11-01 16:45:30,456 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 93f15d67-7f56-4f20-906b-d745cdc447bf, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,457 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 93f15d67-7f56-4f20-906b-d745cdc447bf, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" }
2025-11-01 16:45:30,458 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 93f15d67-7f56-4f20-906b-d745cdc447bf, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,480 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:45:30,480 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4ac26d81-e097-4575-a4c4-13debcd5b94b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,482 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4ac26d81-e097-4575-a4c4-13debcd5b94b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,483 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4ac26d81-e097-4575-a4c4-13debcd5b94b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,484 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 7 < 100, will create new one.
2025-11-01 16:45:30,492 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, d3ed264a-ed95-43e0-99fa-6fc24372a3d3, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,492 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, d3ed264a-ed95-43e0-99fa-6fc24372a3d3, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,526 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, d3ed264a-ed95-43e0-99fa-6fc24372a3d3, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" node_id: 1 }
2025-11-01 16:45:30,527 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, d2cf79e5-4aee-4880-96c8-96363c8c1ca8, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,528 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, d2cf79e5-4aee-4880-96c8-96363c8c1ca8, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" }
2025-11-01 16:45:30,532 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, d2cf79e5-4aee-4880-96c8-96363c8c1ca8, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,583 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:45:30,583 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c07ea9d7-af3f-4e1d-bd1b-d1c51feff45b, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,584 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c07ea9d7-af3f-4e1d-bd1b-d1c51feff45b, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,585 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c07ea9d7-af3f-4e1d-bd1b-d1c51feff45b, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,585 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 8 < 100, will create new one.
2025-11-01 16:45:30,585 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 677efe2a-5517-4bb8-8393-65d6df5b5a2c, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,586 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 677efe2a-5517-4bb8-8393-65d6df5b5a2c, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,616 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 677efe2a-5517-4bb8-8393-65d6df5b5a2c, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" node_id: 1 }
2025-11-01 16:45:30,630 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 2d562f5d-11e9-4954-986d-301fd1ab94ab, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,634 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 2d562f5d-11e9-4954-986d-301fd1ab94ab, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" }
2025-11-01 16:45:30,635 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 2d562f5d-11e9-4954-986d-301fd1ab94ab, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,666 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:30,667 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ae44508b-3b27-45c7-a92d-2acad4f37e31, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,667 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ae44508b-3b27-45c7-a92d-2acad4f37e31, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,675 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ae44508b-3b27-45c7-a92d-2acad4f37e31, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,668 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 9 < 100, will create new one.
2025-11-01 16:45:30,683 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 1574e01c-c830-4f53-8d60-c151e4d7a820, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,690 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 1574e01c-c830-4f53-8d60-c151e4d7a820, ghrun-tvlw7frnpa.auto.internal:10083): request = {  }
2025-11-01 16:45:30,799 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 1574e01c-c830-4f53-8d60-c151e4d7a820, ghrun-tvlw7frnpa.auto.internal:10083): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" node_id: 1 }
2025-11-01 16:45:30,803 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, f8fb6924-5cb1-4f8b-971f-9d137a7a7ed7, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,803 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, f8fb6924-5cb1-4f8b-971f-9d137a7a7ed7, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" }
2025-11-01 16:45:30,804 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, f8fb6924-5cb1-4f8b-971f-9d137a7a7ed7, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:30,857 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:45:30,858 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 05467ec2-de24-4c29-bf36-9f5f8417c93c, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:30,858 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 05467ec2-de24-4c29-bf36-9f5f8417c93c, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:30,859 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 05467ec2-de24-4c29-bf36-9f5f8417c93c, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:35,232 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:45:35,232 - DEBUG - ya.test - _save_outputs: Command (pid 3041572) rc: 0
2025-11-01 16:45:35,233 - DEBUG - ya.test - _save_outputs: Command (pid 3041572) elapsed time (sec): 4.929783821105957
2025-11-01 16:45:35,233 - DEBUG - ya.test - _save_outputs: Command (pid 3041572) wtime: 4.938
2025-11-01 16:45:35,233 - DEBUG - ya.test - _save_outputs: Command (pid 3041572) 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	14	0	0	0	0

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

2025-11-01 16:45:35,234 - DEBUG - ya.test - _save_outputs: Command (pid 3041572) errors:

2025-11-01 16:45:35,242 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:45:35,243 - DEBUG - ya.test - _save_outputs: Command (pid 3041573) rc: 0
2025-11-01 16:45:35,243 - DEBUG - ya.test - _save_outputs: Command (pid 3041573) elapsed time (sec): 4.9303529262542725
2025-11-01 16:45:35,243 - DEBUG - ya.test - _save_outputs: Command (pid 3041573) wtime: 4.938
2025-11-01 16:45:35,243 - DEBUG - ya.test - _save_outputs: Command (pid 3041573) 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	16	0	0	0	0

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

2025-11-01 16:45:35,244 - DEBUG - ya.test - _save_outputs: Command (pid 3041573) errors:

2025-11-01 16:45:39,322 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:39,324 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:39,328 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:39,330 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bc879e9c-d4a2-4fc4-9a8e-7afc510c1c61, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,331 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bc879e9c-d4a2-4fc4-9a8e-7afc510c1c61, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:39,332 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bc879e9c-d4a2-4fc4-9a8e-7afc510c1c61, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,330 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:39,333 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 03d20f7e-62c0-4034-9195-173e36f24118, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,334 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 03d20f7e-62c0-4034-9195-173e36f24118, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:39,335 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:39,337 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:39,330 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:39,336 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 03d20f7e-62c0-4034-9195-173e36f24118, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,338 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9a21e068-12eb-427f-a1bd-5c7f37788714, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,338 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:39,339 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9a21e068-12eb-427f-a1bd-5c7f37788714, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" 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-01 16:45:39,343 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9eff2d78-849d-4007-bfa8-a95261ea62a8, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,349 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9eff2d78-849d-4007-bfa8-a95261ea62a8, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" 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-01 16:45:39,348 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9a21e068-12eb-427f-a1bd-5c7f37788714, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,347 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:39,351 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:39,351 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9be6cb70-2f45-4aba-9473-cb7524da4ecc, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,351 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9be6cb70-2f45-4aba-9473-cb7524da4ecc, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:39,352 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9be6cb70-2f45-4aba-9473-cb7524da4ecc, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,350 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9eff2d78-849d-4007-bfa8-a95261ea62a8, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,354 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:45:39,359 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:45:39,361 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b83b4ba1-f462-4202-b262-95f89bab53d7, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,362 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b83b4ba1-f462-4202-b262-95f89bab53d7, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:39,362 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b83b4ba1-f462-4202-b262-95f89bab53d7, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,387 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:39,388 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:39,388 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0c0c0088-dec7-4653-b3a6-06d6640e4b83, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,389 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0c0c0088-dec7-4653-b3a6-06d6640e4b83, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:39,390 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0c0c0088-dec7-4653-b3a6-06d6640e4b83, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,444 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:39,444 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:39,445 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 71feb9e6-58f3-40d5-8e02-40166aa207f0, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,445 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 71feb9e6-58f3-40d5-8e02-40166aa207f0, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" 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-01 16:45:39,446 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 71feb9e6-58f3-40d5-8e02-40166aa207f0, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,451 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:45:39,451 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:45:39,452 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 79e15836-fd1a-4a8a-834b-6dc0977f8384, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,452 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 79e15836-fd1a-4a8a-834b-6dc0977f8384, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" 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-01 16:45:39,453 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 79e15836-fd1a-4a8a-834b-6dc0977f8384, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:39,495 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:45:39,496 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:45:39,496 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b36dda43-65b0-4f02-9684-768a9ca0d66e, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:39,506 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b36dda43-65b0-4f02-9684-768a9ca0d66e, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" 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-01 16:45:39,507 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b36dda43-65b0-4f02-9684-768a9ca0d66e, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:43,122 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-01 16:45:43,188 - DEBUG - ya.test - _save_outputs: Command (pid 3041558) rc: 0
2025-11-01 16:45:43,191 - DEBUG - ya.test - _save_outputs: Command (pid 3041558) elapsed time (sec): 12.846649408340454
2025-11-01 16:45:43,191 - DEBUG - ya.test - _save_outputs: Command (pid 3041558) wtime: 12.852
2025-11-01 16:45:43,191 - DEBUG - ya.test - _save_outputs: Command (pid 3041558) 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	     10	10	0	0	11135	12479	12479	12479

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

2025-11-01 16:45:43,191 - DEBUG - ya.test - _save_outputs: Command (pid 3041558) errors:

2025-11-01 16:45:53,184 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:53,310 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:53,323 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a5252081-a9bb-47e3-a372-c1940f7b646d, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:53,324 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a5252081-a9bb-47e3-a372-c1940f7b646d, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" 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-01 16:45:53,419 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a5252081-a9bb-47e3-a372-c1940f7b646d, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:54,186 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:54,187 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:54,187 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1a2fd209-4d50-4e3f-8950-a14ed6924fb9, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:54,211 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1a2fd209-4d50-4e3f-8950-a14ed6924fb9, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" 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-01 16:45:54,225 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1a2fd209-4d50-4e3f-8950-a14ed6924fb9, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:54,321 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:54,352 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:54,543 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:54,674 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a05673bc-90c7-4f34-93da-1366b4b339ad, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:54,674 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:54,675 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a05673bc-90c7-4f34-93da-1366b4b339ad, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" 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-01 16:45:54,684 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2a33791a-8198-40b3-970f-b351e78857ed, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:54,693 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:54,720 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:54,742 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2a33791a-8198-40b3-970f-b351e78857ed, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:54,744 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a05673bc-90c7-4f34-93da-1366b4b339ad, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:54,895 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:54,946 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9b85713d-8336-4844-9e41-b4572d9c48b1, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:54,944 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2a33791a-8198-40b3-970f-b351e78857ed, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:54,920 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:54,956 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9b85713d-8336-4844-9e41-b4572d9c48b1, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:55,211 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:55,460 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cf7295d1-1e12-420a-8169-f3bb613e71a3, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:55,472 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cf7295d1-1e12-420a-8169-f3bb613e71a3, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:55,474 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9b85713d-8336-4844-9e41-b4572d9c48b1, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:55,478 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cf7295d1-1e12-420a-8169-f3bb613e71a3, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:55,485 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:55,494 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:55,495 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7d670fd0-31ad-4a36-b502-86212c59f194, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:55,495 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7d670fd0-31ad-4a36-b502-86212c59f194, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" 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-01 16:45:55,496 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7d670fd0-31ad-4a36-b502-86212c59f194, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:55,516 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:55,533 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:55,540 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d3c24427-22e1-455c-bfea-19062d8bec5d, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:55,540 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d3c24427-22e1-455c-bfea-19062d8bec5d, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:55,561 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d3c24427-22e1-455c-bfea-19062d8bec5d, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:55,716 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:55,850 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:55,853 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:45:55,867 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 347ac200-c5ee-4b00-88b5-7c63638a5e8e, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:56,018 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:56,019 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 347ac200-c5ee-4b00-88b5-7c63638a5e8e, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(9)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:56,036 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ca656f4c-c2cf-4408-bc41-cfa36424a695, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:56,047 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 347ac200-c5ee-4b00-88b5-7c63638a5e8e, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:56,063 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ca656f4c-c2cf-4408-bc41-cfa36424a695, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" 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-01 16:45:56,070 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:56,076 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ca656f4c-c2cf-4408-bc41-cfa36424a695, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:56,077 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:45:56,247 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:45:56,407 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 993ca430-ee7f-41ad-ab55-1e1926e40ec9, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:56,408 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 993ca430-ee7f-41ad-ab55-1e1926e40ec9, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=" 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-01 16:45:56,408 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:56,422 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 993ca430-ee7f-41ad-ab55-1e1926e40ec9, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:56,423 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a781d4f7-23f6-45d2-99fc-766e4496b249, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:56,461 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a781d4f7-23f6-45d2-99fc-766e4496b249, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:56,493 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a781d4f7-23f6-45d2-99fc-766e4496b249, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:56,508 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:45:56,701 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:45:56,712 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2e35bf29-c25e-43bb-ae4d-186ac0e22800, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:56,717 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2e35bf29-c25e-43bb-ae4d-186ac0e22800, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=" 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-01 16:45:56,718 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2e35bf29-c25e-43bb-ae4d-186ac0e22800, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:57,743 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:58,912 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:58,917 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:58,932 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:45:58,933 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 849c956f-9080-45e4-95c3-2ed1e685c0e5, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:58,943 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 849c956f-9080-45e4-95c3-2ed1e685c0e5, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:58,945 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 849c956f-9080-45e4-95c3-2ed1e685c0e5, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:58,959 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:58,964 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:58,969 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:58,971 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:58,975 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 87b81945-f7fd-4b12-a4b6-ba81e667e38e, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:58,976 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:58,982 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:59,000 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjEyMDZhYWYtNjFlNGZkMjQtYTc4YzA2OGItZTIyOWQwYzc=
2025-11-01 16:45:59,001 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE0OTEzZDMtNzI2MjE0YjctNmM0ZjM2MWItNDRkMTIxODQ=
2025-11-01 16:45:59,005 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 74761437-1098-4705-8f56-77f1b5681c95, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:59,005 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:59,027 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c57f50b1-8786-49de-ad27-4fb682e23e36, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:59,017 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 74761437-1098-4705-8f56-77f1b5681c95, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(7)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6))" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:59,030 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 74761437-1098-4705-8f56-77f1b5681c95, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:59,028 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c57f50b1-8786-49de-ad27-4fb682e23e36, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4))" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:59,004 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 87b81945-f7fd-4b12-a4b6-ba81e667e38e, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=" 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-01 16:45:59,031 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c57f50b1-8786-49de-ad27-4fb682e23e36, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:59,028 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:59,080 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ecfaa5c6-d6b6-45e3-b26d-808b94442b95, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:59,080 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ecfaa5c6-d6b6-45e3-b26d-808b94442b95, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(9))" } stats_mode: STATS_MODE_NONE }
2025-11-01 16:45:59,072 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 87b81945-f7fd-4b12-a4b6-ba81e667e38e, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:59,081 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ecfaa5c6-d6b6-45e3-b26d-808b94442b95, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:59,083 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:59,093 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 44425293-b59d-4b25-89f8-43cf63d3e314, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:59,093 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:59,106 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 44425293-b59d-4b25-89f8-43cf63d3e314, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=" 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-01 16:45:59,113 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 363c113c-497e-4a70-b87e-b99c4168129c, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:59,115 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 44425293-b59d-4b25-89f8-43cf63d3e314, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:59,119 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 363c113c-497e-4a70-b87e-b99c4168129c, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=" 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-01 16:45:59,147 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 363c113c-497e-4a70-b87e-b99c4168129c, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:45:59,886 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=OGZhNWExZWUtNWRjYTZlMjctZmU5YmQyM2EtYzJkYmIzYzY=
2025-11-01 16:45:59,920 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTAwODk3ZjgtYzJlZjY3ODYtM2JjMzliZmItOTAxNDA2ZDk=
2025-11-01 16:45:59,921 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YjU2YmFmNDktYTU1YzIwZTUtYTIxNDE1NjQtN2RhOTM2NGI=
2025-11-01 16:45:59,922 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTcyMzhlMTAtNjYyODk0MjItYTZkYWJmZTItYmRjNWIxYWE=
2025-11-01 16:45:59,926 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NGVkODJlMGMtOTIwMmYyMTAtMzI1MzQ4NWQtYmE4ZjhjZTg=
2025-11-01 16:45:59,926 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmJlMWE2NTAtYjYxYTFiYjItMWIwZDUyZC04OGVhOTI3MQ==
2025-11-01 16:45:59,927 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NTVkMzgxMTItYTU4YzMzOGUtYmZlNTRmZTEtODMyNWVlOTU=
2025-11-01 16:45:59,940 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:45:59,941 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c545776b-41ff-4346-a80e-33a090656d4d, ghrun-tvlw7frnpa.auto.internal:10083): creating call state
2025-11-01 16:45:59,942 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c545776b-41ff-4346-a80e-33a090656d4d, ghrun-tvlw7frnpa.auto.internal:10083): request = { session_id: "ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==" 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-01 16:45:59,943 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c545776b-41ff-4346-a80e-33a090656d4d, ghrun-tvlw7frnpa.auto.internal:10083): response = { <_MultiThreadedRendezvous object> }
2025-11-01 16:46:00,314 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTFlYjE2ZDEtZGUzODg3ZGItYzhkOGJjYzctNzY2YTJlMA==
2025-11-01 16:46:00,315 - INFO - root - test_log_deviation: check insert: 29500 24500
2025-11-01 16:46:00,318 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.4
2025-11-01 16:46:00,325 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.4
2025-11-01 16:46:00,325 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/q6a6/0020b8/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:10083', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-01 16:46:00,327 - DEBUG - ya.test - execute: Command pid: 3053721
2025-11-01 16:46:00,567 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) rc: 0
2025-11-01 16:46:00,568 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) elapsed time (sec): 0.21796154975891113
2025-11-01 16:46:00,575 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) idrss: 0
2025-11-01 16:46:00,575 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) inblock: 0
2025-11-01 16:46:00,575 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) isrss: 0
2025-11-01 16:46:00,576 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) ixrss: 0
2025-11-01 16:46:00,576 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) majflt: 0
2025-11-01 16:46:00,576 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) maxrss: 909920
2025-11-01 16:46:00,576 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) minflt: 3552
2025-11-01 16:46:00,576 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) msgrcv: 0
2025-11-01 16:46:00,576 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) msgsnd: 0
2025-11-01 16:46:00,577 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) nivcsw: 41
2025-11-01 16:46:00,577 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) nsignals: 0
2025-11-01 16:46:00,577 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) nswap: 0
2025-11-01 16:46:00,577 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) nvcsw: 150
2025-11-01 16:46:00,577 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) oublock: 8
2025-11-01 16:46:00,578 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) stime: 0.0349
2025-11-01 16:46:00,578 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) utime: 0.047345
2025-11-01 16:46:00,578 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) wtime: 0.241
2025-11-01 16:46:00,580 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) output:
Remove path log...
Remove path log...Ok

2025-11-01 16:46:00,591 - DEBUG - ya.test - _save_outputs: Command (pid 3053721) errors:

2025-11-01 16:46:00,595 - INFO - ya.test - pytest_runtest_teardown: Test teardown
