2025-11-10 10:00:35,853 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-10 10:00:35,853 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[1051200]
2025-11-10 10:00:35,853 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-10 10:00:35,853 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-10 10:00:35,855 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.7
2025-11-10 10:00:35,855 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.7
2025-11-10 10:00:35,856 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-10 10:00:35,857 - DEBUG - ya.test - execute: Command pid: 1813715
2025-11-10 10:00:36,254 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) rc: 0
2025-11-10 10:00:36,255 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) elapsed time (sec): 0.397014856338501
2025-11-10 10:00:36,256 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) idrss: 0
2025-11-10 10:00:36,256 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) inblock: 0
2025-11-10 10:00:36,257 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) isrss: 0
2025-11-10 10:00:36,258 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) ixrss: 0
2025-11-10 10:00:36,259 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) majflt: 0
2025-11-10 10:00:36,259 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) maxrss: 541004
2025-11-10 10:00:36,259 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) minflt: 16172
2025-11-10 10:00:36,259 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) msgrcv: 0
2025-11-10 10:00:36,260 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) msgsnd: 0
2025-11-10 10:00:36,260 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) nivcsw: 3
2025-11-10 10:00:36,260 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) nsignals: 0
2025-11-10 10:00:36,260 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) nswap: 0
2025-11-10 10:00:36,260 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) nvcsw: 16
2025-11-10 10:00:36,261 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) oublock: 8
2025-11-10 10:00:36,261 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) stime: 0.229627
2025-11-10 10:00:36,261 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) utime: 0.11877199999999999
2025-11-10 10:00:36,261 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) wtime: 0.398
2025-11-10 10:00:36,261 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) output:
Git info:
    Commit: 2d3bc32bffc01725fa6c3dd0bb0f7616ee098760
    Branch: 
    Author: Daniil Timižev <ditimizhev@ydb.tech>
    Summary: Merge 4ff3894868fb9bba81a268efd022ca68496f230a into 27b8fe5960eec979164acf2636986bcea3ca729d

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-kipqlopw2q
    Host information: 
        Linux ghrun-kipqlopw2q 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-10 10:00:36,262 - DEBUG - ya.test - _save_outputs: Command (pid 1813715) errors:

2025-11-10 10:00:36,262 - INFO - __tests__.test_log_scenario - _setup_ydb: Git info:
    Commit: 2d3bc32bffc01725fa6c3dd0bb0f7616ee098760
    Branch: 
    Author: Daniil Timižev <ditimizhev@ydb.tech>
    Summary: Merge 4ff3894868fb9bba81a268efd022ca68496f230a into 27b8fe5960eec979164acf2636986bcea3ca729d

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-kipqlopw2q
    Host information: 
        Linux ghrun-kipqlopw2q 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-10 10:00:36,333 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd
2025-11-10 10:00:36,334 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/26088
2025-11-10 10:00:36,335 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/26088
2025-11-10 10:00:36,335 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/26089
2025-11-10 10:00:36,336 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/6t6o/0024e6/r3tmp/kikimr_cluster_hcdnlqei
2025-11-10 10:00:36,365 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd
2025-11-10 10:00:36,366 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1775
2025-11-10 10:00:36,366 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/18200
2025-11-10 10:00:36,366 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/7128
2025-11-10 10:00:36,367 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/3309
2025-11-10 10:00:36,367 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/6t6o/0024e6/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-10 10:00:36,367 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/6t6o/0024e6/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/6t6o/0024e6/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_4850eb49.log --grpc-port=1775 --mon-port=18200 --ic-port=26089
2025-11-10 10:00:36,368 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:1775/1, disk_size 68719476736
2025-11-10 10:00:36,368 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/6t6o/0024e6/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-10 10:00:36,368 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/6t6o/0024e6/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/6t6o/0024e6/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_4850eb49.log --grpc-port=1775 --mon-port=18200 --ic-port=26089
2025-11-10 10:00:36,369 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/6t6o/0024e6/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/6t6o/0024e6/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_4850eb49.log', '--grpc-port=1775', '--mon-port=18200', '--ic-port=26089')' in '/home/runner/.ya/build/build_root/6t6o/0024e6/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-10 10:00:36,370 - DEBUG - ya.test - execute: Command pid: 1814369
2025-11-10 10:00:36,371 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:1775/1
2025-11-10 10:00:36,372 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.8
2025-11-10 10:00:36,373 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.8
2025-11-10 10:00:36,373 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-10 10:00:36,374 - DEBUG - ya.test - execute: Command pid: 1814371
2025-11-10 10:00:36,767 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) rc: 0
2025-11-10 10:00:36,767 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) elapsed time (sec): 0.3920712471008301
2025-11-10 10:00:36,768 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) idrss: 0
2025-11-10 10:00:36,768 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) inblock: 0
2025-11-10 10:00:36,768 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) isrss: 0
2025-11-10 10:00:36,768 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) ixrss: 0
2025-11-10 10:00:36,768 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) majflt: 0
2025-11-10 10:00:36,769 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) maxrss: 541008
2025-11-10 10:00:36,769 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) minflt: 16173
2025-11-10 10:00:36,769 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) msgrcv: 0
2025-11-10 10:00:36,769 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) msgsnd: 0
2025-11-10 10:00:36,769 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) nivcsw: 7
2025-11-10 10:00:36,769 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) nsignals: 0
2025-11-10 10:00:36,770 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) nswap: 0
2025-11-10 10:00:36,770 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) nvcsw: 18
2025-11-10 10:00:36,770 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) oublock: 8
2025-11-10 10:00:36,770 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) stime: 0.227883
2025-11-10 10:00:36,770 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) utime: 0.115938
2025-11-10 10:00:36,771 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) wtime: 0.393
2025-11-10 10:00:36,771 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) output:
Git info:
    Commit: 2d3bc32bffc01725fa6c3dd0bb0f7616ee098760
    Branch: 
    Author: Daniil Timižev <ditimizhev@ydb.tech>
    Summary: Merge 4ff3894868fb9bba81a268efd022ca68496f230a into 27b8fe5960eec979164acf2636986bcea3ca729d

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-kipqlopw2q
    Host information: 
        Linux ghrun-kipqlopw2q 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-10 10:00:36,773 - DEBUG - ya.test - _save_outputs: Command (pid 1814371) errors:

2025-11-10 10:00:36,773 - INFO - ydb.tests.library.harness.kikimr_runner - start: Node 1 version:
Git info:
    Commit: 2d3bc32bffc01725fa6c3dd0bb0f7616ee098760
    Branch: 
    Author: Daniil Timižev <ditimizhev@ydb.tech>
    Summary: Merge 4ff3894868fb9bba81a268efd022ca68496f230a into 27b8fe5960eec979164acf2636986bcea3ca729d
2025-11-10 10:00:38,610 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd
2025-11-10 10:00:38,610 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:1775', '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: 26089\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-10 10:00:38,611 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.9
2025-11-10 10:00:38,612 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.9
2025-11-10 10:00:38,612 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:1775', '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: 26089\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-10 10:00:38,614 - DEBUG - ya.test - execute: Command pid: 1818385
2025-11-10 10:00:39,026 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) rc: 0
2025-11-10 10:00:39,026 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) elapsed time (sec): 0.41158556938171387
2025-11-10 10:00:39,027 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) idrss: 0
2025-11-10 10:00:39,027 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) inblock: 0
2025-11-10 10:00:39,027 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) isrss: 0
2025-11-10 10:00:39,027 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) ixrss: 0
2025-11-10 10:00:39,027 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) majflt: 0
2025-11-10 10:00:39,028 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) maxrss: 549256
2025-11-10 10:00:39,028 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) minflt: 18315
2025-11-10 10:00:39,028 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) msgrcv: 0
2025-11-10 10:00:39,028 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) msgsnd: 0
2025-11-10 10:00:39,029 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) nivcsw: 6
2025-11-10 10:00:39,029 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) nsignals: 0
2025-11-10 10:00:39,029 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) nswap: 0
2025-11-10 10:00:39,029 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) nvcsw: 139
2025-11-10 10:00:39,029 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) oublock: 8
2025-11-10 10:00:39,030 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) stime: 0.23185699999999998
2025-11-10 10:00:39,030 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) utime: 0.135042
2025-11-10 10:00:39,030 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) wtime: 0.413
2025-11-10 10:00:39,030 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2025-11-10 10:00:39,031 - DEBUG - ya.test - _save_outputs: Command (pid 1818385) errors:

2025-11-10 10:00:39,032 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd
2025-11-10 10:00:39,032 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:1775', '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-10 10:00:39,034 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.10
2025-11-10 10:00:39,034 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.10
2025-11-10 10:00:39,035 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:1775', '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-10 10:00:39,036 - DEBUG - ya.test - execute: Command pid: 1819227
2025-11-10 10:00:39,443 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) rc: 0
2025-11-10 10:00:39,444 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) elapsed time (sec): 0.40676212310791016
2025-11-10 10:00:39,444 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) idrss: 0
2025-11-10 10:00:39,444 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) inblock: 0
2025-11-10 10:00:39,445 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) isrss: 0
2025-11-10 10:00:39,445 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) ixrss: 0
2025-11-10 10:00:39,445 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) majflt: 0
2025-11-10 10:00:39,445 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) maxrss: 549268
2025-11-10 10:00:39,445 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) minflt: 18315
2025-11-10 10:00:39,445 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) msgrcv: 0
2025-11-10 10:00:39,446 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) msgsnd: 0
2025-11-10 10:00:39,446 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) nivcsw: 1
2025-11-10 10:00:39,446 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) nsignals: 0
2025-11-10 10:00:39,446 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) nswap: 0
2025-11-10 10:00:39,446 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) nvcsw: 135
2025-11-10 10:00:39,446 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) oublock: 8
2025-11-10 10:00:39,447 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) stime: 0.234118
2025-11-10 10:00:39,447 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) utime: 0.129168
2025-11-10 10:00:39,447 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) wtime: 0.408
2025-11-10 10:00:39,447 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-10 10:00:39,448 - DEBUG - ya.test - _save_outputs: Command (pid 1819227) errors:

2025-11-10 10:00:39,448 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-11-10 10:00:39,462 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-10 10:00:39,471 - 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-10 10:00:39,473 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-10 10:00:39,474 - 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-10 10:00:39,480 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-10 10:00:39,481 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, e8fb4d75-a44e-49c0-953f-8d1635489d6d, localhost:1775): creating call state
2025-11-10 10:00:39,481 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, e8fb4d75-a44e-49c0-953f-8d1635489d6d, localhost:1775): request = { database: "/Root" }
2025-11-10 10:00:39,485 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, e8fb4d75-a44e-49c0-953f-8d1635489d6d, localhost:1775): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-kipqlopw2q.auto.internal" port: 1775 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-10 10:00:39,485 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-kipqlopw2q.auto.internal:1775, location 1, ssl: False>]>
2025-11-10 10:00:39,486 - 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-10 10:00:39,496 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[1051200])
2025-11-10 10:00:39,496 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb
2025-11-10 10:00:39,496 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb -e grpc://localhost:1775 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-10 10:00:39,497 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out
2025-11-10 10:00:39,498 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err
2025-11-10 10:00:39,498 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:1775', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-10 10:00:39,499 - DEBUG - ya.test - execute: Command pid: 1820173
2025-11-10 10:00:39,858 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) rc: 0
2025-11-10 10:00:39,859 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) elapsed time (sec): 0.35878753662109375
2025-11-10 10:00:39,859 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) idrss: 0
2025-11-10 10:00:39,859 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) inblock: 0
2025-11-10 10:00:39,860 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) isrss: 0
2025-11-10 10:00:39,860 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) ixrss: 0
2025-11-10 10:00:39,860 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) majflt: 0
2025-11-10 10:00:39,860 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) maxrss: 174552
2025-11-10 10:00:39,861 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) minflt: 3536
2025-11-10 10:00:39,861 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) msgrcv: 0
2025-11-10 10:00:39,861 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) msgsnd: 0
2025-11-10 10:00:39,861 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) nivcsw: 1
2025-11-10 10:00:39,861 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) nsignals: 0
2025-11-10 10:00:39,862 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) nswap: 0
2025-11-10 10:00:39,862 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) nvcsw: 211
2025-11-10 10:00:39,862 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) oublock: 8
2025-11-10 10:00:39,862 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) stime: 0.028158
2025-11-10 10:00:39,862 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) utime: 0.048271999999999995
2025-11-10 10:00:39,863 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) wtime: 0.36
2025-11-10 10:00:39,863 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) output:
Init tables ...
Init tables ...Ok

2025-11-10 10:00:39,863 - DEBUG - ya.test - _save_outputs: Command (pid 1820173) errors:

2025-11-10 10:00:39,863 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 0 < 100, will create new one.
2025-11-10 10:00:39,864 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 8eaccb37-8814-48ae-8164-36061b6eb5dd, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:39,864 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 8eaccb37-8814-48ae-8164-36061b6eb5dd, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:39,867 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 8eaccb37-8814-48ae-8164-36061b6eb5dd, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" node_id: 1 }
2025-11-10 10:00:39,868 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 3fcde6ff-cc72-4cd5-9d2a-fddde9fc1a42, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:39,869 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 3fcde6ff-cc72-4cd5-9d2a-fddde9fc1a42, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" }
2025-11-10 10:00:39,870 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 3fcde6ff-cc72-4cd5-9d2a-fddde9fc1a42, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:39,872 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:39,872 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e5449ee2-0e71-41df-bd8d-d1ff1b2b276d, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:39,873 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e5449ee2-0e71-41df-bd8d-d1ff1b2b276d, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" 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-10 10:00:39,874 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e5449ee2-0e71-41df-bd8d-d1ff1b2b276d, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:39,902 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:39,902 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-10 10:00:39,903 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb -e grpc://localhost:1775 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-10 10:00:39,904 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.0
2025-11-10 10:00:39,904 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.0
2025-11-10 10:00:39,904 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:1775', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-10 10:00:39,905 - DEBUG - ya.test - execute: Command pid: 1821018
2025-11-10 10:00:43,511 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-10 10:00:43,512 - DEBUG - ya.test - _save_outputs: Command (pid 1821018) rc: 0
2025-11-10 10:00:43,512 - DEBUG - ya.test - _save_outputs: Command (pid 1821018) elapsed time (sec): 3.605825662612915
2025-11-10 10:00:43,512 - DEBUG - ya.test - _save_outputs: Command (pid 1821018) wtime: 3.607
2025-11-10 10:00:43,513 - DEBUG - ya.test - _save_outputs: Command (pid 1821018) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	     17	17	0	0	459	519	535	535
2	     17	17	0	0	519	555	559	559
3	     29	29	0	0	519	559	563	563

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	     63	21	0	0	503	555	559	563

2025-11-10 10:00:43,513 - DEBUG - ya.test - _save_outputs: Command (pid 1821018) errors:

2025-11-10 10:00:43,513 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:43,514 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b8ba5f8d-254d-4465-b44b-0225b3dc47e6, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:43,514 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b8ba5f8d-254d-4465-b44b-0225b3dc47e6, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" 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-10 10:00:43,515 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b8ba5f8d-254d-4465-b44b-0225b3dc47e6, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:43,833 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:43,833 - INFO - root - test_log_deviation: Count rows after insert 31493 before wait
2025-11-10 10:00:43,833 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:43,834 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c4a9b800-8842-4a89-a657-63ac78f11cd2, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:43,834 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c4a9b800-8842-4a89-a657-63ac78f11cd2, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" 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-10 10:00:43,835 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c4a9b800-8842-4a89-a657-63ac78f11cd2, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,000 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:44,001 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:44,001 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 194da60e-b44b-44ba-bc9b-c91c08e902cb, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,002 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 194da60e-b44b-44ba-bc9b-c91c08e902cb, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" 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-10 10:00:44,003 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 194da60e-b44b-44ba-bc9b-c91c08e902cb, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,151 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:44,153 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-10 10:00:44,153 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-10 10:00:44,154 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-10 10:00:44,155 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:44,155 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb -e grpc://localhost:1775 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-10 10:00:44,156 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb -e grpc://localhost:1775 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-10 10:00:44,157 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb -e grpc://localhost:1775 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-10 10:00:44,158 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bc943c48-ff76-445f-a4ff-c4a8c1669bed, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,159 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 1 < 100, will create new one.
2025-11-10 10:00:44,165 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.1
2025-11-10 10:00:44,166 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bc943c48-ff76-445f-a4ff-c4a8c1669bed, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,167 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, b70ab6c0-9fe1-4233-9caa-a9f4c08b19b5, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,170 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.2
2025-11-10 10:00:44,171 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bc943c48-ff76-445f-a4ff-c4a8c1669bed, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,171 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.3
2025-11-10 10:00:44,172 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, b70ab6c0-9fe1-4233-9caa-a9f4c08b19b5, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,172 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.1
2025-11-10 10:00:44,175 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.2
2025-11-10 10:00:44,175 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:1775', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-10 10:00:44,176 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:1775', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-10 10:00:44,177 - DEBUG - ya.test - execute: Command pid: 1827240
2025-11-10 10:00:44,178 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.3
2025-11-10 10:00:44,178 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, b70ab6c0-9fe1-4233-9caa-a9f4c08b19b5, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=" node_id: 1 }
2025-11-10 10:00:44,179 - DEBUG - ya.test - execute: Command pid: 1827241
2025-11-10 10:00:44,181 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, d19e612c-861a-4e8b-8db0-910fb44848a8, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,182 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:1775', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-10 10:00:44,183 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, d19e612c-861a-4e8b-8db0-910fb44848a8, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=" }
2025-11-10 10:00:44,184 - DEBUG - ya.test - execute: Command pid: 1827243
2025-11-10 10:00:44,185 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, d19e612c-861a-4e8b-8db0-910fb44848a8, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,188 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=
2025-11-10 10:00:44,188 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ac022a08-e948-4a50-aa51-1ccbbce7ad1d, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,189 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ac022a08-e948-4a50-aa51-1ccbbce7ad1d, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,189 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ac022a08-e948-4a50-aa51-1ccbbce7ad1d, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,190 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 2 < 100, will create new one.
2025-11-10 10:00:44,190 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 78f42a6f-eec7-4623-9765-164fbe2bcca8, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,190 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 78f42a6f-eec7-4623-9765-164fbe2bcca8, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,193 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 78f42a6f-eec7-4623-9765-164fbe2bcca8, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=" node_id: 1 }
2025-11-10 10:00:44,194 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, b511e1f4-73f6-45c7-86a1-59bb5d4951bb, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,194 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, b511e1f4-73f6-45c7-86a1-59bb5d4951bb, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=" }
2025-11-10 10:00:44,195 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, b511e1f4-73f6-45c7-86a1-59bb5d4951bb, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,197 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=
2025-11-10 10:00:44,197 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f8dcd0b8-28ae-4d71-9c5a-4c6003dbb9a7, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,198 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f8dcd0b8-28ae-4d71-9c5a-4c6003dbb9a7, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,198 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 3 < 100, will create new one.
2025-11-10 10:00:44,199 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, e0180de8-52ed-49dd-b904-a31324c13ffa, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,200 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, e0180de8-52ed-49dd-b904-a31324c13ffa, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,200 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f8dcd0b8-28ae-4d71-9c5a-4c6003dbb9a7, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,202 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, e0180de8-52ed-49dd-b904-a31324c13ffa, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" node_id: 1 }
2025-11-10 10:00:44,203 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 47b2de9f-5dcb-4a34-b752-da7089b29c5e, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,203 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 47b2de9f-5dcb-4a34-b752-da7089b29c5e, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" }
2025-11-10 10:00:44,204 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 47b2de9f-5dcb-4a34-b752-da7089b29c5e, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,206 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:00:44,207 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 74aac19f-9268-4c67-a6c4-40b8b140f033, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,207 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 4 < 100, will create new one.
2025-11-10 10:00:44,208 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 74aac19f-9268-4c67-a6c4-40b8b140f033, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,208 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 3cc75a59-3f92-477c-ad8b-5faf525c6abb, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,209 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 3cc75a59-3f92-477c-ad8b-5faf525c6abb, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,210 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 74aac19f-9268-4c67-a6c4-40b8b140f033, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,212 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 3cc75a59-3f92-477c-ad8b-5faf525c6abb, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=" node_id: 1 }
2025-11-10 10:00:44,213 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 4942f249-f771-4668-a0cb-7de0272d4b38, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,213 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 4942f249-f771-4668-a0cb-7de0272d4b38, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=" }
2025-11-10 10:00:44,214 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 4942f249-f771-4668-a0cb-7de0272d4b38, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,215 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:00:44,216 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b0f903b7-b1c0-408b-bf90-22d49607e8fc, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,216 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 5 < 100, will create new one.
2025-11-10 10:00:44,217 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b0f903b7-b1c0-408b-bf90-22d49607e8fc, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,218 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 07525c53-09e5-4503-a951-a2ab42a1a07a, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,219 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 07525c53-09e5-4503-a951-a2ab42a1a07a, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,219 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b0f903b7-b1c0-408b-bf90-22d49607e8fc, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,221 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 07525c53-09e5-4503-a951-a2ab42a1a07a, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk" node_id: 1 }
2025-11-10 10:00:44,222 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 5b705b7d-91ff-4953-859e-5e2a88b7ad87, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,222 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 5b705b7d-91ff-4953-859e-5e2a88b7ad87, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk" }
2025-11-10 10:00:44,222 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 5b705b7d-91ff-4953-859e-5e2a88b7ad87, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,224 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:00:44,224 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 17e2ddf7-2c44-45be-971f-c4fb4cdc8224, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,225 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 6 < 100, will create new one.
2025-11-10 10:00:44,225 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 17e2ddf7-2c44-45be-971f-c4fb4cdc8224, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,229 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, f90434b5-2509-44fc-912c-9cdb9aafe26e, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,231 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, f90434b5-2509-44fc-912c-9cdb9aafe26e, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,231 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 17e2ddf7-2c44-45be-971f-c4fb4cdc8224, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,235 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, f90434b5-2509-44fc-912c-9cdb9aafe26e, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" node_id: 1 }
2025-11-10 10:00:44,235 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, bedbb627-dd44-4c4b-aa74-5f7002a3c147, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,236 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, bedbb627-dd44-4c4b-aa74-5f7002a3c147, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" }
2025-11-10 10:00:44,236 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, bedbb627-dd44-4c4b-aa74-5f7002a3c147, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,238 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:00:44,239 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e1873976-99fb-4d23-8215-1b68962ab267, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,240 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e1873976-99fb-4d23-8215-1b68962ab267, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,240 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 7 < 100, will create new one.
2025-11-10 10:00:44,241 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e1873976-99fb-4d23-8215-1b68962ab267, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,245 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, e82deccf-cb4d-4f72-9475-500cff3f4d68, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,246 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, e82deccf-cb4d-4f72-9475-500cff3f4d68, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,249 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, e82deccf-cb4d-4f72-9475-500cff3f4d68, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=" node_id: 1 }
2025-11-10 10:00:44,249 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 8f0495b2-39a9-4cb0-9f05-6239369113b0, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,250 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 8f0495b2-39a9-4cb0-9f05-6239369113b0, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=" }
2025-11-10 10:00:44,250 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 8f0495b2-39a9-4cb0-9f05-6239369113b0, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,252 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:00:44,253 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, efe6bd47-a597-4d51-9789-d6cd1fae647d, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,254 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 8 < 100, will create new one.
2025-11-10 10:00:44,254 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, efe6bd47-a597-4d51-9789-d6cd1fae647d, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,255 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 1bc0fc19-d85a-4293-a294-c7ef2e9111c8, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,256 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 1bc0fc19-d85a-4293-a294-c7ef2e9111c8, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,257 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, efe6bd47-a597-4d51-9789-d6cd1fae647d, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,259 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 1bc0fc19-d85a-4293-a294-c7ef2e9111c8, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=" node_id: 1 }
2025-11-10 10:00:44,261 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 212baded-178c-40fc-894a-6ac89b7c5f57, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,261 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 212baded-178c-40fc-894a-6ac89b7c5f57, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=" }
2025-11-10 10:00:44,262 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 212baded-178c-40fc-894a-6ac89b7c5f57, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,264 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=
2025-11-10 10:00:44,264 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 09feb35b-5b81-449d-bdeb-850993ade185, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,265 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 9 < 100, will create new one.
2025-11-10 10:00:44,265 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 09feb35b-5b81-449d-bdeb-850993ade185, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,266 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, be388b3a-0534-4f01-b3bf-f6bb2d913176, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,267 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, be388b3a-0534-4f01-b3bf-f6bb2d913176, ghrun-kipqlopw2q.auto.internal:1775): request = {  }
2025-11-10 10:00:44,267 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 09feb35b-5b81-449d-bdeb-850993ade185, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,312 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, be388b3a-0534-4f01-b3bf-f6bb2d913176, ghrun-kipqlopw2q.auto.internal:1775): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=" node_id: 1 }
2025-11-10 10:00:44,312 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 5419fbdf-0f06-4838-9408-7fca0a6c4865, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,313 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 5419fbdf-0f06-4838-9408-7fca0a6c4865, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=" }
2025-11-10 10:00:44,313 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 5419fbdf-0f06-4838-9408-7fca0a6c4865, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:44,343 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:00:44,344 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, aab3de8c-d49a-439f-bb67-8bbe75d25827, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:44,345 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, aab3de8c-d49a-439f-bb67-8bbe75d25827, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:44,346 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, aab3de8c-d49a-439f-bb67-8bbe75d25827, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:48,692 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-10 10:00:48,693 - DEBUG - ya.test - _save_outputs: Command (pid 1827243) rc: 0
2025-11-10 10:00:48,693 - DEBUG - ya.test - _save_outputs: Command (pid 1827243) elapsed time (sec): 4.507720232009888
2025-11-10 10:00:48,694 - DEBUG - ya.test - _save_outputs: Command (pid 1827243) wtime: 4.51
2025-11-10 10:00:48,694 - DEBUG - ya.test - _save_outputs: Command (pid 1827243) 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	20	0	0	0	0

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

2025-11-10 10:00:48,694 - DEBUG - ya.test - _save_outputs: Command (pid 1827243) errors:

2025-11-10 10:00:48,700 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-10 10:00:48,701 - DEBUG - ya.test - _save_outputs: Command (pid 1827241) rc: 0
2025-11-10 10:00:48,701 - DEBUG - ya.test - _save_outputs: Command (pid 1827241) elapsed time (sec): 4.51824164390564
2025-11-10 10:00:48,701 - DEBUG - ya.test - _save_outputs: Command (pid 1827241) wtime: 4.522
2025-11-10 10:00:48,701 - DEBUG - ya.test - _save_outputs: Command (pid 1827241) 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	20	0	0	0	0

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

2025-11-10 10:00:48,701 - DEBUG - ya.test - _save_outputs: Command (pid 1827241) errors:

2025-11-10 10:00:51,386 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=
2025-11-10 10:00:51,387 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=
2025-11-10 10:00:51,388 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 17d6f522-9d41-4b57-b7d0-0f3283bf4407, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,389 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 17d6f522-9d41-4b57-b7d0-0f3283bf4407, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=" 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-10 10:00:51,389 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 17d6f522-9d41-4b57-b7d0-0f3283bf4407, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,409 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:00:51,409 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:00:51,410 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:00:51,410 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:51,412 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=
2025-11-10 10:00:51,412 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9fe2bc20-b63c-43bb-97c8-27bbb86522d1, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,412 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:00:51,414 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9fe2bc20-b63c-43bb-97c8-27bbb86522d1, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:51,414 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 53abd876-0370-4443-9b08-c6fb8e29b519, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,414 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:00:51,415 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9fe2bc20-b63c-43bb-97c8-27bbb86522d1, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,416 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 53abd876-0370-4443-9b08-c6fb8e29b519, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=" 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-10 10:00:51,417 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 9931355b-d629-44e1-a17d-189cd114fd51, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,417 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=
2025-11-10 10:00:51,418 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 9931355b-d629-44e1-a17d-189cd114fd51, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" 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-10 10:00:51,419 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 49b0ae3f-931f-48dc-b1c7-ccf2bc150bfc, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,420 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 53abd876-0370-4443-9b08-c6fb8e29b519, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,421 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 49b0ae3f-931f-48dc-b1c7-ccf2bc150bfc, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:51,421 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 9931355b-d629-44e1-a17d-189cd114fd51, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,423 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 49b0ae3f-931f-48dc-b1c7-ccf2bc150bfc, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,426 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:00:51,427 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:00:51,427 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0f013ab1-34b5-43cc-8f19-4a6729ee83a9, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,428 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0f013ab1-34b5-43cc-8f19-4a6729ee83a9, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:51,428 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0f013ab1-34b5-43cc-8f19-4a6729ee83a9, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,437 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:00:51,438 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:00:51,439 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4b6792ff-d5b9-4ec1-9cad-fe9a7857a8de, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,439 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4b6792ff-d5b9-4ec1-9cad-fe9a7857a8de, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:00:51,440 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4b6792ff-d5b9-4ec1-9cad-fe9a7857a8de, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,445 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:00:51,446 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:00:51,446 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, fe187218-c643-4d04-b230-1dd82117508f, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,447 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, fe187218-c643-4d04-b230-1dd82117508f, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" 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-10 10:00:51,448 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, fe187218-c643-4d04-b230-1dd82117508f, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,452 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:00:51,454 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:00:51,454 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=
2025-11-10 10:00:51,455 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e3800366-8cb6-46f5-b217-35bd1949734c, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,456 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=
2025-11-10 10:00:51,457 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e3800366-8cb6-46f5-b217-35bd1949734c, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" 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-10 10:00:51,458 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f6fb99ee-8344-471c-8f8e-24bcade829ea, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:00:51,459 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f6fb99ee-8344-471c-8f8e-24bcade829ea, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=" 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-10 10:00:51,460 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e3800366-8cb6-46f5-b217-35bd1949734c, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:51,460 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f6fb99ee-8344-471c-8f8e-24bcade829ea, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:00:54,787 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-10 10:00:54,814 - DEBUG - ya.test - _save_outputs: Command (pid 1827240) rc: 0
2025-11-10 10:00:54,814 - DEBUG - ya.test - _save_outputs: Command (pid 1827240) elapsed time (sec): 10.607439517974854
2025-11-10 10:00:54,815 - DEBUG - ya.test - _save_outputs: Command (pid 1827240) wtime: 10.611
2025-11-10 10:00:54,815 - DEBUG - ya.test - _save_outputs: Command (pid 1827240) 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	9407	10303	10303	10303

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

2025-11-10 10:00:54,817 - DEBUG - ya.test - _save_outputs: Command (pid 1827240) errors:

2025-11-10 10:01:07,949 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:08,109 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:08,112 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, e1999d1d-6e6d-4bcb-b9c4-251f615c3a48, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:08,182 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, e1999d1d-6e6d-4bcb-b9c4-251f615c3a48, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" 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-10 10:01:08,217 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, e1999d1d-6e6d-4bcb-b9c4-251f615c3a48, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:08,383 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:08,578 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:08,579 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, ed0194bf-2437-4a36-9710-df510449cba5, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:08,580 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, ed0194bf-2437-4a36-9710-df510449cba5, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" 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-10 10:01:08,586 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, ed0194bf-2437-4a36-9710-df510449cba5, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:08,846 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:08,847 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:08,882 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:01:08,909 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2133affa-ecaf-4eb5-84da-a052e0a60cff, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:09,040 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:01:09,047 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2133affa-ecaf-4eb5-84da-a052e0a60cff, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" 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-10 10:01:09,048 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 21a05539-1916-446d-8baf-05f342af313f, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:09,052 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 21a05539-1916-446d-8baf-05f342af313f, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:09,054 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2133affa-ecaf-4eb5-84da-a052e0a60cff, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:09,074 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 21a05539-1916-446d-8baf-05f342af313f, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:09,076 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:09,076 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:09,077 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6a34e7c0-853f-43e6-94a7-79b7b8011c28, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:09,078 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6a34e7c0-853f-43e6-94a7-79b7b8011c28, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" 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-10 10:01:09,078 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6a34e7c0-853f-43e6-94a7-79b7b8011c28, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:09,381 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:01:09,595 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:01:09,595 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f822e78b-750a-4784-9fd7-b501e303a3ae, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:09,596 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f822e78b-750a-4784-9fd7-b501e303a3ae, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=" 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-10 10:01:09,621 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f822e78b-750a-4784-9fd7-b501e303a3ae, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:09,658 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:01:09,667 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:09,671 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:01:09,679 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:09,924 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:01:10,189 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, bb55abfd-3602-49af-b6ed-361d7b4b077d, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:10,190 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, bb55abfd-3602-49af-b6ed-361d7b4b077d, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:10,182 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:01:10,191 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:10,191 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 95d6c2c4-85ed-48cb-9c02-b158020c6ab9, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:10,183 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:01:10,192 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 95d6c2c4-85ed-48cb-9c02-b158020c6ab9, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(6)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(5))" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:10,192 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:01:10,193 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=
2025-11-10 10:01:10,194 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, bb55abfd-3602-49af-b6ed-361d7b4b077d, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:10,195 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2306b8b4-2450-4cd0-b8bf-5cb737f7388b, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:10,195 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:10,481 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2306b8b4-2450-4cd0-b8bf-5cb737f7388b, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:10,199 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=
2025-11-10 10:01:10,410 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 95d6c2c4-85ed-48cb-9c02-b158020c6ab9, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:10,490 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:01:10,500 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b8c27ca5-26b2-44f7-a721-a52a44b3855d, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:10,962 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b8c27ca5-26b2-44f7-a721-a52a44b3855d, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" 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-10 10:01:10,504 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:01:10,505 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2306b8b4-2450-4cd0-b8bf-5cb737f7388b, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:10,967 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b8c27ca5-26b2-44f7-a721-a52a44b3855d, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:10,968 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4b521b68-401f-44cb-ac66-05e03c5775fd, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:10,976 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:01:10,983 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7568a07c-77d9-462d-807c-f4ac84147796, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:10,984 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7568a07c-77d9-462d-807c-f4ac84147796, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=" 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-10 10:01:10,985 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7568a07c-77d9-462d-807c-f4ac84147796, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:10,985 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=
2025-11-10 10:01:10,985 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8dddad00-cb29-4240-a4f5-c0332e3f6ca8, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:10,986 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8dddad00-cb29-4240-a4f5-c0332e3f6ca8, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=" 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-10 10:01:10,987 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8dddad00-cb29-4240-a4f5-c0332e3f6ca8, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:10,983 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4b521b68-401f-44cb-ac66-05e03c5775fd, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=" 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-10 10:01:10,996 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4b521b68-401f-44cb-ac66-05e03c5775fd, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:11,062 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=
2025-11-10 10:01:11,380 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=
2025-11-10 10:01:11,381 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 26c6c7e9-9aa1-4f37-ada9-9428efc0f3ba, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:11,382 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 26c6c7e9-9aa1-4f37-ada9-9428efc0f3ba, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(1)" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:11,388 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:01:11,389 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:01:11,393 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 26c6c7e9-9aa1-4f37-ada9-9428efc0f3ba, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:11,394 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f0d56099-cb56-43b9-8516-efe9c19e711e, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:11,395 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f0d56099-cb56-43b9-8516-efe9c19e711e, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(1))" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:11,396 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f0d56099-cb56-43b9-8516-efe9c19e711e, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:11,400 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:12,645 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:12,658 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:01:12,669 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:01:12,669 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=
2025-11-10 10:01:12,670 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 87bbbb44-8066-424c-8fb0-ce774464d097, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:12,671 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 87bbbb44-8066-424c-8fb0-ce774464d097, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2))" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:12,672 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 87bbbb44-8066-424c-8fb0-ce774464d097, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:12,696 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Mjk2ZGZkNTItNzE1MjVhMzItZjhmZTNhNjQtYzg1MDdhZDk=
2025-11-10 10:01:12,700 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:01:12,705 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 12e092fe-cf42-4cd6-b789-52bb3168cf36, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:12,718 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 12e092fe-cf42-4cd6-b789-52bb3168cf36, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk" 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-10 10:01:12,719 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 12e092fe-cf42-4cd6-b789-52bb3168cf36, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:12,717 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NjE3N2IwMjUtNTc0MzViM2EtMWJhY2QxNWYtOTIyMzRiYTI=
2025-11-10 10:01:12,722 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:12,723 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 4f0bb847-1846-473d-a302-1d5879caa134, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:12,723 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 4f0bb847-1846-473d-a302-1d5879caa134, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=" 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-10 10:01:12,724 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 4f0bb847-1846-473d-a302-1d5879caa134, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:12,733 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjUzNDg3YTYtOWJiMTAyMjgtZjQ4MGJhNWUtNDBjMGZlMTU=
2025-11-10 10:01:12,734 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:12,735 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cb26c462-12dd-4031-949e-c3d1477e2b0b, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:12,735 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cb26c462-12dd-4031-949e-c3d1477e2b0b, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=" 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-10 10:01:12,736 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cb26c462-12dd-4031-949e-c3d1477e2b0b, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:12,740 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQwM2FlNjktZGQ2ZTc0ZDktNTkwYmEzOWItNWMwZjlhMzg=
2025-11-10 10:01:12,740 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:01:12,741 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 34b9b9fb-5834-41d5-8fcf-888703c03933, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:12,741 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 34b9b9fb-5834-41d5-8fcf-888703c03933, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(2)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(1))" } stats_mode: STATS_MODE_NONE }
2025-11-10 10:01:12,742 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 34b9b9fb-5834-41d5-8fcf-888703c03933, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:13,347 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODhlODU5MDQtODI4ZTU4ZTUtZjM2NTdiMS03MDdjYWQ4NA==
2025-11-10 10:01:13,348 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZjBhNzdiMWQtZTg5OWMwOWEtNmQzNGViYmMtMzg1NWVhYTE=
2025-11-10 10:01:13,355 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViZDE4NGItMTdlOTQyZmMtZDQwZGZhOS01NTA0OGFk
2025-11-10 10:01:13,356 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MjViYmYwYWItNDg3NzgzZjUtZmFjMjEzY2MtMmFkMWQwNjM=
2025-11-10 10:01:13,358 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWFjNTIwZjQtYmRiNTVkNDgtZjA4OGY3NTItMzUwOTcxYmU=
2025-11-10 10:01:13,360 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:01:13,360 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8a2ea5e5-564b-4f93-99c3-202939466395, ghrun-kipqlopw2q.auto.internal:1775): creating call state
2025-11-10 10:01:13,361 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8a2ea5e5-564b-4f93-99c3-202939466395, ghrun-kipqlopw2q.auto.internal:1775): request = { session_id: "ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=" 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-10 10:01:13,363 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8a2ea5e5-564b-4f93-99c3-202939466395, ghrun-kipqlopw2q.auto.internal:1775): response = { <_MultiThreadedRendezvous object> }
2025-11-10 10:01:13,601 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Y2RmMGVjM2EtZjIxNDQyMzktMmMwNjRjOTAtOTY0NjZiNTM=
2025-11-10 10:01:13,601 - INFO - root - test_log_deviation: check insert: 36493 31493
2025-11-10 10:01:13,604 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.4
2025-11-10 10:01:13,606 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.4
2025-11-10 10:01:13,608 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6t6o/0024e6/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:1775', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-10 10:01:13,609 - DEBUG - ya.test - execute: Command pid: 1877650
2025-11-10 10:01:13,872 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) rc: 0
2025-11-10 10:01:13,881 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) elapsed time (sec): 0.26183271408081055
2025-11-10 10:01:13,881 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) idrss: 0
2025-11-10 10:01:13,881 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) inblock: 0
2025-11-10 10:01:13,882 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) isrss: 0
2025-11-10 10:01:13,882 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) ixrss: 0
2025-11-10 10:01:13,882 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) majflt: 0
2025-11-10 10:01:13,882 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) maxrss: 1216120
2025-11-10 10:01:13,882 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) minflt: 3531
2025-11-10 10:01:13,882 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) msgrcv: 0
2025-11-10 10:01:13,883 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) msgsnd: 0
2025-11-10 10:01:13,883 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) nivcsw: 24
2025-11-10 10:01:13,883 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) nsignals: 0
2025-11-10 10:01:13,883 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) nswap: 0
2025-11-10 10:01:13,883 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) nvcsw: 136
2025-11-10 10:01:13,883 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) oublock: 8
2025-11-10 10:01:13,884 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) stime: 0.041949
2025-11-10 10:01:13,884 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) utime: 0.047192
2025-11-10 10:01:13,884 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) wtime: 0.263
2025-11-10 10:01:13,884 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) output:
Remove path log...
Remove path log...Ok

2025-11-10 10:01:13,885 - DEBUG - ya.test - _save_outputs: Command (pid 1877650) errors:

2025-11-10 10:01:13,887 - INFO - ya.test - pytest_runtest_teardown: Test teardown
