2025-11-25 15:03:00,483 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-25 15:03:00,483 - INFO - ya.test - pytest_runtest_setup: test_log_deviation[1051200]
2025-11-25 15:03:00,483 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-25 15:03:00,483 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-25 15:03:00,485 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out
2025-11-25 15:03:00,485 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err
2025-11-25 15:03:00,485 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-25 15:03:00,509 - DEBUG - ya.test - execute: Command pid: 3856788
2025-11-25 15:03:02,662 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) rc: 0
2025-11-25 15:03:02,662 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) elapsed time (sec): 2.151210308074951
2025-11-25 15:03:02,662 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) idrss: 0
2025-11-25 15:03:02,662 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) inblock: 0
2025-11-25 15:03:02,662 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) isrss: 0
2025-11-25 15:03:02,662 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) ixrss: 0
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) majflt: 0
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) maxrss: 544352
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) minflt: 16244
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) msgrcv: 0
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) msgsnd: 0
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) nivcsw: 307
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) nsignals: 0
2025-11-25 15:03:02,663 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) nswap: 0
2025-11-25 15:03:02,664 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) nvcsw: 51
2025-11-25 15:03:02,664 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) oublock: 8
2025-11-25 15:03:02,664 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) stime: 1.323636
2025-11-25 15:03:02,664 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) utime: 0.111373
2025-11-25 15:03:02,664 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) wtime: 2.176
2025-11-25 15:03:02,664 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) output:
Git info:
    Commit: 8523ef496fae3dee6ffc8155a4a2d46d3019b9ae
    Branch: 
    Author: YDBot <ydbot@ydb.tech>
    Summary: Merge c8fdebaf3f9b39296a145496a377f0207b541fb3 into fa180eebc323a7c89d1e546e9f14f30e9c3ac2a3

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-n7olz6xni4
    Host information: 
        Linux ghrun-n7olz6xni4 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/9695656278/bin/clang++
    Compiler version: 
        clang version 20.1.2
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/9695656278/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-deprecated-literal-operator -Wno-unused-but-set-variable -Wno-unused-private-field -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-deprecated-literal-operator -Wno-unused-but-set-variable -Wno-unused-private-field -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-25 15:03:02,664 - DEBUG - ya.test - _save_outputs: Command (pid 3856788) errors:

2025-11-25 15:03:02,665 - INFO - __tests__.test_log_scenario - _setup_ydb: Git info:
    Commit: 8523ef496fae3dee6ffc8155a4a2d46d3019b9ae
    Branch: 
    Author: YDBot <ydbot@ydb.tech>
    Summary: Merge c8fdebaf3f9b39296a145496a377f0207b541fb3 into fa180eebc323a7c89d1e546e9f14f30e9c3ac2a3

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-n7olz6xni4
    Host information: 
        Linux ghrun-n7olz6xni4 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/9695656278/bin/clang++
    Compiler version: 
        clang version 20.1.2
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/9695656278/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-deprecated-literal-operator -Wno-unused-but-set-variable -Wno-unused-private-field -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-deprecated-literal-operator -Wno-unused-but-set-variable -Wno-unused-private-field -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-25 15:03:02,750 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd
2025-11-25 15:03:02,751 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22875
2025-11-25 15:03:02,753 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/fvd5/0002c2/r3tmp/kikimr_cluster_4z7fey9e
2025-11-25 15:03:02,786 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd
2025-11-25 15:03:02,786 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4007
2025-11-25 15:03:02,786 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/17361
2025-11-25 15:03:02,787 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/16041
2025-11-25 15:03:02,787 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/63390
2025-11-25 15:03:02,788 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/kikimr_configs"
2025-11-25 15:03:02,788 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/fvd5/0002c2/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/fvd5/0002c2/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1/logfile_6p8d7c3y.log --grpc-port=4007 --mon-port=17361 --ic-port=22875
2025-11-25 15:03:02,788 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:4007/1, disk_size 68719476736
2025-11-25 15:03:02,788 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/kikimr_configs"
2025-11-25 15:03:02,788 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/fvd5/0002c2/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/fvd5/0002c2/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1/logfile_6p8d7c3y.log --grpc-port=4007 --mon-port=17361 --ic-port=22875
2025-11-25 15:03:02,789 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk2/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/fvd5/0002c2/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1/logfile_6p8d7c3y.log', '--grpc-port=4007', '--mon-port=17361', '--ic-port=22875')' in '/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/tests/olap/test-results/py3test/testing_out_stuff/chunk2/testing_out_stuff/test_log_scenario.py.TestLogScenario.test_log_deviation.1051200/cluster/node_1' (no wait)
2025-11-25 15:03:02,802 - DEBUG - ya.test - execute: Command pid: 3860097
2025-11-25 15:03:02,802 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:4007/1
2025-11-25 15:03:02,803 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.0
2025-11-25 15:03:02,804 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.0
2025-11-25 15:03:02,804 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-25 15:03:02,817 - DEBUG - ya.test - execute: Command pid: 3860121
2025-11-25 15:03:05,453 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) rc: 0
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) elapsed time (sec): 2.6348838806152344
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) idrss: 0
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) inblock: 0
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) isrss: 0
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) ixrss: 0
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) majflt: 1
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) maxrss: 544352
2025-11-25 15:03:05,454 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) minflt: 16243
2025-11-25 15:03:05,455 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) msgrcv: 0
2025-11-25 15:03:05,455 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) msgsnd: 0
2025-11-25 15:03:05,455 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) nivcsw: 408
2025-11-25 15:03:05,455 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) nsignals: 0
2025-11-25 15:03:05,455 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) nswap: 0
2025-11-25 15:03:05,455 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) nvcsw: 84
2025-11-25 15:03:05,455 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) oublock: 8
2025-11-25 15:03:05,456 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) stime: 1.56552
2025-11-25 15:03:05,456 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) utime: 0.0877
2025-11-25 15:03:05,456 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) wtime: 2.648
2025-11-25 15:03:05,456 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) output:
Git info:
    Commit: 8523ef496fae3dee6ffc8155a4a2d46d3019b9ae
    Branch: 
    Author: YDBot <ydbot@ydb.tech>
    Summary: Merge c8fdebaf3f9b39296a145496a377f0207b541fb3 into fa180eebc323a7c89d1e546e9f14f30e9c3ac2a3

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-n7olz6xni4
    Host information: 
        Linux ghrun-n7olz6xni4 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/9695656278/bin/clang++
    Compiler version: 
        clang version 20.1.2
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/9695656278/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-deprecated-literal-operator -Wno-unused-but-set-variable -Wno-unused-private-field -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-deprecated-literal-operator -Wno-unused-but-set-variable -Wno-unused-private-field -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-25 15:03:05,456 - DEBUG - ya.test - _save_outputs: Command (pid 3860121) errors:

2025-11-25 15:03:05,456 - INFO - ydb.tests.library.harness.kikimr_runner - start: Node 1 version:
Git info:
    Commit: 8523ef496fae3dee6ffc8155a4a2d46d3019b9ae
    Branch: 
    Author: YDBot <ydbot@ydb.tech>
    Summary: Merge c8fdebaf3f9b39296a145496a377f0207b541fb3 into fa180eebc323a7c89d1e546e9f14f30e9c3ac2a3
2025-11-25 15:03:09,262 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd
2025-11-25 15:03:09,263 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:4007', '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: 22875\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-25 15:03:09,264 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.1
2025-11-25 15:03:09,278 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.1
2025-11-25 15:03:09,306 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:4007', '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: 22875\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-25 15:03:09,326 - DEBUG - ya.test - execute: Command pid: 3868826
2025-11-25 15:03:11,110 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) rc: 0
2025-11-25 15:03:11,110 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) elapsed time (sec): 1.7486159801483154
2025-11-25 15:03:11,114 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) idrss: 0
2025-11-25 15:03:11,115 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) inblock: 0
2025-11-25 15:03:11,123 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) isrss: 0
2025-11-25 15:03:11,123 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) ixrss: 0
2025-11-25 15:03:11,124 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) majflt: 0
2025-11-25 15:03:11,125 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) maxrss: 552668
2025-11-25 15:03:11,125 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) minflt: 18383
2025-11-25 15:03:11,131 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) msgrcv: 0
2025-11-25 15:03:11,131 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) msgsnd: 0
2025-11-25 15:03:11,131 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) nivcsw: 365
2025-11-25 15:03:11,131 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) nsignals: 0
2025-11-25 15:03:11,131 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) nswap: 0
2025-11-25 15:03:11,132 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) nvcsw: 120
2025-11-25 15:03:11,132 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) oublock: 8
2025-11-25 15:03:11,132 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) stime: 1.075495
2025-11-25 15:03:11,132 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) utime: 0.104429
2025-11-25 15:03:11,132 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) wtime: 1.798
2025-11-25 15:03:11,132 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2025-11-25 15:03:11,132 - DEBUG - ya.test - _save_outputs: Command (pid 3868826) errors:

2025-11-25 15:03:11,135 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd
2025-11-25 15:03:11,142 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:4007', '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-25 15:03:11,145 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.2
2025-11-25 15:03:11,154 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.2
2025-11-25 15:03:11,163 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydbd/ydbd', '--server', 'grpc://localhost:4007', '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-25 15:03:11,206 - DEBUG - ya.test - execute: Command pid: 3870951
2025-11-25 15:03:13,226 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) rc: 0
2025-11-25 15:03:13,226 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) elapsed time (sec): 2.0198304653167725
2025-11-25 15:03:13,227 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) idrss: 0
2025-11-25 15:03:13,227 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) inblock: 0
2025-11-25 15:03:13,227 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) isrss: 0
2025-11-25 15:03:13,227 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) ixrss: 0
2025-11-25 15:03:13,227 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) majflt: 0
2025-11-25 15:03:13,227 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) maxrss: 552624
2025-11-25 15:03:13,227 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) minflt: 18391
2025-11-25 15:03:13,258 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) msgrcv: 0
2025-11-25 15:03:13,258 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) msgsnd: 0
2025-11-25 15:03:13,259 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) nivcsw: 339
2025-11-25 15:03:13,259 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) nsignals: 0
2025-11-25 15:03:13,259 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) nswap: 0
2025-11-25 15:03:13,259 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) nvcsw: 124
2025-11-25 15:03:13,259 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) oublock: 8
2025-11-25 15:03:13,260 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) stime: 0.947978
2025-11-25 15:03:13,260 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) utime: 0.123096
2025-11-25 15:03:13,260 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) wtime: 2.029
2025-11-25 15:03:13,281 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-25 15:03:13,282 - DEBUG - ya.test - _save_outputs: Command (pid 3870951) errors:

2025-11-25 15:03:13,282 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain Root: {'dynamic_storage_pool:1': 'hdd'}
2025-11-25 15:03:13,330 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-25 15:03:13,344 - 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-25 15:03:13,370 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-25 15:03:13,371 - 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-25 15:03:13,398 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root
2025-11-25 15:03:13,399 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 0989483c-701c-40b3-a7e9-22ae63158628, localhost:4007): creating call state
2025-11-25 15:03:13,400 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 0989483c-701c-40b3-a7e9-22ae63158628, localhost:4007): request = { database: "/Root" }
2025-11-25 15:03:13,407 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 0989483c-701c-40b3-a7e9-22ae63158628, localhost:4007): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-n7olz6xni4.auto.internal" port: 4007 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-25 15:03:13,411 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-n7olz6xni4.auto.internal:4007, location 1, ssl: False>]>
2025-11-25 15:03:13,414 - 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-25 15:03:13,442 - INFO - ydb.connection - close: Closing channel for endpoint localhost:4007
2025-11-25 15:03:13,446 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_log_scenario.py::TestLogScenario, test_name: test_log_deviation[1051200])
2025-11-25 15:03:13,447 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb
2025-11-25 15:03:13,447 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log init --path log --store column --ttl 1000 with wait = True
2025-11-25 15:03:13,448 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out
2025-11-25 15:03:13,448 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err
2025-11-25 15:03:13,448 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'init', '--path', 'log', '--store', 'column', '--ttl', '1000']' in 'None' (waiting)
2025-11-25 15:03:13,460 - DEBUG - ya.test - execute: Command pid: 3873798
2025-11-25 15:03:14,134 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) rc: 0
2025-11-25 15:03:14,134 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) elapsed time (sec): 0.6728720664978027
2025-11-25 15:03:14,135 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) idrss: 0
2025-11-25 15:03:14,135 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) inblock: 0
2025-11-25 15:03:14,135 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) isrss: 0
2025-11-25 15:03:14,135 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) ixrss: 0
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) majflt: 0
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) maxrss: 170212
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) minflt: 3476
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) msgrcv: 0
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) msgsnd: 0
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) nivcsw: 62
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) nsignals: 0
2025-11-25 15:03:14,136 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) nswap: 0
2025-11-25 15:03:14,137 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) nvcsw: 135
2025-11-25 15:03:14,137 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) oublock: 8
2025-11-25 15:03:14,137 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) stime: 0.015266
2025-11-25 15:03:14,137 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) utime: 0.0687
2025-11-25 15:03:14,137 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) wtime: 0.685
2025-11-25 15:03:14,165 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) output:
Init tables ...
Init tables ...Ok

2025-11-25 15:03:14,166 - DEBUG - ya.test - _save_outputs: Command (pid 3873798) errors:

2025-11-25 15:03:14,166 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 0 < 100, will create new one.
2025-11-25 15:03:14,168 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, c300ca56-6ab3-47a9-ba53-d7ae12825a50, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:14,186 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, c300ca56-6ab3-47a9-ba53-d7ae12825a50, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:14,189 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, c300ca56-6ab3-47a9-ba53-d7ae12825a50, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" node_id: 1 }
2025-11-25 15:03:14,221 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 46a90359-908b-4c7f-9bfc-74deae6080c5, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:14,232 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 46a90359-908b-4c7f-9bfc-74deae6080c5, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" }
2025-11-25 15:03:14,234 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 46a90359-908b-4c7f-9bfc-74deae6080c5, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:14,297 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:14,298 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, cb283059-466e-420c-bb41-27386e9883ac, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:14,299 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, cb283059-466e-420c-bb41-27386e9883ac, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-25 15:03:14,300 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, cb283059-466e-420c-bb41-27386e9883ac, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:14,334 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:14,338 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-25 15:03:14,338 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-25 15:03:14,339 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.0
2025-11-25 15:03:14,347 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.0
2025-11-25 15:03:14,353 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-25 15:03:14,354 - DEBUG - ya.test - execute: Command pid: 3874696
2025-11-25 15:03:18,205 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:03:18,206 - DEBUG - ya.test - _save_outputs: Command (pid 3874696) rc: 0
2025-11-25 15:03:18,206 - DEBUG - ya.test - _save_outputs: Command (pid 3874696) elapsed time (sec): 3.840681314468384
2025-11-25 15:03:18,209 - DEBUG - ya.test - _save_outputs: Command (pid 3874696) wtime: 3.852
2025-11-25 15:03:18,210 - DEBUG - ya.test - _save_outputs: Command (pid 3874696) output:
Window	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
1	      2	2	0	0	883	903	903	903
2	      8	8	0	0	1271	1439	1439	1439
3	     20	20	0	0	1039	1191	1215	1215

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

2025-11-25 15:03:18,211 - DEBUG - ya.test - _save_outputs: Command (pid 3874696) errors:

2025-11-25 15:03:18,229 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:18,246 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c1a081b6-c5ed-4318-a84d-a6919df84b0e, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:18,247 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c1a081b6-c5ed-4318-a84d-a6919df84b0e, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-25 15:03:18,250 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c1a081b6-c5ed-4318-a84d-a6919df84b0e, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:19,218 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:19,241 - INFO - root - test_log_deviation: Count rows after insert 15000 before wait
2025-11-25 15:03:19,242 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:19,265 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 0937ef26-7689-4fed-90ae-7c161e278308, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:19,266 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 0937ef26-7689-4fed-90ae-7c161e278308, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-25 15:03:19,279 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 0937ef26-7689-4fed-90ae-7c161e278308, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:20,385 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:20,443 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:20,443 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f5230f31-429b-4656-aee9-3937c757ee91, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:20,444 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f5230f31-429b-4656-aee9-3937c757ee91, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-25 15:03:20,464 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f5230f31-429b-4656-aee9-3937c757ee91, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:21,470 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:21,471 - INFO - root - _insert_rows: YdbWorkloadLog bulk_upsert
2025-11-25 15:03:21,472 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run bulk_upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-25 15:03:21,473 - INFO - root - _insert_rows: YdbWorkloadLog insert
2025-11-25 15:03:21,475 - INFO - root - _insert_rows: YdbWorkloadLog upsert
2025-11-25 15:03:21,476 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:21,477 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.1
2025-11-25 15:03:21,479 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run insert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-25 15:03:21,488 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.1
2025-11-25 15:03:21,489 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'bulk_upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-25 15:03:21,480 - INFO - root - _call: YdbWorkloadLog execute /home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb -e grpc://localhost:4007 -d /Root workload log --path log run upsert --seconds 3 --threads 10 --rows 500 --timestamp_deviation 1051200 with wait = True
2025-11-25 15:03:21,491 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.2
2025-11-25 15:03:21,492 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.2
2025-11-25 15:03:21,483 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 1 < 100, will create new one.
2025-11-25 15:03:21,490 - DEBUG - ya.test - execute: Command pid: 3882701
2025-11-25 15:03:21,482 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 6a8f1066-6da2-4b92-90a3-f022a0cca380, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,492 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'insert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-25 15:03:21,493 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 21185247-685d-4f60-b3b5-029de700924f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,532 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.3
2025-11-25 15:03:21,562 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 6a8f1066-6da2-4b92-90a3-f022a0cca380, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:21,577 - DEBUG - ya.test - execute: Command pid: 3882752
2025-11-25 15:03:21,580 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 21185247-685d-4f60-b3b5-029de700924f, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:21,585 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.3
2025-11-25 15:03:21,589 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 6a8f1066-6da2-4b92-90a3-f022a0cca380, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:21,614 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 21185247-685d-4f60-b3b5-029de700924f, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" node_id: 1 }
2025-11-25 15:03:21,620 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 92001b16-cdb7-4c56-a288-50f0515a0a9f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,622 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 92001b16-cdb7-4c56-a288-50f0515a0a9f, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" }
2025-11-25 15:03:21,630 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 92001b16-cdb7-4c56-a288-50f0515a0a9f, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:21,620 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'run', 'upsert', '--seconds', '3', '--threads', '10', '--rows', '500', '--timestamp_deviation', '1051200']' in 'None' (waiting)
2025-11-25 15:03:21,634 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:03:21,636 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c5164fd0-f500-4b64-8f73-dccc7b48e12e, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,635 - DEBUG - ya.test - execute: Command pid: 3882874
2025-11-25 15:03:21,636 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c5164fd0-f500-4b64-8f73-dccc7b48e12e, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:21,637 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 2 < 100, will create new one.
2025-11-25 15:03:21,663 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 27ba0c9d-9389-4d82-90e8-5528e7f5073c, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,642 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c5164fd0-f500-4b64-8f73-dccc7b48e12e, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:21,664 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 27ba0c9d-9389-4d82-90e8-5528e7f5073c, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:21,722 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 27ba0c9d-9389-4d82-90e8-5528e7f5073c, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" node_id: 1 }
2025-11-25 15:03:21,763 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 37a65873-a243-4238-bf71-246e7e466640, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,764 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 37a65873-a243-4238-bf71-246e7e466640, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" }
2025-11-25 15:03:21,765 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 37a65873-a243-4238-bf71-246e7e466640, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:21,800 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:03:21,842 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1520d0d8-f9da-448f-bb36-baef46507b38, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,847 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1520d0d8-f9da-448f-bb36-baef46507b38, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:21,848 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1520d0d8-f9da-448f-bb36-baef46507b38, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:21,842 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 3 < 100, will create new one.
2025-11-25 15:03:21,872 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, eefa499a-d2e9-4572-b940-cd6fe25bf816, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,873 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, eefa499a-d2e9-4572-b940-cd6fe25bf816, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:21,958 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, eefa499a-d2e9-4572-b940-cd6fe25bf816, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" node_id: 1 }
2025-11-25 15:03:21,964 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, f5f93572-9bea-4db0-a810-12f7f6395f7a, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,964 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, f5f93572-9bea-4db0-a810-12f7f6395f7a, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" }
2025-11-25 15:03:21,966 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, f5f93572-9bea-4db0-a810-12f7f6395f7a, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:21,991 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:03:21,991 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2bfc44aa-1764-4895-bf4e-6d531881ae8c, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:21,992 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2bfc44aa-1764-4895-bf4e-6d531881ae8c, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:21,992 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 4 < 100, will create new one.
2025-11-25 15:03:21,992 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2bfc44aa-1764-4895-bf4e-6d531881ae8c, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:22,010 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 7988adc9-9923-498c-a179-a49b1282c884, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:22,013 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 7988adc9-9923-498c-a179-a49b1282c884, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:22,026 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 7988adc9-9923-498c-a179-a49b1282c884, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" node_id: 1 }
2025-11-25 15:03:22,030 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 424ff4e7-c404-4ef2-9c08-a8a0a6e168da, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:22,031 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 424ff4e7-c404-4ef2-9c08-a8a0a6e168da, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" }
2025-11-25 15:03:22,032 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 424ff4e7-c404-4ef2-9c08-a8a0a6e168da, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:22,171 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:03:22,171 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5d10b821-f1e1-4ca7-b9ad-3186170ce67f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:22,202 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5d10b821-f1e1-4ca7-b9ad-3186170ce67f, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:22,204 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5d10b821-f1e1-4ca7-b9ad-3186170ce67f, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:22,173 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 5 < 100, will create new one.
2025-11-25 15:03:22,207 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 399ad904-86b1-49ad-9a3e-cc00a83dba16, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:22,238 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 399ad904-86b1-49ad-9a3e-cc00a83dba16, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:22,438 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 399ad904-86b1-49ad-9a3e-cc00a83dba16, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" node_id: 1 }
2025-11-25 15:03:22,439 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 09a60769-4ac2-452c-89ad-182284fdb84f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:22,439 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 09a60769-4ac2-452c-89ad-182284fdb84f, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" }
2025-11-25 15:03:22,440 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 09a60769-4ac2-452c-89ad-182284fdb84f, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:23,042 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:03:23,042 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 1ac3876e-7e70-4fd0-8201-600383fd2dbc, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:23,048 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 1ac3876e-7e70-4fd0-8201-600383fd2dbc, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:23,049 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 1ac3876e-7e70-4fd0-8201-600383fd2dbc, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:23,043 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 6 < 100, will create new one.
2025-11-25 15:03:23,074 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 96c564fd-1237-47e3-a536-df0c0e991ed7, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:23,074 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 96c564fd-1237-47e3-a536-df0c0e991ed7, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:23,267 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 96c564fd-1237-47e3-a536-df0c0e991ed7, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" node_id: 1 }
2025-11-25 15:03:23,268 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 0a3597d8-6b64-40ad-bde3-0fe4acef1c3d, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:23,268 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 0a3597d8-6b64-40ad-bde3-0fe4acef1c3d, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" }
2025-11-25 15:03:23,269 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 0a3597d8-6b64-40ad-bde3-0fe4acef1c3d, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:23,498 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:03:23,499 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 95817efa-fc8a-470e-8363-3b735bf466ef, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:23,499 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 95817efa-fc8a-470e-8363-3b735bf466ef, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:23,510 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 95817efa-fc8a-470e-8363-3b735bf466ef, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:23,500 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 7 < 100, will create new one.
2025-11-25 15:03:23,522 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 1f0800f1-df65-4814-ad48-ea2e9142ea2a, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:23,522 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 1f0800f1-df65-4814-ad48-ea2e9142ea2a, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:23,906 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 1f0800f1-df65-4814-ad48-ea2e9142ea2a, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" node_id: 1 }
2025-11-25 15:03:23,932 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 6d25f102-c62f-4032-a4d6-221bb8fa9163, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:23,932 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 6d25f102-c62f-4032-a4d6-221bb8fa9163, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" }
2025-11-25 15:03:23,944 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 6d25f102-c62f-4032-a4d6-221bb8fa9163, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:24,134 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:03:24,174 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, b351f47f-6740-491e-9622-57a143bb9cb9, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:24,176 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 8 < 100, will create new one.
2025-11-25 15:03:24,216 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, ba8d5706-6f6b-4ccc-8e8a-e1f3966fc96d, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:24,216 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, ba8d5706-6f6b-4ccc-8e8a-e1f3966fc96d, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:24,177 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, b351f47f-6740-491e-9622-57a143bb9cb9, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:24,220 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, b351f47f-6740-491e-9622-57a143bb9cb9, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:24,268 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, ba8d5706-6f6b-4ccc-8e8a-e1f3966fc96d, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" node_id: 1 }
2025-11-25 15:03:24,311 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, ed72a6f1-089e-47f3-90c6-d64f8ef4966b, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:24,312 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, ed72a6f1-089e-47f3-90c6-d64f8ef4966b, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" }
2025-11-25 15:03:24,313 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, ed72a6f1-089e-47f3-90c6-d64f8ef4966b, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:24,382 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:03:24,383 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d6c39e0e-02a7-4169-827e-49fe890ca80d, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:24,384 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d6c39e0e-02a7-4169-827e-49fe890ca80d, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:24,384 - DEBUG - ydb.query.pool - acquire: Session pool is not large enough: 9 < 100, will create new one.
2025-11-25 15:03:24,389 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d6c39e0e-02a7-4169-827e-49fe890ca80d, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:24,390 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 7ebf548f-bfd2-4dab-a709-41a1843302f9, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:24,401 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 7ebf548f-bfd2-4dab-a709-41a1843302f9, ghrun-n7olz6xni4.auto.internal:4007): request = {  }
2025-11-25 15:03:24,916 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 7ebf548f-bfd2-4dab-a709-41a1843302f9, ghrun-n7olz6xni4.auto.internal:4007): response = { status: SUCCESS session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" node_id: 1 }
2025-11-25 15:03:24,917 - DEBUG - ydb.connection - _prepare_call: RpcState(AttachSession, 18808941-7a24-458f-a29b-4495172d9077, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:24,941 - DEBUG - ydb.connection - _log_request: RpcState(AttachSession, 18808941-7a24-458f-a29b-4495172d9077, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" }
2025-11-25 15:03:24,942 - DEBUG - ydb.connection - _log_response: RpcState(AttachSession, 18808941-7a24-458f-a29b-4495172d9077, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:25,258 - DEBUG - ydb.query.pool - _create_new_session: New session was created for pool. Session id: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:03:25,277 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 09a7494b-0499-4915-af62-8a8bf7ab5097, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:25,277 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 09a7494b-0499-4915-af62-8a8bf7ab5097, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` " } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:25,279 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 09a7494b-0499-4915-af62-8a8bf7ab5097, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:26,709 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:03:26,714 - DEBUG - ya.test - _save_outputs: Command (pid 3882874) rc: 0
2025-11-25 15:03:26,719 - DEBUG - ya.test - _save_outputs: Command (pid 3882874) elapsed time (sec): 5.072452068328857
2025-11-25 15:03:26,720 - DEBUG - ya.test - _save_outputs: Command (pid 3882874) wtime: 5.075
2025-11-25 15:03:26,720 - DEBUG - ya.test - _save_outputs: Command (pid 3882874) 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	18	0	0	0	0

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

2025-11-25 15:03:26,720 - DEBUG - ya.test - _save_outputs: Command (pid 3882874) errors:

2025-11-25 15:03:26,761 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:03:26,766 - DEBUG - ya.test - _save_outputs: Command (pid 3882752) rc: 0
2025-11-25 15:03:26,795 - DEBUG - ya.test - _save_outputs: Command (pid 3882752) elapsed time (sec): 5.17601203918457
2025-11-25 15:03:26,795 - DEBUG - ya.test - _save_outputs: Command (pid 3882752) wtime: 5.192
2025-11-25 15:03:26,795 - DEBUG - ya.test - _save_outputs: Command (pid 3882752) 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	19	0	0	0	0

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

2025-11-25 15:03:26,822 - DEBUG - ya.test - _save_outputs: Command (pid 3882752) errors:

2025-11-25 15:03:42,158 - DEBUG - ya.test - _wait: Process resource usage is not available as process finished before wait4 was called
2025-11-25 15:03:42,158 - DEBUG - ya.test - _save_outputs: Command (pid 3882701) rc: 0
2025-11-25 15:03:42,158 - DEBUG - ya.test - _save_outputs: Command (pid 3882701) elapsed time (sec): 20.62820553779602
2025-11-25 15:03:42,159 - DEBUG - ya.test - _save_outputs: Command (pid 3882701) wtime: 20.669
2025-11-25 15:03:42,173 - DEBUG - ya.test - _save_outputs: Command (pid 3882701) 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	      3	3	0	7	19327	19839	19839	19839

Total	    Txs	Txs/Sec	Retries	Errors	p50(ms)	p95(ms)	p99(ms)	pMax(ms)
3	      3	1	0	7	19327	19839	19839	19839

2025-11-25 15:03:42,174 - DEBUG - ya.test - _save_outputs: Command (pid 3882701) errors:

2025-11-25 15:03:45,116 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:03:45,128 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:03:45,136 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 38e62e95-23a2-4dda-af96-d33b8dd89ae8, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:45,137 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 38e62e95-23a2-4dda-af96-d33b8dd89ae8, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" 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-25 15:03:45,138 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 38e62e95-23a2-4dda-af96-d33b8dd89ae8, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:45,187 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:03:45,187 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:03:45,193 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, acc27b2a-b894-495a-aa7d-be7585cf9845, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:45,194 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, acc27b2a-b894-495a-aa7d-be7585cf9845, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:45,195 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, acc27b2a-b894-495a-aa7d-be7585cf9845, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:45,207 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:03:45,208 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:03:45,208 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2abe87f5-ee4b-491c-bca0-f14f5621f72f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:45,208 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2abe87f5-ee4b-491c-bca0-f14f5621f72f, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:45,209 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2abe87f5-ee4b-491c-bca0-f14f5621f72f, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:45,305 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:03:45,310 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:03:45,310 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 01da5535-d383-4503-8845-717a137be661, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:45,311 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 01da5535-d383-4503-8845-717a137be661, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" 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-25 15:03:45,322 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 01da5535-d383-4503-8845-717a137be661, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:45,372 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:03:45,386 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:03:45,387 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 35ccb88d-d171-480c-a344-093562b58c6e, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:45,388 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 35ccb88d-d171-480c-a344-093562b58c6e, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:45,398 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 35ccb88d-d171-480c-a344-093562b58c6e, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:45,449 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:03:45,470 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:03:45,471 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 5404d955-0141-4260-8fea-fead11de8c0e, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:45,471 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 5404d955-0141-4260-8fea-fead11de8c0e, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:45,477 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 5404d955-0141-4260-8fea-fead11de8c0e, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:45,795 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:03:45,799 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:03:45,799 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 07b5eafc-be41-4fbb-b6e9-1705c8d5e843, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:45,875 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 07b5eafc-be41-4fbb-b6e9-1705c8d5e843, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:45,876 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 07b5eafc-be41-4fbb-b6e9-1705c8d5e843, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:46,042 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:03:46,057 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:46,064 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:03:46,078 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:03:46,079 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d5dcae6d-2049-4a6d-a019-54d8b342d6ed, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:46,079 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:03:46,235 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 65d8728e-c22b-4e8c-a23a-e9b65373c184, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:46,121 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d5dcae6d-2049-4a6d-a019-54d8b342d6ed, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT * FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:03:46,236 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 65d8728e-c22b-4e8c-a23a-e9b65373c184, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-25 15:03:46,241 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d5dcae6d-2049-4a6d-a019-54d8b342d6ed, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:46,243 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 65d8728e-c22b-4e8c-a23a-e9b65373c184, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:03:46,239 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:03:46,251 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 69bd0578-b1c0-44db-99db-063717719d7f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:03:46,252 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 69bd0578-b1c0-44db-99db-063717719d7f, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" 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-25 15:03:46,268 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 69bd0578-b1c0-44db-99db-063717719d7f, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:12,685 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:04:12,782 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:04:12,790 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 7368c3fb-0e3e-446b-95b6-20b3c3501821, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:12,808 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 7368c3fb-0e3e-446b-95b6-20b3c3501821, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-25 15:04:12,811 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 7368c3fb-0e3e-446b-95b6-20b3c3501821, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:12,983 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:04:13,116 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:04:13,133 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 503368bb-257b-4d20-a21c-6bad7b7f53e4, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:13,143 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 503368bb-257b-4d20-a21c-6bad7b7f53e4, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" 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-25 15:04:13,164 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 503368bb-257b-4d20-a21c-6bad7b7f53e4, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:13,189 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:13,396 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:13,397 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 07f8c481-589b-45e2-a463-efdd983d2663, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:13,398 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 07f8c481-589b-45e2-a463-efdd983d2663, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:13,406 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 07f8c481-589b-45e2-a463-efdd983d2663, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:13,455 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:13,465 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:13,577 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:13,705 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 2f87e676-6e92-4153-a912-a3cfb4bf3600, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:13,721 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:13,733 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, d7ef5e3a-cedf-4df7-abbf-f34f87e6aceb, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:13,727 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 2f87e676-6e92-4153-a912-a3cfb4bf3600, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:13,734 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, d7ef5e3a-cedf-4df7-abbf-f34f87e6aceb, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:13,751 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 2f87e676-6e92-4153-a912-a3cfb4bf3600, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:13,752 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, d7ef5e3a-cedf-4df7-abbf-f34f87e6aceb, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:13,771 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:04:13,913 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:04:13,923 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c8171df6-f0a1-4dc8-881f-f75b4d77794f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:13,927 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c8171df6-f0a1-4dc8-881f-f75b4d77794f, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" 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-25 15:04:13,944 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c8171df6-f0a1-4dc8-881f-f75b4d77794f, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:13,917 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:14,089 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:14,116 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 533f356b-255c-49c8-b941-0f248bc54ed1, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:14,120 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 533f356b-255c-49c8-b941-0f248bc54ed1, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" 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-25 15:04:14,127 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 533f356b-255c-49c8-b941-0f248bc54ed1, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:14,136 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:04:14,142 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:04:14,455 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:04:14,455 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c3ae5ba8-234a-4b04-885e-9d6603dbf9e7, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:14,460 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:04:14,468 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c3ae5ba8-234a-4b04-885e-9d6603dbf9e7, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(3)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:14,475 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:14,480 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8f7b7d1b-2986-445c-b315-f294b30c2920, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:14,669 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:14,670 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c3ae5ba8-234a-4b04-885e-9d6603dbf9e7, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:14,690 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8f7b7d1b-2986-445c-b315-f294b30c2920, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(10)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:14,690 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 69a69ba0-738f-4f2b-939d-3047ad4728a5, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:14,693 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8f7b7d1b-2986-445c-b315-f294b30c2920, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:14,694 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 69a69ba0-738f-4f2b-939d-3047ad4728a5, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE timestamp < CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:14,711 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 69a69ba0-738f-4f2b-939d-3047ad4728a5, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,426 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:04:28,434 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:04:28,435 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, a25c4da1-b04e-404a-946e-645bc30f3c6d, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,438 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, a25c4da1-b04e-404a-946e-645bc30f3c6d, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(11)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(10))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:28,442 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, a25c4da1-b04e-404a-946e-645bc30f3c6d, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,434 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:04:28,449 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:04:28,449 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c3c11c13-c1aa-45dc-8d59-221e78224e82, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,450 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c3c11c13-c1aa-45dc-8d59-221e78224e82, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:28,456 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c3c11c13-c1aa-45dc-8d59-221e78224e82, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,472 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:04:28,476 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:04:28,477 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 547c3d3f-1461-46ad-81ce-b0997820d72c, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,478 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 547c3d3f-1461-46ad-81ce-b0997820d72c, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=" 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-25 15:04:28,480 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 547c3d3f-1461-46ad-81ce-b0997820d72c, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,498 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:28,522 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:28,522 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 57f22b2a-e837-4279-b287-1ea7c1fe2c72, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,527 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 57f22b2a-e837-4279-b287-1ea7c1fe2c72, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==" 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-25 15:04:28,534 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 57f22b2a-e837-4279-b287-1ea7c1fe2c72, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,528 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:28,552 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:04:28,524 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:04:28,562 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, c36624ca-1404-4273-9f66-bfec1252586a, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,564 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:28,570 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, c36624ca-1404-4273-9f66-bfec1252586a, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:28,572 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:28,572 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 825d6b82-efd7-4e19-8ba6-1f9f28495ba2, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,574 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, c36624ca-1404-4273-9f66-bfec1252586a, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,590 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:28,596 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:28,621 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 8180a3d3-ebc1-4ebe-aa17-10950c2e4030, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,603 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 825d6b82-efd7-4e19-8ba6-1f9f28495ba2, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" 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-25 15:04:28,622 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:28,624 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 8180a3d3-ebc1-4ebe-aa17-10950c2e4030, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(3))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:28,639 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 63445162-6a93-4d24-bd78-48b1ce46140f, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,640 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 825d6b82-efd7-4e19-8ba6-1f9f28495ba2, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,643 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 63445162-6a93-4d24-bd78-48b1ce46140f, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:28,643 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 8180a3d3-ebc1-4ebe-aa17-10950c2e4030, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,645 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 63445162-6a93-4d24-bd78-48b1ce46140f, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,722 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:04:28,723 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:04:28,724 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 750cdf66-dd19-472e-8f21-9fee888fa7a9, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,726 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 750cdf66-dd19-472e-8f21-9fee888fa7a9, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=" 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-25 15:04:28,741 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 750cdf66-dd19-472e-8f21-9fee888fa7a9, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:28,926 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:28,948 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:28,949 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, 445db2ed-f1fd-41c2-96cf-f32484bbefaa, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:28,967 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, 445db2ed-f1fd-41c2-96cf-f32484bbefaa, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=" exec_mode: EXEC_MODE_EXECUTE query_content { syntax: SYNTAX_YQL_V1 text: "SELECT COUNT(*) FROM `log` WHERE (timestamp >= CurrentUtcTimestamp() - DateTime::IntervalFromHours(5)) AND (timestamp <= CurrentUtcTimestamp() - DateTime::IntervalFromHours(4))" } stats_mode: STATS_MODE_NONE }
2025-11-25 15:04:28,970 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, 445db2ed-f1fd-41c2-96cf-f32484bbefaa, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:29,740 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:29,740 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODU2ODJhMDgtY2JlZjFlYWUtN2QzODE3Ni1lMGUyNzFjYQ==
2025-11-25 15:04:29,742 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=MTQxYTEwMDUtZTFkMGFhN2MtMTEwNzE4MzAtZjMwZmMzNjc=
2025-11-25 15:04:29,750 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YmI4NDQ2NGMtMWZiN2JjMTktM2Q4Zjk5MjktMjQ4NGJhZWY=
2025-11-25 15:04:29,751 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Yjc1ZTk3MDEtNzMyMTQ4NjAtYmIyYWE5NWQtN2JlZDNhNmY=
2025-11-25 15:04:29,751 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ODZmZDcyNzEtOGVkMTQ1YTYtMjExNWJlMmEtN2ViN2JiNjA=
2025-11-25 15:04:29,753 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=YTdjMjk4NTYtMjI1NGIyYTktY2NlNDEyYTMtMmI1ZjVlYTU=
2025-11-25 15:04:29,754 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=Njc5NTUyOWMtM2E5YjU5NTItYWMxYjYzYjAtYWZmNGZhYTk=
2025-11-25 15:04:29,754 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=NWI4YzBkNTYtMzYxZDRjNGQtM2Q4ZTc5ZjMtZjIzODllMjM=
2025-11-25 15:04:29,754 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZDFkYmRmZTUtNDNiN2IyOS0xZjEwNmM1OS03MTE2MTMyZA==
2025-11-25 15:04:29,833 - DEBUG - ydb.query.pool - acquire: Acquired active session from queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:29,842 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteQuery, f2a5b420-12b1-42ce-9e49-f78131b49955, ghrun-n7olz6xni4.auto.internal:4007): creating call state
2025-11-25 15:04:29,843 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteQuery, f2a5b420-12b1-42ce-9e49-f78131b49955, ghrun-n7olz6xni4.auto.internal:4007): request = { session_id: "ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==" 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-25 15:04:29,844 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteQuery, f2a5b420-12b1-42ce-9e49-f78131b49955, ghrun-n7olz6xni4.auto.internal:4007): response = { <_MultiThreadedRendezvous object> }
2025-11-25 15:04:30,138 - DEBUG - ydb.query.pool - release: Session returned to queue: ydb://session/3?node_id=1&id=ZTNiYjVjODAtYWFhYjk3NDctYTFjNGRjNC1iYWMyZGZkYw==
2025-11-25 15:04:30,139 - INFO - root - test_log_deviation: check insert: 20000 15000
2025-11-25 15:04:30,165 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.4
2025-11-25 15:04:30,166 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.4
2025-11-25 15:04:30,167 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/fvd5/0002c2/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:4007', '-d', '/Root', 'workload', 'log', '--path', 'log', 'clean']' in 'None' (waiting)
2025-11-25 15:04:30,169 - DEBUG - ya.test - execute: Command pid: 3917010
2025-11-25 15:04:30,473 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) rc: 0
2025-11-25 15:04:30,474 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) elapsed time (sec): 0.3031754493713379
2025-11-25 15:04:30,474 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) idrss: 0
2025-11-25 15:04:30,474 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) inblock: 0
2025-11-25 15:04:30,474 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) isrss: 0
2025-11-25 15:04:30,475 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) ixrss: 0
2025-11-25 15:04:30,478 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) majflt: 0
2025-11-25 15:04:30,479 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) maxrss: 799556
2025-11-25 15:04:30,479 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) minflt: 3477
2025-11-25 15:04:30,483 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) msgrcv: 0
2025-11-25 15:04:30,483 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) msgsnd: 0
2025-11-25 15:04:30,483 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) nivcsw: 32
2025-11-25 15:04:30,490 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) nsignals: 0
2025-11-25 15:04:30,491 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) nswap: 0
2025-11-25 15:04:30,491 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) nvcsw: 134
2025-11-25 15:04:30,492 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) oublock: 8
2025-11-25 15:04:30,493 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) stime: 0.024134
2025-11-25 15:04:30,493 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) utime: 0.048267
2025-11-25 15:04:30,493 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) wtime: 0.305
2025-11-25 15:04:30,493 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) output:
Remove path log...
Remove path log...Ok

2025-11-25 15:04:30,494 - DEBUG - ya.test - _save_outputs: Command (pid 3917010) errors:

2025-11-25 15:04:30,515 - INFO - ya.test - pytest_runtest_teardown: Test teardown
