2025-11-05 14:30:01,615 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-05 14:30:01,615 - INFO - ya.test - pytest_runtest_setup: test_clickbench[0]
2025-11-05 14:30:01,615 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-05 14:30:01,616 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-05 14:30:01,686 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd
2025-11-05 14:30:01,687 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13191
2025-11-05 14:30:01,689 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/j3ko/001b65/r3tmp/kikimr_cluster_sewveeuk
2025-11-05 14:30:01,714 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd
2025-11-05 14:30:01,714 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/18293
2025-11-05 14:30:01,714 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/2003
2025-11-05 14:30:01,715 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/24918
2025-11-05 14:30:01,715 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5686
2025-11-05 14:30:01,716 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/kikimr_configs"
2025-11-05 14:30:01,716 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/j3ko/001b65/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/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/node_1/logfile_jy14s3sd.log --grpc-port=18293 --mon-port=2003 --ic-port=13191
2025-11-05 14:30:01,716 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:18293/1, disk_size 68719476736
2025-11-05 14:30:01,717 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/node_1/logfile_jy14s3sd.log', '--grpc-port=18293', '--mon-port=2003', '--ic-port=13191')' in '/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/node_1' (no wait)
2025-11-05 14:30:01,719 - DEBUG - ya.test - execute: Command pid: 986850
2025-11-05 14:30:01,720 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:18293/1
2025-11-05 14:30:05,914 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd
2025-11-05 14:30:05,915 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:18293', '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: 13191\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-11-05 14:30:05,916 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out
2025-11-05 14:30:05,916 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err
2025-11-05 14:30:05,917 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:18293', '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: 13191\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-05 14:30:05,918 - DEBUG - ya.test - execute: Command pid: 987364
2025-11-05 14:30:06,463 - DEBUG - ya.test - _save_outputs: Command (pid 987364) rc: 0
2025-11-05 14:30:06,463 - DEBUG - ya.test - _save_outputs: Command (pid 987364) elapsed time (sec): 0.5434730052947998
2025-11-05 14:30:06,463 - DEBUG - ya.test - _save_outputs: Command (pid 987364) idrss: 0
2025-11-05 14:30:06,463 - DEBUG - ya.test - _save_outputs: Command (pid 987364) inblock: 0
2025-11-05 14:30:06,464 - DEBUG - ya.test - _save_outputs: Command (pid 987364) isrss: 0
2025-11-05 14:30:06,464 - DEBUG - ya.test - _save_outputs: Command (pid 987364) ixrss: 0
2025-11-05 14:30:06,464 - DEBUG - ya.test - _save_outputs: Command (pid 987364) majflt: 0
2025-11-05 14:30:06,464 - DEBUG - ya.test - _save_outputs: Command (pid 987364) maxrss: 620212
2025-11-05 14:30:06,464 - DEBUG - ya.test - _save_outputs: Command (pid 987364) minflt: 43682
2025-11-05 14:30:06,464 - DEBUG - ya.test - _save_outputs: Command (pid 987364) msgrcv: 0
2025-11-05 14:30:06,464 - DEBUG - ya.test - _save_outputs: Command (pid 987364) msgsnd: 0
2025-11-05 14:30:06,465 - DEBUG - ya.test - _save_outputs: Command (pid 987364) nivcsw: 1
2025-11-05 14:30:06,465 - DEBUG - ya.test - _save_outputs: Command (pid 987364) nsignals: 0
2025-11-05 14:30:06,465 - DEBUG - ya.test - _save_outputs: Command (pid 987364) nswap: 0
2025-11-05 14:30:06,465 - DEBUG - ya.test - _save_outputs: Command (pid 987364) nvcsw: 701
2025-11-05 14:30:06,465 - DEBUG - ya.test - _save_outputs: Command (pid 987364) oublock: 8
2025-11-05 14:30:06,466 - DEBUG - ya.test - _save_outputs: Command (pid 987364) stime: 0.199178
2025-11-05 14:30:06,466 - DEBUG - ya.test - _save_outputs: Command (pid 987364) utime: 0.32198499999999997
2025-11-05 14:30:06,466 - DEBUG - ya.test - _save_outputs: Command (pid 987364) wtime: 0.545
2025-11-05 14:30:06,466 - DEBUG - ya.test - _save_outputs: Command (pid 987364) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 4

2025-11-05 14:30:06,466 - DEBUG - ya.test - _save_outputs: Command (pid 987364) errors:

2025-11-05 14:30:06,467 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd
2025-11-05 14:30:06,468 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:18293', '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-05 14:30:06,469 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.0
2025-11-05 14:30:06,469 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.0
2025-11-05 14:30:06,470 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:18293', '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-05 14:30:06,471 - DEBUG - ya.test - execute: Command pid: 987458
2025-11-05 14:30:07,002 - DEBUG - ya.test - _save_outputs: Command (pid 987458) rc: 0
2025-11-05 14:30:07,002 - DEBUG - ya.test - _save_outputs: Command (pid 987458) elapsed time (sec): 0.5301079750061035
2025-11-05 14:30:07,002 - DEBUG - ya.test - _save_outputs: Command (pid 987458) idrss: 0
2025-11-05 14:30:07,002 - DEBUG - ya.test - _save_outputs: Command (pid 987458) inblock: 0
2025-11-05 14:30:07,003 - DEBUG - ya.test - _save_outputs: Command (pid 987458) isrss: 0
2025-11-05 14:30:07,003 - DEBUG - ya.test - _save_outputs: Command (pid 987458) ixrss: 0
2025-11-05 14:30:07,003 - DEBUG - ya.test - _save_outputs: Command (pid 987458) majflt: 0
2025-11-05 14:30:07,003 - DEBUG - ya.test - _save_outputs: Command (pid 987458) maxrss: 620532
2025-11-05 14:30:07,003 - DEBUG - ya.test - _save_outputs: Command (pid 987458) minflt: 43856
2025-11-05 14:30:07,004 - DEBUG - ya.test - _save_outputs: Command (pid 987458) msgrcv: 0
2025-11-05 14:30:07,004 - DEBUG - ya.test - _save_outputs: Command (pid 987458) msgsnd: 0
2025-11-05 14:30:07,004 - DEBUG - ya.test - _save_outputs: Command (pid 987458) nivcsw: 1
2025-11-05 14:30:07,004 - DEBUG - ya.test - _save_outputs: Command (pid 987458) nsignals: 0
2025-11-05 14:30:07,004 - DEBUG - ya.test - _save_outputs: Command (pid 987458) nswap: 0
2025-11-05 14:30:07,004 - DEBUG - ya.test - _save_outputs: Command (pid 987458) nvcsw: 722
2025-11-05 14:30:07,005 - DEBUG - ya.test - _save_outputs: Command (pid 987458) oublock: 8
2025-11-05 14:30:07,005 - DEBUG - ya.test - _save_outputs: Command (pid 987458) stime: 0.194678
2025-11-05 14:30:07,005 - DEBUG - ya.test - _save_outputs: Command (pid 987458) utime: 0.315859
2025-11-05 14:30:07,005 - DEBUG - ya.test - _save_outputs: Command (pid 987458) wtime: 0.531
2025-11-05 14:30:07,006 - DEBUG - ya.test - _save_outputs: Command (pid 987458) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-05 14:30:07,006 - DEBUG - ya.test - _save_outputs: Command (pid 987458) errors:

2025-11-05 14:30:07,006 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain local: {'dynamic_storage_pool:1': 'hdd'}
2025-11-05 14:30:07,032 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-05 14:30:07,552 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd
2025-11-05 14:30:07,552 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13795
2025-11-05 14:30:07,553 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1566
2025-11-05 14:30:07,553 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28297
2025-11-05 14:30:07,554 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13442
2025-11-05 14:30:07,554 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22159
2025-11-05 14:30:07,555 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/kikimr_configs"
2025-11-05 14:30:07,556 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:18293 --tenant=/local/test_db --log-file-name=/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/slot_1/logfile_qamyuu9b.log --grpc-port=13795 --mon-port=1566 --ic-port=28297
2025-11-05 14:30:07,557 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:18293', '--tenant=/local/test_db', '--log-file-name=/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/slot_1/logfile_qamyuu9b.log', '--grpc-port=13795', '--mon-port=1566', '--ic-port=28297')' in '/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/cluster/slot_1' (no wait)
2025-11-05 14:30:07,559 - DEBUG - ya.test - execute: Command pid: 988374
2025-11-05 14:30:07,559 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:13795/1
2025-11-05 14:30:09,566 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydb/ydb
2025-11-05 14:30:09,567 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out
2025-11-05 14:30:09,568 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err
2025-11-05 14:30:09,569 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:18293', '-d', '/local/test_db', 'workload', 'clickbench', '-p', 'olap_yatests/clickbench/hits', 'init', '--store=column']' in 'None' (waiting)
2025-11-05 14:30:09,571 - DEBUG - ya.test - execute: Command pid: 989799
2025-11-05 14:30:17,247 - DEBUG - ya.test - _save_outputs: Command (pid 989799) rc: 0
2025-11-05 14:30:17,248 - DEBUG - ya.test - _save_outputs: Command (pid 989799) elapsed time (sec): 7.675075054168701
2025-11-05 14:30:17,249 - DEBUG - ya.test - _save_outputs: Command (pid 989799) idrss: 0
2025-11-05 14:30:17,250 - DEBUG - ya.test - _save_outputs: Command (pid 989799) inblock: 423784
2025-11-05 14:30:17,251 - DEBUG - ya.test - _save_outputs: Command (pid 989799) isrss: 0
2025-11-05 14:30:17,251 - DEBUG - ya.test - _save_outputs: Command (pid 989799) ixrss: 0
2025-11-05 14:30:17,253 - DEBUG - ya.test - _save_outputs: Command (pid 989799) majflt: 55
2025-11-05 14:30:17,253 - DEBUG - ya.test - _save_outputs: Command (pid 989799) maxrss: 631944
2025-11-05 14:30:17,254 - DEBUG - ya.test - _save_outputs: Command (pid 989799) minflt: 105512
2025-11-05 14:30:17,256 - DEBUG - ya.test - _save_outputs: Command (pid 989799) msgrcv: 0
2025-11-05 14:30:17,256 - DEBUG - ya.test - _save_outputs: Command (pid 989799) msgsnd: 0
2025-11-05 14:30:17,258 - DEBUG - ya.test - _save_outputs: Command (pid 989799) nivcsw: 93
2025-11-05 14:30:17,258 - DEBUG - ya.test - _save_outputs: Command (pid 989799) nsignals: 0
2025-11-05 14:30:17,265 - DEBUG - ya.test - _save_outputs: Command (pid 989799) nswap: 0
2025-11-05 14:30:17,266 - DEBUG - ya.test - _save_outputs: Command (pid 989799) nvcsw: 3364
2025-11-05 14:30:17,267 - DEBUG - ya.test - _save_outputs: Command (pid 989799) oublock: 24
2025-11-05 14:30:17,268 - DEBUG - ya.test - _save_outputs: Command (pid 989799) stime: 0.429695
2025-11-05 14:30:17,269 - DEBUG - ya.test - _save_outputs: Command (pid 989799) utime: 0.26526299999999997
2025-11-05 14:30:17,273 - DEBUG - ya.test - _save_outputs: Command (pid 989799) wtime: 7.677
2025-11-05 14:30:17,274 - DEBUG - ya.test - _save_outputs: Command (pid 989799) output:
Init tables ...
Init tables ...Ok

2025-11-05 14:30:17,275 - DEBUG - ya.test - _save_outputs: Command (pid 989799) errors:
(!) New version of YDB CLI is available. Run 'ydb update' command for update. You can also disable further version checks with 'ydb version --disable-checks' command

2025-11-05 14:30:17,277 - DEBUG - ya.test - verify_sanitize_errors: No sanitizer errors found
2025-11-05 14:30:17,281 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydb/ydb
2025-11-05 14:30:17,287 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.0
2025-11-05 14:30:17,288 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.0
2025-11-05 14:30:17,289 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:18293', '-d', '/local/test_db', 'workload', 'clickbench', '-p', 'olap_yatests/clickbench/hits', 'import', 'files', '--input', '/home/runner/.ya/build/build_root/j3ko/001b65/environment/arcadia/ydb/tests/functional/clickbench/data/hits.csv']' in 'None' (waiting)
2025-11-05 14:30:17,297 - DEBUG - ya.test - execute: Command pid: 994722
2025-11-05 14:30:57,155 - DEBUG - ya.test - _save_outputs: Command (pid 994722) rc: 0
2025-11-05 14:30:57,156 - DEBUG - ya.test - _save_outputs: Command (pid 994722) elapsed time (sec): 39.85771584510803
2025-11-05 14:30:57,156 - DEBUG - ya.test - _save_outputs: Command (pid 994722) idrss: 0
2025-11-05 14:30:57,157 - DEBUG - ya.test - _save_outputs: Command (pid 994722) inblock: 176512
2025-11-05 14:30:57,157 - DEBUG - ya.test - _save_outputs: Command (pid 994722) isrss: 0
2025-11-05 14:30:57,157 - DEBUG - ya.test - _save_outputs: Command (pid 994722) ixrss: 0
2025-11-05 14:30:57,158 - DEBUG - ya.test - _save_outputs: Command (pid 994722) majflt: 0
2025-11-05 14:30:57,158 - DEBUG - ya.test - _save_outputs: Command (pid 994722) maxrss: 632436
2025-11-05 14:30:57,158 - DEBUG - ya.test - _save_outputs: Command (pid 994722) minflt: 483035
2025-11-05 14:30:57,159 - DEBUG - ya.test - _save_outputs: Command (pid 994722) msgrcv: 0
2025-11-05 14:30:57,159 - DEBUG - ya.test - _save_outputs: Command (pid 994722) msgsnd: 0
2025-11-05 14:30:57,159 - DEBUG - ya.test - _save_outputs: Command (pid 994722) nivcsw: 279
2025-11-05 14:30:57,159 - DEBUG - ya.test - _save_outputs: Command (pid 994722) nsignals: 0
2025-11-05 14:30:57,160 - DEBUG - ya.test - _save_outputs: Command (pid 994722) nswap: 0
2025-11-05 14:30:57,160 - DEBUG - ya.test - _save_outputs: Command (pid 994722) nvcsw: 61319
2025-11-05 14:30:57,160 - DEBUG - ya.test - _save_outputs: Command (pid 994722) oublock: 32
2025-11-05 14:30:57,161 - DEBUG - ya.test - _save_outputs: Command (pid 994722) stime: 2.635405
2025-11-05 14:30:57,161 - DEBUG - ya.test - _save_outputs: Command (pid 994722) utime: 3.4562910000000002
2025-11-05 14:30:57,162 - DEBUG - ya.test - _save_outputs: Command (pid 994722) wtime: 39.865
2025-11-05 14:30:57,162 - DEBUG - ya.test - _save_outputs: Command (pid 994722) output:
Fill table hits...
Fill table hits OK 100000 / 99997497 (39.381821s)

2025-11-05 14:30:57,162 - DEBUG - ya.test - _save_outputs: Command (pid 994722) errors:
(!) New version of YDB CLI is available. Run 'ydb update' command for update. You can also disable further version checks with 'ydb version --disable-checks' command


2025-11-05 14:30:57,162 - DEBUG - ya.test - verify_sanitize_errors: No sanitizer errors found
2025-11-05 14:30:57,169 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:30:57,172 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-11-05 14:30:57,183 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 548
2025-11-05 14:30:57,186 - DEBUG - root - check_if_ydb_alive: Expected nodes count: 1
2025-11-05 14:30:57,187 - INFO - root - _create_ydb_driver: Connecting to grpc://localhost:18293 to local/test_db ydb_access_token is set False
2025-11-05 14:30:57,188 - 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')]
2025-11-05 14:30:57,191 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-05 14:30:57,194 - 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')]
2025-11-05 14:30:57,207 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local/test_db
2025-11-05 14:30:57,208 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 37c7f0db-c32a-4882-94e3-e59ecbf29071, localhost:18293): creating call state
2025-11-05 14:30:57,210 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 37c7f0db-c32a-4882-94e3-e59ecbf29071, localhost:18293): request = { database: "local/test_db" }
2025-11-05 14:30:57,215 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 37c7f0db-c32a-4882-94e3-e59ecbf29071, localhost:18293): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-uqiopzyque.auto.internal" port: 13795 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" node_id: 50000 } self_location: "1" } } } }
2025-11-05 14:30:57,216 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local/test_db: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-uqiopzyque.auto.internal:13795, location , ssl: False>]>
2025-11-05 14:30:57,216 - 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')]
2025-11-05 14:30:57,222 - INFO - ydb.connection - close: Closing channel for endpoint localhost:18293
2025-11-05 14:30:57,223 - INFO - root - _create_ydb_driver: Connected
2025-11-05 14:30:57,224 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, c23870d4-455d-45cf-a3ea-4b7419410c79, ghrun-uqiopzyque.auto.internal:13795): creating call state
2025-11-05 14:30:57,225 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, c23870d4-455d-45cf-a3ea-4b7419410c79, ghrun-uqiopzyque.auto.internal:13795): request = { query { yql_text: "select 1" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-11-05 14:30:57,227 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, c23870d4-455d-45cf-a3ea-4b7419410c79, ghrun-uqiopzyque.auto.internal:13795): response = { <_MultiThreadedRendezvous object> }
2025-11-05 14:30:57,383 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:30:57,391 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes HTTP/1.1" 200 780
2025-11-05 14:30:57,396 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_clickbench.py::TestClickbench, test_name: test_clickbench[0])
2025-11-05 14:30:57,400 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:30:57,403 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-11-05 14:30:57,414 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 548
2025-11-05 14:30:57,416 - DEBUG - root - check_if_ydb_alive: Expected nodes count: 1
2025-11-05 14:30:57,417 - INFO - root - _get_tables: get_tables /local/test_db/olap_yatests/clickbench/hits
2025-11-05 14:30:57,417 - INFO - root - _describe_path_impl: describe /local/test_db/olap_yatests/clickbench/hits
2025-11-05 14:30:57,418 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 0b4a0034-1396-4160-9f30-882a2e46620f, ghrun-uqiopzyque.auto.internal:13795): creating call state
2025-11-05 14:30:57,418 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 0b4a0034-1396-4160-9f30-882a2e46620f, ghrun-uqiopzyque.auto.internal:13795): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/local/test_db/olap_yatests/clickbench/hits" }
2025-11-05 14:30:57,426 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 0b4a0034-1396-4160-9f30-882a2e46620f, ghrun-uqiopzyque.auto.internal:13795): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Scheme.DescribePathResult] { self { name: "hits" owner: "root@builtin" type: COLUMN_TABLE effective_permissions { subject: "USERS" permission_names: "ydb.database.connect" } effective_permissions { subject: "METADATA-READERS" permission_names: "ydb.generic.list" } effective_permissions { subject: "DATA-READERS" permission_names: "ydb.granular.select_row" } effective_permissions { subject: "DATA-WRITERS" permission_names: "ydb.tables.modify" } effective_permissions { subject: "DDL-ADMINS" permission_names: "ydb.granular.create_directory" permission_names: "ydb.granular.write_attributes" permission_names: "ydb.granular.create_table" permission_names: "ydb.granular.remove_schema" permission_names: "ydb.granular.create_queue" permission_names: "ydb.granular.alter_schema" } effective_permissions { subject: "ACCESS-ADMINS" permission_names: "ydb.access.grant" } effective_permissions { subject: "DATABASE-ADMINS" permission_names: "ydb.generic.manage" } created_at { plan_step: 1762353015970 tx_id: 281474976720659 } } } } } }
2025-11-05 14:30:57,431 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:30:57,434 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/clickbench/hits&tablets=true HTTP/1.1" 307 0
2025-11-05 14:30:57,445 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/clickbench/hits&tablets=true HTTP/1.1" 200 578
2025-11-05 14:30:57,447 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/clickbench/hits balance: 128-128 shards.
2025-11-05 14:30:57,449 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, 85354a72-1c13-46ce-a4dd-ed243d573e22, ghrun-uqiopzyque.auto.internal:13795): creating call state
2025-11-05 14:30:57,449 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, 85354a72-1c13-46ce-a4dd-ed243d573e22, ghrun-uqiopzyque.auto.internal:13795): request = { query { yql_text: "select 1" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-11-05 14:30:57,451 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, 85354a72-1c13-46ce-a4dd-ed243d573e22, ghrun-uqiopzyque.auto.internal:13795): response = { <_MultiThreadedRendezvous object> }
2025-11-05 14:30:57,519 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:30:57,522 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-11-05 14:30:57,531 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 548
2025-11-05 14:30:57,533 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydb/ydb
2025-11-05 14:30:57,534 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.1
2025-11-05 14:30:57,535 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.1
2025-11-05 14:30:57,535 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/j3ko/001b65/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:18293', '-d', '/local/test_db', 'workload', 'clickbench', '--path', 'olap_yatests/clickbench/hits', 'run', '--json', '/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/q0.json', '--output', '/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/q0.out', '--executer', 'generic', '--include', '0', '--iterations', '1', '--plan', '/home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/q0.plan', '--global-timeout', '1800.0s', '--verbose']' in 'None' (waiting)
2025-11-05 14:30:57,537 - DEBUG - ya.test - execute: Command pid: 1004944
2025-11-05 14:31:02,037 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) rc: 0
2025-11-05 14:31:02,037 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) elapsed time (sec): 4.499297618865967
2025-11-05 14:31:02,037 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) idrss: 0
2025-11-05 14:31:02,038 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) inblock: 0
2025-11-05 14:31:02,038 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) isrss: 0
2025-11-05 14:31:02,038 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) ixrss: 0
2025-11-05 14:31:02,038 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) majflt: 1
2025-11-05 14:31:02,039 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) maxrss: 635256
2025-11-05 14:31:02,039 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) minflt: 98205
2025-11-05 14:31:02,039 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) msgrcv: 0
2025-11-05 14:31:02,039 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) msgsnd: 0
2025-11-05 14:31:02,040 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) nivcsw: 8
2025-11-05 14:31:02,040 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) nsignals: 0
2025-11-05 14:31:02,040 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) nswap: 0
2025-11-05 14:31:02,040 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) nvcsw: 2474
2025-11-05 14:31:02,041 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) oublock: 344
2025-11-05 14:31:02,041 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) stime: 0.19641399999999998
2025-11-05 14:31:02,041 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) utime: 0.223847
2025-11-05 14:31:02,042 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) wtime: 4.501
2025-11-05 14:31:02,042 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) output:
Query00:
Query text:
SELECT COUNT(*) FROM `olap_yatests/clickbench/hits`

	iteration 0:	ok	3.554615s seconds

Results for 1 iterations
┌─────────┬──────────┬─────────┬─────────┬─────────┬─────────┬───────────┬─────────┬─────────┬─────────┬─────────┬──────────────┬────────────┬────────────┐
│ Query # │ ColdTime │ Min     │ Max     │ Mean    │ Median  │ UnixBench │ Std     │ RttMin  │ RttMax  │ RttAvg  │ SuccessCount │ FailsCount │ DiffsCount │
├─────────┼──────────┼─────────┼─────────┼─────────┼─────────┼───────────┼─────────┼─────────┼─────────┼─────────┼──────────────┼────────────┼────────────┤
│ Query00 │   3.462  │   3.462 │   3.462 │   3.461 │   3.461 │   3.462   │   0.000 │   0.093 │   0.093 │   0.092 │ 1            │            │            │
├─────────┼──────────┼─────────┼─────────┼─────────┼─────────┼───────────┼─────────┼─────────┼─────────┼─────────┼──────────────┼────────────┼────────────┤
│ Sum     │   3.462  │   3.462 │   3.462 │   3.461 │   3.461 │   3.462   │   0.000 │   0.093 │   0.093 │   0.092 │ 1            │            │            │
├─────────┼──────────┼─────────┼─────────┼─────────┼─────────┼───────────┼─────────┼─────────┼─────────┼─────────┼──────────────┼────────────┼────────────┤
│ Avg     │   3.462  │   3.462 │   3.462 │   3.461 │   3.461 │   3.462   │   0.000 │   0.093 │   0.093 │   0.092 │ 1            │            │            │
├─────────┼──────────┼─────────┼─────────┼─────────┼─────────┼───────────┼─────────┼─────────┼─────────┼─────────┼──────────────┼────────────┼────────────┤
│ GAvg    │   3.462  │   3.462 │   3.462 │   3.461 │   3.461 │   3.462   │   0.000 │   0.093 │   0.093 │   0.001 │ 1            │            │            │
└─────────┴──────────┴─────────┴─────────┴─────────┴─────────┴───────────┴─────────┴─────────┴─────────┴─────────┴──────────────┴────────────┴────────────┘

Results saved to /home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/q0.out
Json report saved to /home/runner/.ya/build/build_root/j3ko/001b65/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_clickbench/testing_out_stuff/test_clickbench.py.TestClickbench.test_clickbench.0/q0.json

2025-11-05 14:31:02,043 - DEBUG - ya.test - _save_outputs: Command (pid 1004944) errors:
(!) New version of YDB CLI is available. Run 'ydb update' command for update. You can also disable further version checks with 'ydb version --disable-checks' command

[K|Progress: 0 rows read, 0 B read.
[K
[K|Progress: 0 rows read, 0 B read.
[K/Progress: 810 rows read, 13K B read.
[K-Progress: 810 rows read, 13K B read.
[K
2025-11-05 14:31:02,043 - DEBUG - ya.test - verify_sanitize_errors: No sanitizer errors found
2025-11-05 14:31:02,047 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:31:02,050 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-11-05 14:31:02,062 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 548
2025-11-05 14:31:02,072 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:31:02,077 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-11-05 14:31:02,087 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 548
2025-11-05 14:31:02,091 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2003
2025-11-05 14:31:02,097 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2003 "GET /viewer/json/nodes HTTP/1.1" 200 785
2025-11-05 14:31:02,861 - INFO - ya.test - pytest_runtest_teardown: Test teardown
