2025-12-12 09:08:57,686 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 09:08:57,686 - INFO - ya.test - pytest_runtest_setup: test_tpch[1]
2025-12-12 09:08:57,687 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 09:08:57,687 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-12-12 09:08:57,812 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd
2025-12-12 09:08:57,813 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/30996
2025-12-12 09:08:57,815 - DEBUG - ydb.tests.library.harness.kikimr_runner - start: Working directory: /home/runner/.ya/build/build_root/yq5c/0003f4/r3tmp/kikimr_cluster_0eaaiaj1
2025-12-12 09:08:57,858 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd
2025-12-12 09:08:57,859 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13953
2025-12-12 09:08:57,860 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/2876
2025-12-12 09:08:57,860 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/15504
2025-12-12 09:08:57,861 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/3856
2025-12-12 09:08:57,862 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/kikimr_configs"
2025-12-12 09:08:57,862 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/yq5c/0003f4/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/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/node_1/logfile_feevs977.log --grpc-port=13953 --mon-port=2876 --ic-port=30996
2025-12-12 09:08:57,863 - DEBUG - ydb.tests.library.harness.kikimr_runner - format_pdisk: Formatting pdisk SectorMap:1:64 on node localhost:13953/1, disk_size 68719476736
2025-12-12 09:08:57,864 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/node_1/logfile_feevs977.log', '--grpc-port=13953', '--mon-port=2876', '--ic-port=30996')' in '/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/node_1' (no wait)
2025-12-12 09:08:57,867 - DEBUG - ya.test - execute: Command pid: 1194645
2025-12-12 09:08:57,869 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:13953/1
2025-12-12 09:09:05,442 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd
2025-12-12 09:09:05,442 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13953', '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: 30996\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']
2025-12-12 09:09:05,443 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out
2025-12-12 09:09:05,444 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err
2025-12-12 09:09:05,444 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13953', '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: 30996\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-12-12 09:09:05,458 - DEBUG - ya.test - execute: Command pid: 1197292
2025-12-12 09:09:06,484 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) rc: 0
2025-12-12 09:09:06,485 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) elapsed time (sec): 1.0251727104187012
2025-12-12 09:09:06,485 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) idrss: 0
2025-12-12 09:09:06,485 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) inblock: 0
2025-12-12 09:09:06,486 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) isrss: 0
2025-12-12 09:09:06,486 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) ixrss: 0
2025-12-12 09:09:06,486 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) majflt: 0
2025-12-12 09:09:06,487 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) maxrss: 579188
2025-12-12 09:09:06,487 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) minflt: 42244
2025-12-12 09:09:06,487 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) msgrcv: 0
2025-12-12 09:09:06,487 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) msgsnd: 0
2025-12-12 09:09:06,488 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) nivcsw: 143
2025-12-12 09:09:06,488 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) nsignals: 0
2025-12-12 09:09:06,488 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) nswap: 0
2025-12-12 09:09:06,489 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) nvcsw: 1082
2025-12-12 09:09:06,489 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) oublock: 8
2025-12-12 09:09:06,489 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) stime: 0.229598
2025-12-12 09:09:06,490 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) utime: 0.5185989999999999
2025-12-12 09:09:06,490 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) wtime: 1.039
2025-12-12 09:09:06,490 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-12-12 09:09:06,491 - DEBUG - ya.test - _save_outputs: Command (pid 1197292) errors:

2025-12-12 09:09:06,492 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd
2025-12-12 09:09:06,493 - DEBUG - ydb.tests.library.harness.kikimr_runner - __call_kikimr_new_cli: Executing command = ['/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13953', '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-12-12 09:09:06,498 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.0
2025-12-12 09:09:06,499 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.0
2025-12-12 09:09:06,499 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13953', '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-12-12 09:09:06,504 - DEBUG - ya.test - execute: Command pid: 1197589
2025-12-12 09:09:07,254 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) rc: 0
2025-12-12 09:09:07,255 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) elapsed time (sec): 0.7491872310638428
2025-12-12 09:09:07,255 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) idrss: 0
2025-12-12 09:09:07,255 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) inblock: 0
2025-12-12 09:09:07,256 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) isrss: 0
2025-12-12 09:09:07,256 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) ixrss: 0
2025-12-12 09:09:07,256 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) majflt: 0
2025-12-12 09:09:07,257 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) maxrss: 580000
2025-12-12 09:09:07,257 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) minflt: 42408
2025-12-12 09:09:07,257 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) msgrcv: 0
2025-12-12 09:09:07,257 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) msgsnd: 0
2025-12-12 09:09:07,258 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) nivcsw: 122
2025-12-12 09:09:07,258 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) nsignals: 0
2025-12-12 09:09:07,258 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) nswap: 0
2025-12-12 09:09:07,258 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) nvcsw: 672
2025-12-12 09:09:07,259 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) oublock: 8
2025-12-12 09:09:07,259 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) stime: 0.230648
2025-12-12 09:09:07,259 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) utime: 0.429042
2025-12-12 09:09:07,260 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) wtime: 0.754
2025-12-12 09:09:07,260 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 6

2025-12-12 09:09:07,260 - DEBUG - ya.test - _save_outputs: Command (pid 1197589) errors:

2025-12-12 09:09:07,490 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-12-12 09:09:08,038 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd
2025-12-12 09:09:08,038 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/18804
2025-12-12 09:09:08,040 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/26807
2025-12-12 09:09:08,041 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/25853
2025-12-12 09:09:08,041 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/24154
2025-12-12 09:09:08,052 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/15686
2025-12-12 09:09:08,053 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/kikimr_configs"
2025-12-12 09:09:08,066 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:13953 --tenant=/local/test_db --log-file-name=/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/slot_1/logfile_6sajpv6f.log --grpc-port=18804 --mon-port=26807 --ic-port=25853
2025-12-12 09:09:08,068 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/kikimr_configs/config.yaml', '--node-broker=localhost:13953', '--tenant=/local/test_db', '--log-file-name=/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/slot_1/logfile_6sajpv6f.log', '--grpc-port=18804', '--mon-port=26807', '--ic-port=25853')' in '/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/cluster/slot_1' (no wait)
2025-12-12 09:09:08,082 - DEBUG - ya.test - execute: Command pid: 1198230
2025-12-12 09:09:08,088 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:18804/1
2025-12-12 09:09:14,125 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydb/ydb
2025-12-12 09:09:14,127 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out
2025-12-12 09:09:14,127 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err
2025-12-12 09:09:14,128 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:13953', '-d', '/local/test_db', 'workload', 'tpch', '-p', 'olap_yatests/tpch/s1', 'init', '--store=column']' in 'None' (waiting)
2025-12-12 09:09:14,142 - DEBUG - ya.test - execute: Command pid: 1199566
2025-12-12 09:09:30,706 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) rc: 0
2025-12-12 09:09:30,706 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) elapsed time (sec): 16.54522204399109
2025-12-12 09:09:30,707 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) idrss: 0
2025-12-12 09:09:30,707 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) inblock: 0
2025-12-12 09:09:30,707 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) isrss: 0
2025-12-12 09:09:30,708 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) ixrss: 0
2025-12-12 09:09:30,708 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) majflt: 0
2025-12-12 09:09:30,708 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) maxrss: 593048
2025-12-12 09:09:30,709 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) minflt: 101974
2025-12-12 09:09:30,709 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) msgrcv: 0
2025-12-12 09:09:30,709 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) msgsnd: 0
2025-12-12 09:09:30,714 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) nivcsw: 115
2025-12-12 09:09:30,715 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) nsignals: 0
2025-12-12 09:09:30,716 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) nswap: 0
2025-12-12 09:09:30,716 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) nvcsw: 2849
2025-12-12 09:09:30,717 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) oublock: 16
2025-12-12 09:09:30,718 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) stime: 0.192073
2025-12-12 09:09:30,718 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) utime: 0.304179
2025-12-12 09:09:30,719 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) wtime: 16.575
2025-12-12 09:09:30,728 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) output:
Init tables ...
Init tables ...Ok

2025-12-12 09:09:30,733 - DEBUG - ya.test - _save_outputs: Command (pid 1199566) 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-12-12 09:09:30,737 - DEBUG - ya.test - verify_sanitize_errors: No sanitizer errors found
2025-12-12 09:09:30,751 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydb/ydb
2025-12-12 09:09:30,753 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.0
2025-12-12 09:09:30,765 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.0
2025-12-12 09:09:30,778 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:13953', '-d', '/local/test_db', 'workload', 'tpch', '-p', 'olap_yatests/tpch/s1', 'import', 'generator', '--scale=1']' in 'None' (waiting)
2025-12-12 09:09:30,786 - DEBUG - ya.test - execute: Command pid: 1201900
2025-12-12 09:14:24,886 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) rc: 0
2025-12-12 09:14:24,887 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) elapsed time (sec): 294.0993809700012
2025-12-12 09:14:24,887 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) idrss: 0
2025-12-12 09:14:24,887 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) inblock: 0
2025-12-12 09:14:24,888 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) isrss: 0
2025-12-12 09:14:24,888 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) ixrss: 0
2025-12-12 09:14:24,888 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) majflt: 0
2025-12-12 09:14:24,889 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) maxrss: 2307848
2025-12-12 09:14:24,889 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) minflt: 4838904
2025-12-12 09:14:24,890 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) msgrcv: 0
2025-12-12 09:14:24,890 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) msgsnd: 0
2025-12-12 09:14:24,890 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) nivcsw: 33145
2025-12-12 09:14:24,890 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) nsignals: 0
2025-12-12 09:14:24,891 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) nswap: 0
2025-12-12 09:14:24,891 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) nvcsw: 1062960
2025-12-12 09:14:24,891 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) oublock: 32
2025-12-12 09:14:24,892 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) stime: 32.730601
2025-12-12 09:14:24,892 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) utime: 219.443199
2025-12-12 09:14:24,892 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) wtime: 294.108
2025-12-12 09:14:24,893 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) output:
Fill table supplier...
Fill table supplier OK 10000 / 10000 (13.505592s)
Fill table customer...
Fill table customer OK 150000 / 150000 (2.995857s)
Fill table orders...
Fill table orders OK 1500000 / 1500000 (264.459152s)
Fill table part...
Fill table part OK 200000 / 200000 (10.934370s)
Fill table nation...
Fill table nation OK 25 / 25 (0.591104s)
Fill table region...
Fill table region OK 5 / 5 (0.300977s)

2025-12-12 09:14:24,893 - DEBUG - ya.test - _save_outputs: Command (pid 1201900) 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-12-12 09:14:24,894 - DEBUG - ya.test - verify_sanitize_errors: No sanitizer errors found
2025-12-12 09:14:24,902 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:24,906 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-12-12 09:14:24,918 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 551
2025-12-12 09:14:24,921 - DEBUG - root - check_if_ydb_alive: Expected nodes count: 1
2025-12-12 09:14:24,922 - INFO - root - _create_ydb_driver: Connecting to grpc://localhost:13953 to local/test_db ydb_access_token is set False
2025-12-12 09:14:24,922 - 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-12-12 09:14:24,925 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 09:14:24,927 - 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-12-12 09:14:24,954 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local/test_db
2025-12-12 09:14:24,955 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, d89fad40-1854-4466-ad28-6149d403ae4c, localhost:13953): creating call state
2025-12-12 09:14:24,956 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, d89fad40-1854-4466-ad28-6149d403ae4c, localhost:13953): request = { database: "local/test_db" }
2025-12-12 09:14:24,962 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, d89fad40-1854-4466-ad28-6149d403ae4c, localhost:13953): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-7uza2v6l2u.auto.internal" port: 18804 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" node_id: 50000 } self_location: "1" } } } }
2025-12-12 09:14:24,963 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local/test_db: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-7uza2v6l2u.auto.internal:18804, location , ssl: False>]>
2025-12-12 09:14:24,963 - 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-12-12 09:14:24,970 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13953
2025-12-12 09:14:24,971 - INFO - root - _create_ydb_driver: Connected
2025-12-12 09:14:24,973 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, b40a5646-4620-41a3-bfe8-c7500b9f0177, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:24,974 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, b40a5646-4620-41a3-bfe8-c7500b9f0177, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "select 1" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:24,976 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, b40a5646-4620-41a3-bfe8-c7500b9f0177, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:25,116 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,120 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-12-12 09:14:25,132 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 551
2025-12-12 09:14:25,134 - DEBUG - root - check_if_ydb_alive: Expected nodes count: 1
2025-12-12 09:14:25,135 - INFO - root - _get_tables: get_tables /local/test_db/olap_yatests/tpch/s1
2025-12-12 09:14:25,135 - INFO - root - _describe_path_impl: describe /local/test_db/olap_yatests/tpch/s1
2025-12-12 09:14:25,136 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 7e42e1dd-bcc9-4715-8dc6-de95b69df5e9, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:25,137 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 7e42e1dd-bcc9-4715-8dc6-de95b69df5e9, ghrun-7uza2v6l2u.auto.internal:18804): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/local/test_db/olap_yatests/tpch/s1" }
2025-12-12 09:14:25,145 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 7e42e1dd-bcc9-4715-8dc6-de95b69df5e9, ghrun-7uza2v6l2u.auto.internal:18804): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Scheme.DescribePathResult] { self { name: "s1" owner: "root@builtin" type: DIRECTORY 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: 1765530557590 tx_id: 281474976720659 } } } } } }
2025-12-12 09:14:25,146 - INFO - root - list_directory: list /local/test_db/olap_yatests/tpch/s1
2025-12-12 09:14:25,146 - DEBUG - ydb.connection - _prepare_call: RpcState(ListDirectory, 8ee78cf6-cbb2-421c-94ad-77dc15884a71, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:25,147 - DEBUG - ydb.connection - _log_request: RpcState(ListDirectory, 8ee78cf6-cbb2-421c-94ad-77dc15884a71, ghrun-7uza2v6l2u.auto.internal:18804): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/local/test_db/olap_yatests/tpch/s1" }
2025-12-12 09:14:25,158 - DEBUG - ydb.connection - _log_response: RpcState(ListDirectory, 8ee78cf6-cbb2-421c-94ad-77dc15884a71, ghrun-7uza2v6l2u.auto.internal:18804): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Scheme.ListDirectoryResult] { self { name: "s1" owner: "root@builtin" type: DIRECTORY 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: 1765530557590 tx_id: 281474976720659 } } children { name: "customer" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530557590 tx_id: 281474976720659 } } children { name: "lineitem" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530560320 tx_id: 281474976720660 } } children { name: "nation" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530560780 tx_id: 281474976720661 } } children { name: "orders" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530563130 tx_id: 281474976720662 } } children { name: "part" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530565480 tx_id: 281474976720663 } } children { name: "partsupp" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530567530 tx_id: 281474976720664 } } children { name: "region" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530568040 tx_id: 281474976720665 } } children { name: "supplier" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530570120 tx_id: 281474976720666 } } } } } }
2025-12-12 09:14:25,167 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,171 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/customer&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,185 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/customer&tablets=true HTTP/1.1" 200 580
2025-12-12 09:14:25,187 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/customer balance: 64-64 shards.
2025-12-12 09:14:25,191 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,194 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/lineitem&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,205 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/lineitem&tablets=true HTTP/1.1" 200 580
2025-12-12 09:14:25,208 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/lineitem balance: 64-64 shards.
2025-12-12 09:14:25,212 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,216 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/nation&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,230 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/nation&tablets=true HTTP/1.1" 200 579
2025-12-12 09:14:25,233 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/nation balance: 1-1 shards.
2025-12-12 09:14:25,236 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,240 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/orders&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,252 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/orders&tablets=true HTTP/1.1" 200 580
2025-12-12 09:14:25,255 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/orders balance: 64-64 shards.
2025-12-12 09:14:25,258 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,261 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/part&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,272 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/part&tablets=true HTTP/1.1" 200 580
2025-12-12 09:14:25,275 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/part balance: 64-64 shards.
2025-12-12 09:14:25,278 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,281 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/partsupp&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,291 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/partsupp&tablets=true HTTP/1.1" 200 580
2025-12-12 09:14:25,293 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/partsupp balance: 64-64 shards.
2025-12-12 09:14:25,297 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,300 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/region&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,313 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/region&tablets=true HTTP/1.1" 200 579
2025-12-12 09:14:25,315 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/region balance: 1-1 shards.
2025-12-12 09:14:25,319 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:25,322 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/supplier&tablets=true HTTP/1.1" 307 0
2025-12-12 09:14:25,340 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/supplier&tablets=true HTTP/1.1" 200 580
2025-12-12 09:14:25,342 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/supplier balance: 64-64 shards.
2025-12-12 09:14:25,344 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, e9a6a99a-48ef-43fa-8a98-66bb64833d6e, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:25,345 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, e9a6a99a-48ef-43fa-8a98-66bb64833d6e, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "select 1" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:25,350 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, e9a6a99a-48ef-43fa-8a98-66bb64833d6e, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:25,421 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, 3dd5c2b8-04c4-4e46-afbd-1dfd8fcd99a8, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:25,422 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, 3dd5c2b8-04c4-4e46-afbd-1dfd8fcd99a8, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/customer`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:25,423 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, 3dd5c2b8-04c4-4e46-afbd-1dfd8fcd99a8, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:26,877 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, 1854c613-0e6b-4c32-afa0-2f68b21dcd5f, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:26,878 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, 1854c613-0e6b-4c32-afa0-2f68b21dcd5f, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/nation`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:26,881 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, 1854c613-0e6b-4c32-afa0-2f68b21dcd5f, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:27,643 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, aa16288c-5d5b-44ec-8ac6-dff786efbd55, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:27,644 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, aa16288c-5d5b-44ec-8ac6-dff786efbd55, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/orders`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:27,646 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, aa16288c-5d5b-44ec-8ac6-dff786efbd55, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:37,058 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, b2435253-763e-4181-afeb-d7c62f1b3ca7, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:37,058 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, b2435253-763e-4181-afeb-d7c62f1b3ca7, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/part`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:37,060 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, b2435253-763e-4181-afeb-d7c62f1b3ca7, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:37,867 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, 1deeb1c7-ca7e-4563-9ad8-e79e0e128898, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:37,867 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, 1deeb1c7-ca7e-4563-9ad8-e79e0e128898, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/partsupp`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:37,869 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, 1deeb1c7-ca7e-4563-9ad8-e79e0e128898, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:38,679 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, a170ce14-5e73-4163-a554-682eb0768c68, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:38,680 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, a170ce14-5e73-4163-a554-682eb0768c68, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/region`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:38,683 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, a170ce14-5e73-4163-a554-682eb0768c68, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:39,581 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, f60de5ed-cf39-49a0-b51c-65dd6b048324, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:39,583 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, f60de5ed-cf39-49a0-b51c-65dd6b048324, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/supplier`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:39,585 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, f60de5ed-cf39-49a0-b51c-65dd6b048324, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:40,369 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, 57bf72af-e950-4373-b776-f66a687da6fd, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:14:40,370 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, 57bf72af-e950-4373-b776-f66a687da6fd, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "SELECT count(*) FROM `/local/test_db/olap_yatests/tpch/s1/lineitem`" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:14:40,372 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, 57bf72af-e950-4373-b776-f66a687da6fd, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:14:59,776 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:59,784 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes HTTP/1.1" 200 779
2025-12-12 09:14:59,789 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:14:59,793 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-12-12 09:14:59,802 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 551
2025-12-12 09:15:00,577 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,584 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes HTTP/1.1" 200 781
2025-12-12 09:15:00,589 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:13953/1
2025-12-12 09:15:00,590 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:18804/1
2025-12-12 09:15:00,595 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_tpch.py::TestTpchS1, test_name: test_tpch[1])
2025-12-12 09:15:00,599 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,603 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-12-12 09:15:00,614 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 554
2025-12-12 09:15:00,621 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,625 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-12-12 09:15:00,635 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 554
2025-12-12 09:15:00,638 - DEBUG - root - check_if_ydb_alive: Expected nodes count: 1
2025-12-12 09:15:00,639 - INFO - root - _get_tables: get_tables /local/test_db/olap_yatests/tpch/s1
2025-12-12 09:15:00,639 - INFO - root - _describe_path_impl: describe /local/test_db/olap_yatests/tpch/s1
2025-12-12 09:15:00,640 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, ee831c2e-82ad-4ecc-9f22-6acc8ede6d73, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:15:00,641 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, ee831c2e-82ad-4ecc-9f22-6acc8ede6d73, ghrun-7uza2v6l2u.auto.internal:18804): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/local/test_db/olap_yatests/tpch/s1" }
2025-12-12 09:15:00,647 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, ee831c2e-82ad-4ecc-9f22-6acc8ede6d73, ghrun-7uza2v6l2u.auto.internal:18804): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Scheme.DescribePathResult] { self { name: "s1" owner: "root@builtin" type: DIRECTORY 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: 1765530557590 tx_id: 281474976720659 } } } } } }
2025-12-12 09:15:00,650 - INFO - root - list_directory: list /local/test_db/olap_yatests/tpch/s1
2025-12-12 09:15:00,651 - DEBUG - ydb.connection - _prepare_call: RpcState(ListDirectory, 7735c434-a9da-43b4-b606-23126061ee27, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:15:00,652 - DEBUG - ydb.connection - _log_request: RpcState(ListDirectory, 7735c434-a9da-43b4-b606-23126061ee27, ghrun-7uza2v6l2u.auto.internal:18804): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/local/test_db/olap_yatests/tpch/s1" }
2025-12-12 09:15:00,659 - DEBUG - ydb.connection - _log_response: RpcState(ListDirectory, 7735c434-a9da-43b4-b606-23126061ee27, ghrun-7uza2v6l2u.auto.internal:18804): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Scheme.ListDirectoryResult] { self { name: "s1" owner: "root@builtin" type: DIRECTORY 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: 1765530557590 tx_id: 281474976720659 } } children { name: "customer" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530557590 tx_id: 281474976720659 } } children { name: "lineitem" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530560320 tx_id: 281474976720660 } } children { name: "nation" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530560780 tx_id: 281474976720661 } } children { name: "orders" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530563130 tx_id: 281474976720662 } } children { name: "part" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530565480 tx_id: 281474976720663 } } children { name: "partsupp" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530567530 tx_id: 281474976720664 } } children { name: "region" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530568040 tx_id: 281474976720665 } } children { name: "supplier" owner: "root@builtin" type: COLUMN_TABLE created_at { plan_step: 1765530570120 tx_id: 281474976720666 } } } } } }
2025-12-12 09:15:00,664 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,668 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/customer&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,681 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/customer&tablets=true HTTP/1.1" 200 586
2025-12-12 09:15:00,684 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/customer balance: 64-64 shards.
2025-12-12 09:15:00,688 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,692 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/lineitem&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,704 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/lineitem&tablets=true HTTP/1.1" 200 586
2025-12-12 09:15:00,707 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/lineitem balance: 64-64 shards.
2025-12-12 09:15:00,710 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,714 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/nation&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,727 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/nation&tablets=true HTTP/1.1" 200 584
2025-12-12 09:15:00,730 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/nation balance: 1-1 shards.
2025-12-12 09:15:00,733 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,736 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/orders&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,750 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/orders&tablets=true HTTP/1.1" 200 585
2025-12-12 09:15:00,753 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/orders balance: 64-64 shards.
2025-12-12 09:15:00,756 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,759 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/part&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,772 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/part&tablets=true HTTP/1.1" 200 585
2025-12-12 09:15:00,774 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/part balance: 64-64 shards.
2025-12-12 09:15:00,778 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,781 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/partsupp&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,792 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/partsupp&tablets=true HTTP/1.1" 200 585
2025-12-12 09:15:00,794 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/partsupp balance: 64-64 shards.
2025-12-12 09:15:00,797 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,801 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/region&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,811 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/region&tablets=true HTTP/1.1" 200 584
2025-12-12 09:15:00,813 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/region balance: 1-1 shards.
2025-12-12 09:15:00,816 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:00,820 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/supplier&tablets=true HTTP/1.1" 307 0
2025-12-12 09:15:00,830 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db&path=/local/test_db/olap_yatests/tpch/s1/supplier&tablets=true HTTP/1.1" 200 585
2025-12-12 09:15:00,833 - INFO - root - check_if_ydb_alive: Table /local/test_db/olap_yatests/tpch/s1/supplier balance: 64-64 shards.
2025-12-12 09:15:00,834 - DEBUG - ydb.connection - _prepare_call: RpcState(StreamExecuteScanQuery, 022b1bd3-4cef-48b1-bd3e-8136f428fbf5, ghrun-7uza2v6l2u.auto.internal:18804): creating call state
2025-12-12 09:15:00,835 - DEBUG - ydb.connection - _log_request: RpcState(StreamExecuteScanQuery, 022b1bd3-4cef-48b1-bd3e-8136f428fbf5, ghrun-7uza2v6l2u.auto.internal:18804): request = { query { yql_text: "select 1" } mode: MODE_EXEC collect_stats: STATS_COLLECTION_NONE }
2025-12-12 09:15:00,837 - DEBUG - ydb.connection - _log_response: RpcState(StreamExecuteScanQuery, 022b1bd3-4cef-48b1-bd3e-8136f428fbf5, ghrun-7uza2v6l2u.auto.internal:18804): response = { <_MultiThreadedRendezvous object> }
2025-12-12 09:15:00,908 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydb/ydb
2025-12-12 09:15:00,910 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydb.out.1
2025-12-12 09:15:00,910 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydb.err.1
2025-12-12 09:15:00,911 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/apps/ydb/ydb', '-e', 'grpc://localhost:13953', '-d', '/local/test_db', 'workload', 'tpch', '--path', 'olap_yatests/tpch/s1', 'run', '--json', '/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/q1.json', '--output', '/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/q1.out', '--executer', 'generic', '--include', '1', '--iterations', '1', '--plan', '/home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/q1.plan', '--global-timeout', '1800.0s', '--verbose', '--check-canonical', '--scale', '1']' in 'None' (waiting)
2025-12-12 09:15:00,913 - DEBUG - ya.test - execute: Command pid: 1236400
2025-12-12 09:15:33,736 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 09:15:33,736 - 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-12-12 09:15:33,750 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local/test_db
2025-12-12 09:15:33,751 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 049696c6-7512-489d-a988-6d69b121eee5, localhost:13953): creating call state
2025-12-12 09:15:33,751 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 049696c6-7512-489d-a988-6d69b121eee5, localhost:13953): request = { database: "local/test_db" }
2025-12-12 09:15:33,755 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 049696c6-7512-489d-a988-6d69b121eee5, localhost:13953): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-7uza2v6l2u.auto.internal" port: 18804 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" node_id: 50000 } self_location: "1" } } } }
2025-12-12 09:15:33,756 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local/test_db: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-7uza2v6l2u.auto.internal:18804, location , ssl: False>]>
2025-12-12 09:15:33,757 - INFO - ydb.connection - close: Closing channel for endpoint localhost:13953
2025-12-12 09:15:44,675 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) rc: 0
2025-12-12 09:15:44,676 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) elapsed time (sec): 43.76130962371826
2025-12-12 09:15:44,676 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) idrss: 0
2025-12-12 09:15:44,676 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) inblock: 0
2025-12-12 09:15:44,676 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) isrss: 0
2025-12-12 09:15:44,676 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) ixrss: 0
2025-12-12 09:15:44,677 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) majflt: 0
2025-12-12 09:15:44,677 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) maxrss: 629204
2025-12-12 09:15:44,677 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) minflt: 108811
2025-12-12 09:15:44,677 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) msgrcv: 0
2025-12-12 09:15:44,677 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) msgsnd: 0
2025-12-12 09:15:44,677 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) nivcsw: 14
2025-12-12 09:15:44,678 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) nsignals: 0
2025-12-12 09:15:44,678 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) nswap: 0
2025-12-12 09:15:44,678 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) nvcsw: 4680
2025-12-12 09:15:44,678 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) oublock: 2416
2025-12-12 09:15:44,678 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) stime: 0.223686
2025-12-12 09:15:44,679 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) utime: 0.665376
2025-12-12 09:15:44,679 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) wtime: 43.763
2025-12-12 09:15:44,679 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) output:
Query01:
Query text:
$z1_12 = 1;
select
    l_returnflag,
    l_linestatus,
    sum(l_quantity) as sum_qty,
    sum(l_extendedprice) as sum_base_price,
    sum(l_extendedprice * ($z1_12 - l_discount)) as sum_disc_price,
    sum(l_extendedprice * ($z1_12 - l_discount) * ($z1_12 + l_tax)) as sum_charge,
    avg(l_quantity) as avg_qty,
    avg(l_extendedprice) as avg_price,
    avg(l_discount) as avg_disc,
    count(*) as count_order
from
    `olap_yatests/tpch/s1/lineitem`
where
    l_shipdate <= Date('1998-12-01') - Interval("P90D")
group by
    l_returnflag,
    l_linestatus
order by
    l_returnflag,
    l_linestatus;

	iteration 0:	ok	41.094229s seconds

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

Results saved to /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/q1.out
Json report saved to /home/runner/.ya/build/build_root/yq5c/0003f4/ydb/tests/functional/tpc/medium/test-results/py3test/testing_out_stuff/test_tpch/testing_out_stuff/test_tpch.py.TestTpchS1.test_tpch.1/q1.json

2025-12-12 09:15:44,679 - DEBUG - ya.test - _save_outputs: Command (pid 1236400) 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: 271K rows read, 13.8M B read.
[K-Progress: 784K rows read, 39.8M B read.
[K\Progress: 1.34M rows read, 68M B read.
[K|Progress: 1.83M rows read, 93M B read.
[K/Progress: 2.28M rows read, 115M B read.
[K-Progress: 2.55M rows read, 130M B read.
[K\Progress: 2.92M rows read, 148M B read.
[K|Progress: 3.23M rows read, 164M B read.
[K/Progress: 3.54M rows read, 180M B read.
[K-Progress: 3.9M rows read, 198M B read.
[K\Progress: 4.49M rows read, 228M B read.
[K|Progress: 5.15M rows read, 261M B read.
[K/Progress: 5.92M rows read, 300M B read.
[K
2025-12-12 09:15:44,680 - DEBUG - ya.test - verify_sanitize_errors: No sanitizer errors found
2025-12-12 09:15:44,694 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:44,697 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes?database=/local/test_db HTTP/1.1" 307 0
2025-12-12 09:15:44,706 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /node/50000/viewer/json/nodes?database=/local/test_db HTTP/1.1" 200 553
2025-12-12 09:15:44,710 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:2876
2025-12-12 09:15:44,714 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:2876 "GET /viewer/json/nodes HTTP/1.1" 200 780
2025-12-12 09:15:44,719 - INFO - ya.test - pytest_runtest_teardown: Test teardown
