2025-12-12 13:25:14,040 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 13:25:14,040 - INFO - ya.test - pytest_runtest_setup: test_format_inference[v2-test.csv-csv_with_names]
2025-12-12 13:25:14,040 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 13:25:14,041 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-12-12 13:25:15,043 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:30596/1
2025-12-12 13:25:15,044 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/25027
2025-12-12 13:25:15,057 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17653
2025-12-12 13:25:15,062 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/30596
2025-12-12 13:25:15,063 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/21561
2025-12-12 13:25:15,063 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/14216
2025-12-12 13:25:15,063 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17200
2025-12-12 13:25:22,065 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:15018/1
2025-12-12 13:25:22,066 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/7506
2025-12-12 13:25:22,066 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/11997
2025-12-12 13:25:22,066 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/15018
2025-12-12 13:25:22,067 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/13591
2025-12-12 13:25:22,067 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/22949
2025-12-12 13:25:25,068 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:8731/1
2025-12-12 13:25:25,069 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/8058
2025-12-12 13:25:25,070 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/23305
2025-12-12 13:25:25,070 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/8731
2025-12-12 13:25:25,070 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/9964
2025-12-12 13:25:25,070 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/11362
2025-12-12 13:25:25,071 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/1324
2025-12-12 13:25:25,073 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/14388
2025-12-12 13:25:25,074 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/26377
2025-12-12 13:25:25,151 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:25,152 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/2396
2025-12-12 13:25:25,152 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/65302
2025-12-12 13:25:25,153 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/17054
2025-12-12 13:25:25,154 - 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 13:25:25,155 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 13:25:25,156 - 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 13:25:25,160 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-12-12 13:25:25,160 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 2b0928f1-4dfd-413b-b265-f6a5738456c1, localhost:18756): creating call state
2025-12-12 13:25:25,161 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 2b0928f1-4dfd-413b-b265-f6a5738456c1, localhost:18756): request = { database: "local" }
2025-12-12 13:25:25,163 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 2b0928f1-4dfd-413b-b265-f6a5738456c1, localhost:18756): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-qsiocfpt6q.auto.internal" port: 18756 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-12-12 13:25:25,164 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-qsiocfpt6q.auto.internal:18756, location 1, ssl: False>]>
2025-12-12 13:25:25,164 - 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 13:25:25,167 - INFO - ydb.connection - close: Closing channel for endpoint localhost:18756
2025-12-12 13:25:25,169 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-12 13:25:25,169 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fcd87f74830 state=pending>
2025-12-12 13:25:25,169 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-12-12 13:25:25,169 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fcd87f74240>
2025-12-12 13:25:25,170 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fcd87f74240>
2025-12-12 13:25:25,170 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, a9c867a9-522f-4699-b092-1de1cc55ed87, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,170 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, a9c867a9-522f-4699-b092-1de1cc55ed87, ghrun-qsiocfpt6q.auto.internal:18756): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-12 13:25:25,173 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, a9c867a9-522f-4699-b092-1de1cc55ed87, ghrun-qsiocfpt6q.auto.internal:18756): on response callback started
2025-12-12 13:25:25,173 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, a9c867a9-522f-4699-b092-1de1cc55ed87, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZGE3YWM2M2QtOWY0YzM3NzktYzU0ZWUzMjUtNTJkOTU1YzM=" } } } }
2025-12-12 13:25:25,174 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd87f74240>
2025-12-12 13:25:25,174 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fcd87f74240>
2025-12-12 13:25:25,174 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 17ea64f1-17d2-425a-90b8-8165a4c8d29e, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,175 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, a9c867a9-522f-4699-b092-1de1cc55ed87, ghrun-qsiocfpt6q.auto.internal:18756): on response callback success
2025-12-12 13:25:25,176 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 17ea64f1-17d2-425a-90b8-8165a4c8d29e, ghrun-qsiocfpt6q.auto.internal:18756): request = { session_id: "ydb://session/3?node_id=1&id=ZGE3YWM2M2QtOWY0YzM3NzktYzU0ZWUzMjUtNTJkOTU1YzM=" path: "local/DbPoolStorage_e61c8b2e-decc-40cc-90f6-7bbd3fea67df/tenants" columns { name: "tenant" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } columns { name: "common" type { optional_type { item { type_id: BOOL } } } } columns { name: "state" type { optional_type { item { type_id: UINT32 } } } } columns { name: "state_time" type { optional_type { item { type_id: TIMESTAMP } } } } primary_key: "tenant" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:25:25,193 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 17ea64f1-17d2-425a-90b8-8165a4c8d29e, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:25:25,194 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd87f74240>
2025-12-12 13:25:25,195 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 96aecadb-df33-470d-ada6-833337c2d57f, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,196 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 96aecadb-df33-470d-ada6-833337c2d57f, ghrun-qsiocfpt6q.auto.internal:18756): request = { session_id: "ydb://session/3?node_id=1&id=ZGE3YWM2M2QtOWY0YzM3NzktYzU0ZWUzMjUtNTJkOTU1YzM=" path: "local/DbPoolStorage_e61c8b2e-decc-40cc-90f6-7bbd3fea67df/mappings" columns { name: "subject_type" type { optional_type { item { type_id: STRING } } } } columns { name: "subject_id" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } primary_key: "subject_type" primary_key: "subject_id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:25:25,213 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 96aecadb-df33-470d-ada6-833337c2d57f, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:25:25,214 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd87f74240>
2025-12-12 13:25:25,214 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, a704dcdf-adb5-4745-b7b8-f3c5ca24b74a, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,215 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, a704dcdf-adb5-4745-b7b8-f3c5ca24b74a, ghrun-qsiocfpt6q.auto.internal:18756): request = { session_id: "ydb://session/3?node_id=1&id=ZGE3YWM2M2QtOWY0YzM3NzktYzU0ZWUzMjUtNTJkOTU1YzM=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "--!syntax_v1\n            PRAGMA TablePathPrefix(\"local/DbPoolStorage_e61c8b2e-decc-40cc-90f6-7bbd3fea67df\");\n            UPSERT INTO tenants (tenant, vtenant, common, state, state_time) values(\"/default\", \"/default\", true, 0, CurrentUtcTimestamp());\n                " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:25:25,231 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, a704dcdf-adb5-4745-b7b8-f3c5ca24b74a, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-12-12 13:25:25,232 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd87f74240>
2025-12-12 13:25:25,300 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:25,301 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28176
2025-12-12 13:25:25,302 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1635
2025-12-12 13:25:25,303 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/default/kikimr_configs"
2025-12-12 13:25:25,303 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --tenant=/default --node-kind=yq --log-file-name=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/default/node_1/logfile_nc70ru1t.log --grpc-port=17054 --mon-port=28176 --ic-port=2396
2025-12-12 13:25:25,305 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/default/kikimr_configs/config.yaml', '--node=1', '--tenant=/default', '--node-kind=yq', '--log-file-name=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/default/node_1/logfile_nc70ru1t.log', '--grpc-port=17054', '--mon-port=28176', '--ic-port=2396')' in '/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/default/node_1' (no wait)
2025-12-12 13:25:25,306 - DEBUG - ya.test - execute: Command pid: 2750687
2025-12-12 13:25:25,307 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:17054/1
2025-12-12 13:25:25,308 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-12-12 13:25:25,311 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4302
2025-12-12 13:25:25,312 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/24369
2025-12-12 13:25:25,385 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:25,386 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/20546
2025-12-12 13:25:25,386 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/11406
2025-12-12 13:25:25,453 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:25,453 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/11416
2025-12-12 13:25:25,454 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4990
2025-12-12 13:25:25,455 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/11938
2025-12-12 13:25:25,456 - 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 13:25:25,458 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 13:25:25,459 - 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 13:25:25,467 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-12-12 13:25:25,467 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 4c4114ca-7f81-49d4-a8dd-e8d9c4df2f9f, localhost:18756): creating call state
2025-12-12 13:25:25,468 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 4c4114ca-7f81-49d4-a8dd-e8d9c4df2f9f, localhost:18756): request = { database: "local" }
2025-12-12 13:25:25,471 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 4c4114ca-7f81-49d4-a8dd-e8d9c4df2f9f, localhost:18756): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-qsiocfpt6q.auto.internal" port: 18756 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-12-12 13:25:25,472 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-qsiocfpt6q.auto.internal:18756, location 1, ssl: False>]>
2025-12-12 13:25:25,472 - 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 13:25:25,475 - INFO - ydb.connection - close: Closing channel for endpoint localhost:18756
2025-12-12 13:25:25,477 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-12 13:25:25,477 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fcd84e16ef0 state=pending>
2025-12-12 13:25:25,477 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-12-12 13:25:25,478 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fcd84e15730>
2025-12-12 13:25:25,478 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fcd84e15730>
2025-12-12 13:25:25,478 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, c3ebb3be-7860-4368-82ad-b3d46d5fecad, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,479 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, c3ebb3be-7860-4368-82ad-b3d46d5fecad, ghrun-qsiocfpt6q.auto.internal:18756): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-12 13:25:25,481 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, c3ebb3be-7860-4368-82ad-b3d46d5fecad, ghrun-qsiocfpt6q.auto.internal:18756): on response callback started
2025-12-12 13:25:25,482 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, c3ebb3be-7860-4368-82ad-b3d46d5fecad, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=OGIyOTU4Yy1kYzk2NDU5YS1mNjlhYzc1MS0yZjJlYjY0Yw==" } } } }
2025-12-12 13:25:25,482 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd84e15730>
2025-12-12 13:25:25,482 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fcd84e15730>
2025-12-12 13:25:25,483 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 7a226eb8-5e47-4305-94f6-86f18eea3d0b, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,483 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, c3ebb3be-7860-4368-82ad-b3d46d5fecad, ghrun-qsiocfpt6q.auto.internal:18756): on response callback success
2025-12-12 13:25:25,485 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 7a226eb8-5e47-4305-94f6-86f18eea3d0b, ghrun-qsiocfpt6q.auto.internal:18756): request = { session_id: "ydb://session/3?node_id=1&id=OGIyOTU4Yy1kYzk2NDU5YS1mNjlhYzc1MS0yZjJlYjY0Yw==" path: "local/DbPoolStorage_c791b308-dcd0-4bd6-8804-e204e894b6f1/tenants" columns { name: "tenant" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } columns { name: "common" type { optional_type { item { type_id: BOOL } } } } columns { name: "state" type { optional_type { item { type_id: UINT32 } } } } columns { name: "state_time" type { optional_type { item { type_id: TIMESTAMP } } } } primary_key: "tenant" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:25:25,500 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 7a226eb8-5e47-4305-94f6-86f18eea3d0b, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:25:25,501 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd84e15730>
2025-12-12 13:25:25,502 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 2cf59046-c5bc-43b8-b020-4c8b8c192048, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,502 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 2cf59046-c5bc-43b8-b020-4c8b8c192048, ghrun-qsiocfpt6q.auto.internal:18756): request = { session_id: "ydb://session/3?node_id=1&id=OGIyOTU4Yy1kYzk2NDU5YS1mNjlhYzc1MS0yZjJlYjY0Yw==" path: "local/DbPoolStorage_c791b308-dcd0-4bd6-8804-e204e894b6f1/mappings" columns { name: "subject_type" type { optional_type { item { type_id: STRING } } } } columns { name: "subject_id" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } primary_key: "subject_type" primary_key: "subject_id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:25:25,517 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 2cf59046-c5bc-43b8-b020-4c8b8c192048, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:25:25,517 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd84e15730>
2025-12-12 13:25:25,518 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 85c072d8-4845-44d2-bf54-813aa1821ff3, ghrun-qsiocfpt6q.auto.internal:18756): creating call state
2025-12-12 13:25:25,519 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 85c072d8-4845-44d2-bf54-813aa1821ff3, ghrun-qsiocfpt6q.auto.internal:18756): request = { session_id: "ydb://session/3?node_id=1&id=OGIyOTU4Yy1kYzk2NDU5YS1mNjlhYzc1MS0yZjJlYjY0Yw==" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "--!syntax_v1\n            PRAGMA TablePathPrefix(\"local/DbPoolStorage_c791b308-dcd0-4bd6-8804-e204e894b6f1\");\n            UPSERT INTO tenants (tenant, vtenant, common, state, state_time) values(\"/cp\", \"/cp\", true, 0, CurrentUtcTimestamp());\n                UPSERT INTO tenants (tenant, vtenant, common, state, state_time) values(\"/compute\", \"/compute\", true, 0, CurrentUtcTimestamp());\n                " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:25:25,540 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 85c072d8-4845-44d2-bf54-813aa1821ff3, ghrun-qsiocfpt6q.auto.internal:18756): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-12-12 13:25:25,541 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fcd84e15730>
2025-12-12 13:25:25,542 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/13522
2025-12-12 13:25:25,603 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:25,605 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/12921
2025-12-12 13:25:25,605 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/62179
2025-12-12 13:25:25,606 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/cp/kikimr_configs"
2025-12-12 13:25:25,606 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --tenant=/cp --node-kind=yq --log-file-name=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/cp/node_1/logfile_729bswt3.log --grpc-port=11938 --mon-port=12921 --ic-port=20546
2025-12-12 13:25:25,608 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/cp/kikimr_configs/config.yaml', '--node=1', '--tenant=/cp', '--node-kind=yq', '--log-file-name=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/cp/node_1/logfile_729bswt3.log', '--grpc-port=11938', '--mon-port=12921', '--ic-port=20546')' in '/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/cp/node_1' (no wait)
2025-12-12 13:25:25,609 - DEBUG - ya.test - execute: Command pid: 2750800
2025-12-12 13:25:25,610 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:11938/1
2025-12-12 13:25:25,611 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-12-12 13:25:25,656 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:25,657 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/10349
2025-12-12 13:25:25,657 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/3970
2025-12-12 13:25:25,658 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/compute/kikimr_configs"
2025-12-12 13:25:25,658 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rvnw/003483/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/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/compute/node_1/logfile_hzpy3_89.log --grpc-port=13522 --mon-port=10349 --ic-port=11416
2025-12-12 13:25:25,659 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/compute/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/compute/node_1/logfile_hzpy3_89.log', '--grpc-port=13522', '--mon-port=10349', '--ic-port=11416')' in '/home/runner/.ya/build/build_root/rvnw/003483/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_formats/testing_out_stuff/test_formats.py.TestS3Formats.test_format_inference.v2-test.csv-csv_with_names/compute/node_1' (no wait)
2025-12-12 13:25:25,660 - DEBUG - ya.test - execute: Command pid: 2750804
2025-12-12 13:25:25,661 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:13522/1
2025-12-12 13:25:27,497 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:27,498 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.2
2025-12-12 13:25:27,499 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.2
2025-12-12 13:25:27,499 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13522', '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: 11416\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-12-12 13:25:27,500 - DEBUG - ya.test - execute: Command pid: 2752147
2025-12-12 13:25:27,904 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) rc: 0
2025-12-12 13:25:27,904 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) elapsed time (sec): 0.4030005931854248
2025-12-12 13:25:27,904 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) idrss: 0
2025-12-12 13:25:27,905 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) inblock: 0
2025-12-12 13:25:27,905 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) isrss: 0
2025-12-12 13:25:27,905 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) ixrss: 0
2025-12-12 13:25:27,905 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) majflt: 0
2025-12-12 13:25:27,905 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) maxrss: 529076
2025-12-12 13:25:27,905 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) minflt: 19769
2025-12-12 13:25:27,905 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) msgrcv: 0
2025-12-12 13:25:27,906 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) msgsnd: 0
2025-12-12 13:25:27,906 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) nivcsw: 6
2025-12-12 13:25:27,906 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) nsignals: 0
2025-12-12 13:25:27,906 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) nswap: 0
2025-12-12 13:25:27,906 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) nvcsw: 133
2025-12-12 13:25:27,906 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) oublock: 8
2025-12-12 13:25:27,907 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) stime: 0.24879199999999999
2025-12-12 13:25:27,907 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) utime: 0.110174
2025-12-12 13:25:27,907 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) wtime: 0.404
2025-12-12 13:25:27,907 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-12-12 13:25:27,907 - DEBUG - ya.test - _save_outputs: Command (pid 2752147) errors:

2025-12-12 13:25:27,908 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:27,909 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.3
2025-12-12 13:25:27,910 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.3
2025-12-12 13:25:27,910 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13522', '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 13:25:27,911 - DEBUG - ya.test - execute: Command pid: 2752465
2025-12-12 13:25:28,306 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) rc: 0
2025-12-12 13:25:28,307 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) elapsed time (sec): 0.39473819732666016
2025-12-12 13:25:28,307 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) idrss: 0
2025-12-12 13:25:28,307 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) inblock: 0
2025-12-12 13:25:28,307 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) isrss: 0
2025-12-12 13:25:28,307 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) ixrss: 0
2025-12-12 13:25:28,308 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) majflt: 0
2025-12-12 13:25:28,308 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) maxrss: 529072
2025-12-12 13:25:28,308 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) minflt: 19769
2025-12-12 13:25:28,308 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) msgrcv: 0
2025-12-12 13:25:28,308 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) msgsnd: 0
2025-12-12 13:25:28,308 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) nivcsw: 10
2025-12-12 13:25:28,309 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) nsignals: 0
2025-12-12 13:25:28,309 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) nswap: 0
2025-12-12 13:25:28,309 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) nvcsw: 144
2025-12-12 13:25:28,309 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) oublock: 8
2025-12-12 13:25:28,309 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) stime: 0.258172
2025-12-12 13:25:28,309 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) utime: 0.09278
2025-12-12 13:25:28,309 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) wtime: 0.396
2025-12-12 13:25:28,310 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 6

2025-12-12 13:25:28,310 - DEBUG - ya.test - _save_outputs: Command (pid 2752465) errors:

2025-12-12 13:25:28,311 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd
2025-12-12 13:25:28,312 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.4
2025-12-12 13:25:28,312 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.4
2025-12-12 13:25:28,312 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rvnw/003483/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:13522', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 2\n    Name: "dynamic_storage_pool:2"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "ssd"\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 13:25:28,313 - DEBUG - ya.test - execute: Command pid: 2752777
2025-12-12 13:25:28,710 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) rc: 0
2025-12-12 13:25:28,710 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) elapsed time (sec): 0.3955991268157959
2025-12-12 13:25:28,710 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) idrss: 0
2025-12-12 13:25:28,710 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) inblock: 0
2025-12-12 13:25:28,710 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) isrss: 0
2025-12-12 13:25:28,711 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) ixrss: 0
2025-12-12 13:25:28,711 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) majflt: 0
2025-12-12 13:25:28,711 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) maxrss: 529068
2025-12-12 13:25:28,711 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) minflt: 19773
2025-12-12 13:25:28,711 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) msgrcv: 0
2025-12-12 13:25:28,711 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) msgsnd: 0
2025-12-12 13:25:28,711 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) nivcsw: 12
2025-12-12 13:25:28,712 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) nsignals: 0
2025-12-12 13:25:28,712 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) nswap: 0
2025-12-12 13:25:28,712 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) nvcsw: 148
2025-12-12 13:25:28,712 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) oublock: 8
2025-12-12 13:25:28,712 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) stime: 0.24126299999999998
2025-12-12 13:25:28,712 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) utime: 0.108568
2025-12-12 13:25:28,712 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) wtime: 0.397
2025-12-12 13:25:28,713 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 7

2025-12-12 13:25:28,713 - DEBUG - ya.test - _save_outputs: Command (pid 2752777) errors:

2025-12-12 13:25:28,713 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain local: {'dynamic_storage_pool:1': 'hdd', 'dynamic_storage_pool:2': 'ssd'}
2025-12-12 13:25:28,737 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-12-12 13:25:28,748 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-12-12 13:25:28,774 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-12-12 13:25:28,800 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-12-12 13:25:28,843 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-12-12 13:25:28,890 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_formats.py::TestS3Formats, test_name: test_format_inference[v2-test.csv-csv_with_names])
2025-12-12 13:25:28,892 - DEBUG - botocore.hooks - _emit: Event choose-service-name: calling handler <function handle_service_name_alias at 0x7fcda1e210d0>
2025-12-12 13:25:28,894 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_post at 0x7fcda1f2cdd0>
2025-12-12 13:25:28,895 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function lazy_call.<locals>._handler at 0x7fcda1358ad0>
2025-12-12 13:25:28,895 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_url at 0x7fcda1f2cad0>
2025-12-12 13:25:28,899 - DEBUG - botocore.endpoint - create_endpoint: Setting s3 timeout as (60, 60)
2025-12-12 13:25:28,904 - DEBUG - botocore.client - _register_legacy_retries: Registering retry handlers for service: s3
2025-12-12 13:25:28,905 - DEBUG - botocore.utils - register: Registering S3 region redirector handler
2025-12-12 13:25:28,906 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:s3
2025-12-12 13:25:28,908 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:Bucket
2025-12-12 13:25:28,908 - DEBUG - boto3.resources.model - _load_name_with_category: Renaming Bucket attribute name
2025-12-12 13:25:28,910 - DEBUG - botocore.hooks - _emit: Event creating-resource-class.s3.Bucket: calling handler <function lazy_call.<locals>._handler at 0x7fcda1359550>
2025-12-12 13:25:28,911 - DEBUG - boto3.resources.action - __call__: Calling s3:create_bucket with {'Bucket': 'fbucket', 'ACL': 'public-read'}
2025-12-12 13:25:28,911 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function validate_bucket_name at 0x7fcda1e22f90>
2025-12-12 13:25:28,912 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fcda1e49850>
2025-12-12 13:25:28,912 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,912 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function generate_idempotent_uuid at 0x7fcda1e22d50>
2025-12-12 13:25:28,912 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fcda1e49a90>
2025-12-12 13:25:28,913 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,913 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:13510', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableAccessPoints': True, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:25:28,915 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:13510/fbucket
2025-12-12 13:25:28,915 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:25:28,915 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:25:28,916 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function add_expect_header at 0x7fcda1e23410>
2025-12-12 13:25:28,916 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function add_recursion_detection_header at 0x7fcda1e21310>
2025-12-12 13:25:28,916 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function inject_api_version_header_if_needed at 0x7fcda1e48e90>
2025-12-12 13:25:28,917 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=CreateBucket) with params: {'url_path': '', 'query_string': {}, 'method': 'PUT', 'headers': {'x-amz-acl': 'public-read', 'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource'}, 'body': b'', 'auth_path': '/fbucket/', 'url': 'http://localhost:13510/fbucket', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fcd84c044c0>, 'has_streaming_input': False, 'auth_type': 'v4', 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Bucket': 'fbucket', 'ACL': 'public-read'}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-12-12 13:25:28,917 - DEBUG - botocore.hooks - _emit: Event request-created.s3.CreateBucket: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fcd84c04a10>>
2025-12-12 13:25:28,918 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.CreateBucket: calling handler <bound method ClientCreator._default_s3_presign_to_sigv2 of <botocore.client.ClientCreator object at 0x7fcd8b3f8d30>>
2025-12-12 13:25:28,918 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.CreateBucket: calling handler <function set_operation_specific_signer at 0x7fcda1e22bd0>
2025-12-12 13:25:28,918 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.CreateBucket: calling handler <function remove_arn_from_signing_path at 0x7fcda1e499d0>
2025-12-12 13:25:28,919 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:25:28,919 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
PUT
/fbucket

host:localhost:13510
x-amz-acl:public-read
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20251212T132528Z

host;x-amz-acl;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2025-12-12 13:25:28,919 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132528Z
20251212/yandex/s3/aws4_request
55a0edb9c9fbb80dedf54ff4d5c7bcdc797a7e6d0d61f341914551a853e4589f
2025-12-12 13:25:28,920 - DEBUG - botocore.auth - add_auth: Signature:
f245b091dcaf5a790f8f1045a7f918590ece6436fab0c18da0c4985c02ae0fb3
2025-12-12 13:25:28,920 - DEBUG - botocore.hooks - _emit: Event request-created.s3.CreateBucket: calling handler <function add_retry_headers at 0x7fcda1e49790>
2025-12-12 13:25:28,920 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=PUT, url=http://localhost:13510/fbucket, headers={'x-amz-acl': b'public-read', 'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'X-Amz-Date': b'20251212T132528Z', 'X-Amz-Content-SHA256': b'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=host;x-amz-acl;x-amz-content-sha256;x-amz-date, Signature=f245b091dcaf5a790f8f1045a7f918590ece6436fab0c18da0c4985c02ae0fb3', 'amz-sdk-invocation-id': b'd6a5b5cb-c277-42e6-805c-a1b207227e24', 'amz-sdk-request': b'attempt=1', 'Content-Length': '0'}>
2025-12-12 13:25:28,933 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:25:28 GMT', 'x-amzn-requestid': 'O6uxib7bmJ71zEQmPeDK2P0cBzmCSOgM6bffciXlMcb4pdjLYZyo', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '161', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:25:28,934 - DEBUG - botocore.parsers - parse: Response body:
b'<CreateBucketResponse xmlns="http://s3.amazonaws.com/doc/2006-03-01"><CreateBucketResponse><Bucket>fbucket</Bucket></CreateBucketResponse></CreateBucketResponse>'
2025-12-12 13:25:28,935 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.CreateBucket: calling handler <botocore.retryhandler.RetryHandler object at 0x7fcd8507ea90>
2025-12-12 13:25:28,935 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:25:28,935 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.CreateBucket: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,936 - DEBUG - boto3.resources.action - __call__: Response: {'ResponseMetadata': {'RequestId': 'O6uxib7bmJ71zEQmPeDK2P0cBzmCSOgM6bffciXlMcb4pdjLYZyo', 'HTTPStatusCode': 200, 'HTTPHeaders': {'server': 'Werkzeug/2.2.3 Python/3.12.9', 'date': 'Fri, 12 Dec 2025 13:25:28 GMT', 'x-amzn-requestid': 'O6uxib7bmJ71zEQmPeDK2P0cBzmCSOgM6bffciXlMcb4pdjLYZyo', 'content-type': 'text/html; charset=utf-8', 'content-length': '161', 'access-control-allow-origin': '*', 'connection': 'close'}, 'RetryAttempts': 0}}
2025-12-12 13:25:28,936 - DEBUG - boto3.resources.collection - pages: Calling paginated s3:list_objects with {'Bucket': 'fbucket'}
2025-12-12 13:25:28,937 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function set_list_objects_encoding_type_url at 0x7fcda1e48890>
2025-12-12 13:25:28,938 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function validate_bucket_name at 0x7fcda1e22f90>
2025-12-12 13:25:28,938 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fcda1e49850>
2025-12-12 13:25:28,938 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,938 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function generate_idempotent_uuid at 0x7fcda1e22d50>
2025-12-12 13:25:28,939 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fcda1e49a90>
2025-12-12 13:25:28,939 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,939 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:13510', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:25:28,941 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:13510/fbucket
2025-12-12 13:25:28,941 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:25:28,941 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:25:28,942 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function add_expect_header at 0x7fcda1e23410>
2025-12-12 13:25:28,942 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function add_recursion_detection_header at 0x7fcda1e21310>
2025-12-12 13:25:28,942 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function inject_api_version_header_if_needed at 0x7fcda1e48e90>
2025-12-12 13:25:28,943 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=ListObjects) with params: {'url_path': '', 'query_string': {'encoding-type': 'url'}, 'method': 'GET', 'headers': {'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource'}, 'body': b'', 'auth_path': '/fbucket/', 'url': 'http://localhost:13510/fbucket?encoding-type=url', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fcd84c044c0>, 'has_streaming_input': False, 'auth_type': 'v4', 'encoding_type_auto_set': True, 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Bucket': 'fbucket', 'EncodingType': 'url'}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-12-12 13:25:28,944 - DEBUG - botocore.hooks - _emit: Event request-created.s3.ListObjects: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fcd84c04a10>>
2025-12-12 13:25:28,944 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.ListObjects: calling handler <bound method ClientCreator._default_s3_presign_to_sigv2 of <botocore.client.ClientCreator object at 0x7fcd8b3f8d30>>
2025-12-12 13:25:28,944 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.ListObjects: calling handler <function set_operation_specific_signer at 0x7fcda1e22bd0>
2025-12-12 13:25:28,945 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.ListObjects: calling handler <function remove_arn_from_signing_path at 0x7fcda1e499d0>
2025-12-12 13:25:28,945 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:25:28,946 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
GET
/fbucket
encoding-type=url
host:localhost:13510
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20251212T132528Z

host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2025-12-12 13:25:28,946 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132528Z
20251212/yandex/s3/aws4_request
341b05fbe590f4d348a242de946035faa3279578a716469b64ca2351336d696b
2025-12-12 13:25:28,946 - DEBUG - botocore.auth - add_auth: Signature:
1e4ab26fc79de838f17c174e1c96b1e6c094608856731c147bb34b0767187bbb
2025-12-12 13:25:28,946 - DEBUG - botocore.hooks - _emit: Event request-created.s3.ListObjects: calling handler <function add_retry_headers at 0x7fcda1e49790>
2025-12-12 13:25:28,947 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=GET, url=http://localhost:13510/fbucket?encoding-type=url, headers={'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'X-Amz-Date': b'20251212T132528Z', 'X-Amz-Content-SHA256': b'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=1e4ab26fc79de838f17c174e1c96b1e6c094608856731c147bb34b0767187bbb', 'amz-sdk-invocation-id': b'47508911-953e-47c5-8d77-14aff3f3fa58', 'amz-sdk-request': b'attempt=1'}>
2025-12-12 13:25:28,955 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:25:28 GMT', 'x-amzn-requestid': 'Ph7FEKxIaMlWtSHf0CqroDm7vEhpjQSZ9I2DXvDlU3fLd7cb13FL', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '558', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:25:28,956 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?><ListBucketResult xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Name>fbucket</Name><MaxKeys>1000</MaxKeys><EncodingType>url</EncodingType><IsTruncated>false</IsTruncated><Contents><Key>test.parquet</Key><LastModified>2025-12-12T13:25:12.000Z</LastModified><ETag>&#34;321b7b6cd6df2df919acfc810b0b5362&#34;</ETag><Size>2899</Size><StorageClass>STANDARD</StorageClass><Owner><ID>75aa57f09aa0c8caeab4f8c24e99d10f8e7faeebf76c078efc7c6caea54ba06a</ID><DisplayName>webfile</DisplayName></Owner></Contents></ListBucketResult>'
2025-12-12 13:25:28,958 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.ListObjects: calling handler <botocore.retryhandler.RetryHandler object at 0x7fcd8507ea90>
2025-12-12 13:25:28,959 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:25:28,959 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.ListObjects: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,960 - DEBUG - botocore.hooks - _emit: Event after-call.s3.ListObjects: calling handler <function decode_list_object at 0x7fcda1e48950>
2025-12-12 13:25:28,960 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:ObjectSummary
2025-12-12 13:25:28,960 - DEBUG - boto3.resources.model - _load_name_with_category: Renaming ObjectSummary attribute key
2025-12-12 13:25:28,961 - DEBUG - botocore.hooks - _emit: Event creating-resource-class.s3.ObjectSummary: calling handler <function lazy_call.<locals>._handler at 0x7fcda13596d0>
2025-12-12 13:25:28,962 - DEBUG - boto3.resources.action - __call__: Calling s3:delete_objects with {'Bucket': 'fbucket', 'Delete': {'Objects': [{'Key': 'test.parquet'}]}}
2025-12-12 13:25:28,963 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <function validate_bucket_name at 0x7fcda1e22f90>
2025-12-12 13:25:28,963 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fcda1e49850>
2025-12-12 13:25:28,963 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,963 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <function generate_idempotent_uuid at 0x7fcda1e22d50>
2025-12-12 13:25:28,964 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fcda1e49a90>
2025-12-12 13:25:28,964 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,964 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:13510', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:25:28,964 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:13510/fbucket
2025-12-12 13:25:28,965 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:25:28,965 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:25:28,966 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function escape_xml_payload at 0x7fcda1e22990>
2025-12-12 13:25:28,967 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function add_expect_header at 0x7fcda1e23410>
2025-12-12 13:25:28,967 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function add_recursion_detection_header at 0x7fcda1e21310>
2025-12-12 13:25:28,967 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function inject_api_version_header_if_needed at 0x7fcda1e48e90>
2025-12-12 13:25:28,968 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=DeleteObjects) with params: {'url_path': '?delete', 'query_string': {}, 'method': 'POST', 'headers': {'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'Content-MD5': 'VlzRp/YoIEUxqS5THItLwA=='}, 'body': b'<Delete xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Object><Key>test.parquet</Key></Object></Delete>', 'auth_path': '/fbucket/', 'url': 'http://localhost:13510/fbucket?delete', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fcd84c044c0>, 'has_streaming_input': False, 'auth_type': 'v4', 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Bucket': 'fbucket', 'Delete': {'Objects': [{'Key': 'test.parquet'}]}}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}, 'checksum': {'request_algorithm': 'conditional-md5'}}}
2025-12-12 13:25:28,969 - DEBUG - botocore.hooks - _emit: Event request-created.s3.DeleteObjects: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fcd84c04a10>>
2025-12-12 13:25:28,969 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.DeleteObjects: calling handler <bound method ClientCreator._default_s3_presign_to_sigv2 of <botocore.client.ClientCreator object at 0x7fcd8b3f8d30>>
2025-12-12 13:25:28,969 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.DeleteObjects: calling handler <function set_operation_specific_signer at 0x7fcda1e22bd0>
2025-12-12 13:25:28,970 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.DeleteObjects: calling handler <function remove_arn_from_signing_path at 0x7fcda1e499d0>
2025-12-12 13:25:28,970 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:25:28,971 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
POST
/fbucket
delete=
content-md5:VlzRp/YoIEUxqS5THItLwA==
host:localhost:13510
x-amz-content-sha256:e9ffb702ea7dc0ba73b57a6c1bcb44576252f0978845aa20cded885650f6f10e
x-amz-date:20251212T132528Z

content-md5;host;x-amz-content-sha256;x-amz-date
e9ffb702ea7dc0ba73b57a6c1bcb44576252f0978845aa20cded885650f6f10e
2025-12-12 13:25:28,971 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132528Z
20251212/yandex/s3/aws4_request
c96bc34e8d0bdc2f1f9d046f3799a8ca965d2a8851ee9f5e239bf45ffddcf601
2025-12-12 13:25:28,971 - DEBUG - botocore.auth - add_auth: Signature:
078ce6e5ea0aa740bcf9eb73164066fb1bd5ea7f006d87a14d7dd863ee9d7ca7
2025-12-12 13:25:28,971 - DEBUG - botocore.hooks - _emit: Event request-created.s3.DeleteObjects: calling handler <function add_retry_headers at 0x7fcda1e49790>
2025-12-12 13:25:28,972 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=POST, url=http://localhost:13510/fbucket?delete, headers={'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'Content-MD5': b'VlzRp/YoIEUxqS5THItLwA==', 'X-Amz-Date': b'20251212T132528Z', 'X-Amz-Content-SHA256': b'e9ffb702ea7dc0ba73b57a6c1bcb44576252f0978845aa20cded885650f6f10e', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=078ce6e5ea0aa740bcf9eb73164066fb1bd5ea7f006d87a14d7dd863ee9d7ca7', 'amz-sdk-invocation-id': b'bf326996-096f-4c45-a908-3e82bfad91f3', 'amz-sdk-request': b'attempt=1', 'Content-Length': '105'}>
2025-12-12 13:25:28,980 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:25:28 GMT', 'x-amzn-requestid': 'd8oUmrOiz148KgB1l0CRfOeFcHXAV05GBbKvBnZHKdm6LlddqIUc', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '156', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:25:28,980 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?><DeleteResult xmlns="http://s3.amazonaws.com/doc/2006-03-01"><Deleted><Key>test.parquet</Key></Deleted></DeleteResult>'
2025-12-12 13:25:28,981 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.DeleteObjects: calling handler <botocore.retryhandler.RetryHandler object at 0x7fcd8507ea90>
2025-12-12 13:25:28,981 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:25:28,982 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.DeleteObjects: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd847022c0>>
2025-12-12 13:25:28,982 - DEBUG - boto3.resources.action - __call__: Response: {'ResponseMetadata': {'RequestId': 'd8oUmrOiz148KgB1l0CRfOeFcHXAV05GBbKvBnZHKdm6LlddqIUc', 'HTTPStatusCode': 200, 'HTTPHeaders': {'server': 'Werkzeug/2.2.3 Python/3.12.9', 'date': 'Fri, 12 Dec 2025 13:25:28 GMT', 'x-amzn-requestid': 'd8oUmrOiz148KgB1l0CRfOeFcHXAV05GBbKvBnZHKdm6LlddqIUc', 'content-type': 'text/html; charset=utf-8', 'content-length': '156', 'access-control-allow-origin': '*', 'connection': 'close'}, 'RetryAttempts': 0}, 'Deleted': [{'Key': 'test.parquet'}]}
2025-12-12 13:25:28,983 - DEBUG - botocore.hooks - _emit: Event choose-service-name: calling handler <function handle_service_name_alias at 0x7fcda1e210d0>
2025-12-12 13:25:28,985 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_post at 0x7fcda1f2cdd0>
2025-12-12 13:25:28,985 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function lazy_call.<locals>._handler at 0x7fcda1358ad0>
2025-12-12 13:25:28,985 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_url at 0x7fcda1f2cad0>
2025-12-12 13:25:28,989 - DEBUG - botocore.endpoint - create_endpoint: Setting s3 timeout as (60, 60)
2025-12-12 13:25:28,993 - DEBUG - botocore.client - _register_legacy_retries: Registering retry handlers for service: s3
2025-12-12 13:25:28,994 - DEBUG - botocore.utils - register: Registering S3 region redirector handler
2025-12-12 13:25:28,996 - DEBUG - s3transfer.utils - acquire: Acquiring 0
2025-12-12 13:25:28,997 - DEBUG - s3transfer.tasks - _wait_until_all_complete: UploadSubmissionTask(transfer_id=0, {'transfer_future': <s3transfer.futures.TransferFuture object at 0x7fcd843cbbc0>}) about to wait for the following futures []
2025-12-12 13:25:28,997 - DEBUG - s3transfer.tasks - _wait_until_all_complete: UploadSubmissionTask(transfer_id=0, {'transfer_future': <s3transfer.futures.TransferFuture object at 0x7fcd843cbbc0>}) done waiting for dependent futures
2025-12-12 13:25:28,998 - DEBUG - s3transfer.tasks - _execute_main: Executing task UploadSubmissionTask(transfer_id=0, {'transfer_future': <s3transfer.futures.TransferFuture object at 0x7fcd843cbbc0>}) with kwargs {'client': <botocore.client.S3 object at 0x7fcd8a105780>, 'config': <boto3.s3.transfer.TransferConfig object at 0x7fcd8b3bf760>, 'osutil': <s3transfer.utils.OSUtils object at 0x7fcd84e489c0>, 'request_executor': <s3transfer.futures.BoundedExecutor object at 0x7fcd780224a0>, 'transfer_future': <s3transfer.futures.TransferFuture object at 0x7fcd843cbbc0>}
2025-12-12 13:25:28,998 - DEBUG - s3transfer.futures - submit: Submitting task PutObjectTask(transfer_id=0, {'bucket': 'fbucket', 'key': 'test.csv', 'extra_args': {}}) to executor <s3transfer.futures.BoundedExecutor object at 0x7fcd780224a0> for transfer request: 0.
2025-12-12 13:25:28,998 - DEBUG - s3transfer.utils - acquire: Acquiring 0
2025-12-12 13:25:28,999 - DEBUG - s3transfer.tasks - _wait_until_all_complete: PutObjectTask(transfer_id=0, {'bucket': 'fbucket', 'key': 'test.csv', 'extra_args': {}}) about to wait for the following futures []
2025-12-12 13:25:29,000 - DEBUG - s3transfer.utils - release: Releasing acquire 0/None
2025-12-12 13:25:29,000 - DEBUG - s3transfer.tasks - _wait_until_all_complete: PutObjectTask(transfer_id=0, {'bucket': 'fbucket', 'key': 'test.csv', 'extra_args': {}}) done waiting for dependent futures
2025-12-12 13:25:29,001 - DEBUG - s3transfer.tasks - _execute_main: Executing task PutObjectTask(transfer_id=0, {'bucket': 'fbucket', 'key': 'test.csv', 'extra_args': {}}) with kwargs {'client': <botocore.client.S3 object at 0x7fcd8a105780>, 'fileobj': <s3transfer.utils.ReadFileChunk object at 0x7fcd843cb260>, 'bucket': 'fbucket', 'key': 'test.csv', 'extra_args': {}}
2025-12-12 13:25:29,003 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function validate_ascii_metadata at 0x7fcda1e48050>
2025-12-12 13:25:29,003 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function sse_md5 at 0x7fcda1e23050>
2025-12-12 13:25:29,003 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function convert_body_to_file_like_object at 0x7fcda1e48d10>
2025-12-12 13:25:29,003 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function validate_bucket_name at 0x7fcda1e22f90>
2025-12-12 13:25:29,004 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fcda1e49850>
2025-12-12 13:25:29,004 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd84e4acc0>>
2025-12-12 13:25:29,004 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function generate_idempotent_uuid at 0x7fcda1e22d50>
2025-12-12 13:25:29,004 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fcda1e49a90>
2025-12-12 13:25:29,005 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd84e4acc0>>
2025-12-12 13:25:29,005 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:13510', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:25:29,006 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:13510/fbucket
2025-12-12 13:25:29,006 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:25:29,007 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:25:29,007 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function conditionally_calculate_md5 at 0x7fcda203ff50>
2025-12-12 13:25:29,008 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function add_expect_header at 0x7fcda1e23410>
2025-12-12 13:25:29,008 - DEBUG - botocore.handlers - add_expect_header: Adding expect 100 continue header to request.
2025-12-12 13:25:29,008 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function add_recursion_detection_header at 0x7fcda1e21310>
2025-12-12 13:25:29,008 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function inject_api_version_header_if_needed at 0x7fcda1e48e90>
2025-12-12 13:25:29,009 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=PutObject) with params: {'url_path': '/test.csv', 'query_string': {}, 'method': 'PUT', 'headers': {'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80', 'Content-MD5': '8AIrnGKGbVGiz8D/fhp3fg==', 'Expect': '100-continue'}, 'body': <s3transfer.utils.ReadFileChunk object at 0x7fcd843cb260>, 'auth_path': '/fbucket/test.csv', 'url': 'http://localhost:13510/fbucket/test.csv', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fcd84e38f10>, 'has_streaming_input': True, 'auth_type': 'v4', 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Bucket': 'fbucket', 'Key': 'test.csv', 'Body': <s3transfer.utils.ReadFileChunk object at 0x7fcd843cb260>}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-12-12 13:25:29,010 - DEBUG - botocore.hooks - _emit: Event request-created.s3.PutObject: calling handler <function signal_not_transferring at 0x7fcd853a1010>
2025-12-12 13:25:29,010 - DEBUG - botocore.hooks - _emit: Event request-created.s3.PutObject: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fcd84e3adb0>>
2025-12-12 13:25:29,010 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.PutObject: calling handler <bound method ClientCreator._default_s3_presign_to_sigv2 of <botocore.client.ClientCreator object at 0x7fcd845fe3b0>>
2025-12-12 13:25:29,011 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.PutObject: calling handler <function set_operation_specific_signer at 0x7fcda1e22bd0>
2025-12-12 13:25:29,011 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.PutObject: calling handler <function remove_arn_from_signing_path at 0x7fcda1e499d0>
2025-12-12 13:25:29,012 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:25:29,012 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
PUT
/fbucket/test.csv

content-md5:8AIrnGKGbVGiz8D/fhp3fg==
host:localhost:13510
x-amz-content-sha256:d9dfec6187c856be0eb7c0424004a785a78f453312b86f27c5bf44f36a27c91b
x-amz-date:20251212T132529Z

content-md5;host;x-amz-content-sha256;x-amz-date
d9dfec6187c856be0eb7c0424004a785a78f453312b86f27c5bf44f36a27c91b
2025-12-12 13:25:29,012 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132529Z
20251212/yandex/s3/aws4_request
08e1dcb5c0916d81d3bf3be219cb6fdfe56082fc8342902443c89cb7e5615fce
2025-12-12 13:25:29,012 - DEBUG - botocore.auth - add_auth: Signature:
87c873df0183772612d95ff8ab1671b4b4d3ede6d34968391105d8ef84a29b1b
2025-12-12 13:25:29,012 - DEBUG - botocore.hooks - _emit: Event request-created.s3.PutObject: calling handler <function signal_transferring at 0x7fcd853a10d0>
2025-12-12 13:25:29,013 - DEBUG - botocore.hooks - _emit: Event request-created.s3.PutObject: calling handler <function add_retry_headers at 0x7fcda1e49790>
2025-12-12 13:25:29,013 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=PUT, url=http://localhost:13510/fbucket/test.csv, headers={'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80', 'Content-MD5': b'8AIrnGKGbVGiz8D/fhp3fg==', 'Expect': b'100-continue', 'X-Amz-Date': b'20251212T132529Z', 'X-Amz-Content-SHA256': b'd9dfec6187c856be0eb7c0424004a785a78f453312b86f27c5bf44f36a27c91b', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=87c873df0183772612d95ff8ab1671b4b4d3ede6d34968391105d8ef84a29b1b', 'amz-sdk-invocation-id': b'a00c69b8-3b04-4a41-af25-36f9944ed02a', 'amz-sdk-request': b'attempt=1', 'Content-Length': '54'}>
2025-12-12 13:25:29,015 - DEBUG - botocore.awsrequest - _send_output: Waiting for 100 Continue response.
2025-12-12 13:25:29,016 - DEBUG - botocore.awsrequest - _handle_expect_response: 100 Continue response seen, now sending request body.
2025-12-12 13:25:29,020 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:25:29 GMT', 'ETag': '"f0022b9c62866d51a2cfc0ff7e1a777e"', 'last-modified': 'Fri, 12 Dec 2025 13:25:29 GMT', 'Content-Length': '0', 'x-amzn-requestid': 'FL0HtM6sREIWXXc9l8M4J2DDn9HbUzzjmOJelLuoO3uyrcesXqVP', 'Content-Type': 'text/html; charset=utf-8', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:25:29,021 - DEBUG - botocore.parsers - parse: Response body:
b''
2025-12-12 13:25:29,021 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.PutObject: calling handler <botocore.retryhandler.RetryHandler object at 0x7fcd84e49910>
2025-12-12 13:25:29,022 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:25:29,022 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.PutObject: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fcd84e4acc0>>
2025-12-12 13:25:29,022 - DEBUG - s3transfer.utils - release: Releasing acquire 0/None
2025-12-12 13:25:29,024 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-12-12 13:25:29,048 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-12-12 13:25:29,496 - DEBUG - root - create_query_impl: Request: content {
  type: ANALYTICS
  name: "simple"
  acl {
    visibility: PRIVATE
  }
  limits {
    execution_timeout {
    }
  }
  text: "\n            SELECT *\n            FROM `h752177879844301271_test_format_inferencefruitbucket`.`test.csv`\n            WITH (format=`csv_with_names`, with_infer=\'true\');\n            "
  syntax: YQL_V1
}
execute_mode: RUN
idempotency_key: "b0b41c34-2a67-4106-ad26-0b9859f543d5"

2025-12-12 13:25:29,686 - DEBUG - root - create_query_impl: Result: query_id: "ptqudq7r70j5rjboe5ek"

2025-12-12 13:25:29,742 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r70j5rjboe5ek"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765545929
        nanos: 500790000
      }
      modified_at {
        seconds: 1765545929
        nanos: 500790000
      }
      revision: 1
    }
    execute_mode: RUN
    status: STARTING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r70j5qi9ssi7u-ptqudq7r70j5rjboe5ek"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765545929
      nanos: 500790000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h752177879844301271_test_format_inferencefruitbucket`.`test.csv`\n            WITH (format=`csv_with_names`, with_infer=\'true\');\n            "
    syntax: YQL_V1
  }
}

2025-12-12 13:25:30,254 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-12-12 13:25:30,768 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r70j5rjboe5ek"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765545929
        nanos: 500790000
      }
      modified_at {
        seconds: 1765545929
        nanos: 500790000
      }
      revision: 1
    }
    started_at {
      seconds: 1765545930
      nanos: 342000000
    }
    execute_mode: RUN
    status: RUNNING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r70j5qi9ssi7u-ptqudq7r70j5rjboe5ek"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765545929
      nanos: 500790000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h752177879844301271_test_format_inferencefruitbucket`.`test.csv`\n            WITH (format=`csv_with_names`, with_infer=\'true\');\n            "
    syntax: YQL_V1
  }
}

2025-12-12 13:25:31,280 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r70j5rjboe5ek"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765545929
        nanos: 500790000
      }
      modified_at {
        seconds: 1765545929
        nanos: 500790000
      }
      revision: 1
    }
    started_at {
      seconds: 1765545930
      nanos: 342000000
    }
    execute_mode: RUN
    status: COMPLETING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r70j5qi9ssi7u-ptqudq7r70j5rjboe5ek"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765545929
      nanos: 500790000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h752177879844301271_test_format_inferencefruitbucket`.`test.csv`\n            WITH (format=`csv_with_names`, with_infer=\'true\');\n            "
    syntax: YQL_V1
  }
  plan {
    json: "{\"Plan\":{\"Plans\":[{\"PlanNodeId\":5,\"Plans\":[{\"PlanNodeId\":4,\"Plans\":[{\"PlanNodeId\":3,\"Plans\":[{\"PlanNodeId\":2,\"Plans\":[{\"PlanNodeId\":1,\"Operators\":[{\"E-Size\":\"0\",\"Format\":\"csv_with_names\",\"Name\":\"h752177879844301271_test_format_inferencefruitbucket.test.csv \",\"Inputs\":[],\"Path\":\"test.csv \",\"E-Rows\":\"0\",\"ExternalDataSource\":\"h752177879844301271_test_format_inferencefruitbucket\",\"ReadColumns\":[\"Fruit\",\"Price\",\"Weight\"],\"SourceType\":\"s3\",\"E-Cost\":\"0\"}],\"Node Type\":\"Source\"}],\"Node Type\":\"Stage\"}],\"Node Type\":\"UnionAll\",\"PlanNodeType\":\"Connection\"}],\"Node Type\":\"Collect\"}],\"Node Type\":\"ResultSet\",\"PlanNodeType\":\"ResultSet\"}],\"Node Type\":\"Query\",\"PlanNodeType\":\"Query\"},\"meta\":{\"version\":\"0.2\",\"type\":\"query\"}}"
  }
  statistics {
    json: "{\"ResultSet\":{\"Tasks\":{\"sum\":2,\"count\":2,\"avg\":1,\"max\":1,\"min\":1},\"CpuTimeUs\":{\"sum\":\"637us\",\"count\":2,\"avg\":\"318us\",\"max\":\"516us\",\"min\":\"121us\"},\"IngressBytes\":{\"sum\":54,\"count\":1,\"avg\":54,\"max\":54,\"min\":54},\"IngressRows\":{\"sum\":3,\"count\":1,\"avg\":3,\"max\":3,\"min\":3},\"InputBytes\":{\"sum\":31,\"count\":1,\"avg\":31,\"max\":31,\"min\":31},\"InputRows\":{\"sum\":3,\"count\":1,\"avg\":3,\"max\":3,\"min\":3},\"OutputBytes\":{\"sum\":62,\"count\":2,\"avg\":31,\"max\":31,\"min\":31},\"OutputRows\":{\"sum\":6,\"count\":2,\"avg\":3,\"max\":3,\"min\":3},\"ResultBytes\":{\"sum\":31,\"count\":1,\"avg\":31,\"max\":31,\"min\":31},\"ResultRows\":{\"sum\":3,\"count\":1,\"avg\":3,\"max\":3,\"min\":3},\"MaxMemoryUsage\":{\"sum\":211812352,\"count\":2,\"avg\":105906176,\"max\":210763776,\"min\":1048576}}}"
  }
  ast {
    data: "(\n(let $1 (DataSource \'\"s3\" \'\"/local/h752177879844301271_test_format_inferencefruitbucket\"))\n(let $2 (Bool \'\"true\"))\n(let $3 \'\"cluster:default_/local/h752177879844301271_test_format_inferencefruitbucket\")\n(let $4 (OptionalType (DataType \'Int64)))\n(let $5 (StructType \'(\'\"Fruit\" (DataType \'Utf8)) \'(\'\"Price\" $4) \'(\'\"Weight\" $4)))\n(let $6 (S3ParseSettings world \'(\'((String \'\"Paths {\\n  Name: \\\"test.csv\\\"\\n  Size: 54\\n  Read: true\\n}\\n\") $2 (AsStruct))) (SecureParam $3) \'\"\" \'\"test.csv \" \'\"csv_with_names\" $5 (lambda \'($11) $2) \'()))\n(let $7 (DqPhyStage \'((DqSource $1 $6)) (lambda \'($12) (block \'(\n  (let $13 (DqSourceWideWrap $12 $1 $5 \'(\'(\'format \'\"csv_with_names\"))))\n  (return (FromFlow (NarrowMap $13 (lambda \'($14 $15 $16) (AsStruct \'(\'\"Fruit\" $14) \'(\'\"Price\" $15) \'(\'\"Weight\" $16))))))\n))) \'(\'(\'\"_logical_id\" \'353) \'(\'\"_id\" \'\"7bbefed5-6de9db02-b9efb2ee-f534def5\"))))\n(let $8 (DqCnUnionAll (TDqOutput $7 \'\"0\")))\n(let $9 (DqPhyStage \'($8) (lambda \'($17) $17) \'(\'(\'\"_logical_id\" \'411) \'(\'\"_id\" \'\"4c2f8c25-86b00b86-4fe6bed3-46f4763c\"))))\n(let $10 (DqCnResult (TDqOutput $9 \'\"0\") \'()))\n(return (KqpPhysicalQuery \'((KqpPhysicalTx \'($7 $9) \'($10) \'() \'(\'(\'\"type\" \'\"generic\")))) \'((KqpTxResultBinding (ListType $5) \'\"0\" \'\"0\")) \'(\'(\'\"type\" \'\"script\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'162\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'162\'/></clipPath>\n\n<defs>\n\n<g id=\'icon_memory\'>\n  <path fill-rule=\'evenodd\' clip-rule=\'evenodd\' d=\'M5 3C3.89543 3 3 3.89543 3 5H1V7H3V9H1V11H3V13H1V15H3V17H1V19H3C3 20.1046 3.89543 21 5 21H9C10.1046 21 11 20.1046 11 19H13C13 20.1046 13.8954 21 15 21H19C20.1046 21 21 20.1046 21 19H23V17H21V15H23V13H21V11H23V9H21V7H23V5H21C21 3.89543 20.1046 3 19 3H15C13.8954 3 13 3.89543 13 5H11C11 3.89543 10.1046 3 9 3H5ZM11 7V9H13V7H11ZM11 11V13H13V11H11ZM11 15V17H13V15H11ZM5 5H9V19H5V5ZM15 5H19V19H15V5Z\' />\n</g>\n\n<g id=\'icon_cpu\'>\n  <path d=\'M13.9802 7.75H10.0102C8.76023 7.75 7.74023 8.76 7.74023 10.02V13.99C7.74023 15.24 8.75023 16.26 10.0102 16.26H13.9802C15.2302 16.26 16.2502 15.25 16.2502 13.99V10.02C16.2502 8.76 15.2402 7.75 13.9802 7.75ZM13.5002 12.98L12.6102 14.53C12.4802 14.76 12.2402 14.88 12.0002 14.88C11.8802 14.88 11.7502 14.85 11.6502 14.79C11.3102 14.6 11.1902 14.17 11.3902 13.83L12.0302 12.72H11.4702C11.0202 12.72 10.6502 12.52 10.4502 12.18C10.2502 11.84 10.2702 11.42 10.5002 11.03L11.3902 9.48C11.5902 9.14 12.0202 9.03 12.3502 9.22C12.6902 9.41 12.8102 9.84 12.6102 10.18L11.9702 11.29H12.5302C12.9802 11.29 13.3502 11.49 13.5502 11.83C13.7502 12.17 13.7302 12.59 13.5002 12.98Z\' />\n  <path d=\'M21.25 12.75C21.67 12.75 22 12.41 22 12C22 11.58 21.67 11.25 21.25 11.25H20V9.05H21.25C21.67 9.05 22 8.72 22 8.3C22 7.89 21.67 7.55 21.25 7.55H19.77C19.29 5.96 18.04 4.71 16.45 4.23V2.75C16.45 2.34 16.11 2 15.7 2C15.29 2 14.95 2.34 14.95 2.75V4H12.75V2.75C12.75 2.34 12.41 2 12 2C11.59 2 11.25 2.34 11.25 2.75V4H9.06V2.75C9.06 2.34 8.72 2 8.31 2C7.89 2 7.56 2.34 7.56 2.75V4.23C5.96 4.71 4.71 5.96 4.23 7.55H2.75C2.34 7.55 2 7.89 2 8.3C2 8.72 2.34 9.05 2.75 9.05H4V11.25H2.75C2.34 11.25 2 11.58 2 12C2 12.41 2.34 12.75 2.75 12.75H4V14.95H2.75C2.34 14.95 2 15.28 2 15.7C2 16.11 2.34 16.45 2.75 16.45H4.23C4.7 18.04 5.96 19.29 7.56 19.77V21.25C7.56 21.66 7.89 22 8.31 22C8.72 22 9.06 21.66 9.06 21.25V20H11.26V21.25C11.26 21.66 11.59 22 12.01 22C12.42 22 12.76 21.66 12.76 21.25V20H14.95V21.25C14.95 21.66 15.29 22 15.7 22C16.11 22 16.45 21.66 16.45 21.25V19.77C18.04 19.29 19.29 18.04 19.77 16.45H21.25C21.67 16.45 22 16.11 22 15.7C22 15.28 21.67 14.95 21.25 14.95H20V12.75H21.25ZM17.26 14.26C17.26 15.91 15.91 17.26 14.26 17.26H9.74C8.09 17.26 6.74 15.91 6.74 14.26V9.74C6.74 8.09 8.09 6.74 9.74 6.74H14.26C15.91 6.74 17.26 8.09 17.26 9.74V14.26Z\' />\n</g>\n\n<g id=\'icon_input\'>\n  <path d=\'M3 6L6 6L6 12L10 12L10 6L13 6V5L8 0L3 5L3 6Z\' />\n  <path d=\'M2 16L14 16V14L2 14V16Z\' />\n</g>\n\n<g id=\'icon_output\'>\n  <path d=\'M13 9H10V16H6V9L3 9V8L8 3L13 8V9Z\' />\n  <path d=\'M14 2H2V0H14V2Z\' />\n</g>\n\n</defs>\n<rect x=\'0\' y=\'27\' width=\'298\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'301\' y=\'27\' width=\'64\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'395\' y=\'27\' width=\'200\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'368\' y=\'27\' width=\'24\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'598\' y=\'27\' width=\'682\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<circle cx=\'8\' cy=\'60\' r=\'7\' stroke=\'var(--stage-main, #F2F2F2)\' stroke-width=\'1\' fill=\'var(--stage-clone, #D9D9D9)\' />\n<text text-anchor=\'middle\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'8\' y=\'64\'>1</text>\n<g><title>Output Rows 33%, 3</title>\n  <rect x=\'303\' y=\'33\' width=\'60\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'303,33 333,33 363,33 363,47 303,47\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'303\' y=\'36\' width=\'5\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'303\' y=\'44\'>3</text>\n</g>\n<g><title>Output 50%, 31B, Rows 50%, 3</title>\n<use href=\'#icon_output\' transform=\'translate(395 29) scale(0.9 0.9)\' fill=\'var(--output-medium, #5781B9)\'/>\n  <rect x=\'413\' y=\'29\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'413,29 503,29 593,29 593,43 413,43\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'413\' y=\'32\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'40\'>31B</text>\n</g>\n<g><title>Output, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'29\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-medium, #5781B9)\'/>\n</g>\n<g><title>Memory 0%, 1.00MB</title>\n<use href=\'#icon_memory\' transform=\'translate(395 45) scale(0.6 0.6)\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <rect x=\'413\' y=\'45\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--mem-light, #AA7785)\'/>  <polygon points=\'413,45 413,45 413,45 413,59 413,59\' stroke=\'none\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n<rect x=\'413\' y=\'48\' width=\'33\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'56\'>1.00MB</text>\n</g>\n<g><title>CPU Usage 18%, 121us</title>\n<use href=\'#icon_cpu\' transform=\'translate(395 61) scale(0.6 0.6)\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <rect x=\'413\' y=\'61\' width=\'42\' height=\'14\' stroke-width=\'0\' fill=\'var(--cpu-light, #B78C98)\'/>  <polygon points=\'413,61 434,61 455,61 455,75 413,75\' stroke=\'none\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n<rect x=\'413\' y=\'64\' width=\'28\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'72\'>121us</text>\n</g>\n<g><title>Input 100%, 31B, Rows 100%, 3, Width 10B</title>\n<use href=\'#icon_input\' transform=\'translate(395 77) scale(0.9 0.9)\' fill=\'var(--input-medium, #5A8183)\'/>\n  <rect x=\'413\' y=\'77\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--input-light, #7CA3A5)\'/>  <polygon points=\'413,77 503,77 593,77 593,91 413,91\' stroke=\'none\' fill=\'var(--input-medium, #5A8183)\'/>\n<rect x=\'413\' y=\'80\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'88\'>31B</text>\n</g>\n<g><title>Input, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'77\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--input-medium, #5A8183)\'/>\n</g>\n<rect x=\'0\' y=\'96\' width=\'298\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'301\' y=\'96\' width=\'64\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'395\' y=\'96\' width=\'200\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'368\' y=\'96\' width=\'24\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'598\' y=\'96\' width=\'682\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<circle cx=\'8\' cy=\'129\' r=\'7\' stroke=\'var(--stage-main, #F2F2F2)\' stroke-width=\'1\' fill=\'var(--stage-clone, #D9D9D9)\' />\n<text text-anchor=\'middle\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'8\' y=\'133\'>0</text>\n<g><title>Output Rows 33%, 3</title>\n  <rect x=\'303\' y=\'102\' width=\'60\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'303,102 333,102 363,102 363,116 303,116\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'303\' y=\'105\' width=\'5\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'303\' y=\'113\'>3</text>\n</g>\n<g><title>Output Rows 33%, 3, Est: 0 Rows: 0 Size: 0B</title>\n  <rect x=\'303\' y=\'122\' width=\'60\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'303,122 333,122 363,122 363,136 303,136\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'303\' y=\'125\' width=\'5\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'303\' y=\'133\'>3</text>\n</g>\n<g><title>Output 50%, 31B, Rows 50%, 3</title>\n<use href=\'#icon_output\' transform=\'translate(395 98) scale(0.9 0.9)\' fill=\'var(--output-medium, #5781B9)\'/>\n  <rect x=\'413\' y=\'98\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'413,98 503,98 593,98 593,112 413,112\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'413\' y=\'101\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'109\'>31B</text>\n</g>\n<g><title>Output, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'98\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-medium, #5781B9)\'/>\n</g>\n<g><title>Memory 99%, 201.00MB</title>\n<use href=\'#icon_memory\' transform=\'translate(395 114) scale(0.6 0.6)\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <rect x=\'413\' y=\'114\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--mem-light, #AA7785)\'/>  <polygon points=\'413,114 503,114 593,114 593,128 413,128\' stroke=\'none\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n<rect x=\'413\' y=\'117\' width=\'44\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'125\'>201.00MB</text>\n</g>\n<g><title>CPU Usage 81%, 516us</title>\n<use href=\'#icon_cpu\' transform=\'translate(395 130) scale(0.6 0.6)\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <rect x=\'413\' y=\'130\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--cpu-light, #B78C98)\'/>  <polygon points=\'413,130 503,130 593,130 593,144 413,144\' stroke=\'none\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n<rect x=\'413\' y=\'133\' width=\'28\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'141\'>516us</text>\n</g>\n<g><title>Ingress 100%, 54B, Rows 100%, 3, Width 18B</title>\n<use href=\'#icon_input\' transform=\'translate(395 146) scale(0.9 0.9)\' fill=\'var(--ingress-medium, #466364)\'/>\n  <rect x=\'413\' y=\'146\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--ingress-light, #5A8183)\'/>  <polygon points=\'413,146 503,146 593,146 593,160 413,160\' stroke=\'none\' fill=\'var(--ingress-medium, #466364)\'/>\n<rect x=\'413\' y=\'149\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'157\'>54B</text>\n</g>\n<g><title>Ingress, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'146\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--ingress-medium, #466364)\'/>\n</g>\n\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'162\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'602\' y=\'11\'>0:00</text>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'0\' y=\'11\'>ResultSet</text>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'303\' y=\'11\'>Operators</text>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'397\' y=\'11\'>Stages</text>\n<text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'11\'>Tasks</text>\n<text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'22\'>2</text>\n<g><title>Ingress 54B, Rows 3, Width 18B, Avg 54B/s</title>\n  <rect x=\'395\' y=\'14\' width=\'65\' height=\'10\' stroke-width=\'0\' fill=\'var(--ingress-medium, #466364)\'/>\n  <text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-light, #FFFFFF)\' x=\'397\' y=\'22\'>54B</text>\n</g>\n<g><title>CPU Usage 637us, Avg 0.00 CPU/s</title>\n  <rect x=\'462\' y=\'14\' width=\'66\' height=\'10\' stroke-width=\'0\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-light, #FFFFFF)\' x=\'464\' y=\'22\'>637us</text>\n</g>\n<g><title>Memory 202.00MB</title>\n  <rect x=\'530\' y=\'14\' width=\'65\' height=\'10\' stroke-width=\'0\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-light, #FFFFFF)\' x=\'532\' y=\'22\'>202.00MB</text>\n</g>\n<g><title>Duration: 1.00, Total 1.00</title>\n  <rect x=\'1215\' y=\'3\' width=\'65\' height=\'10\' stroke-width=\'0\' fill=\'var(--stage-grid, #B2B2B2)\'/>\n  <text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-inv, #FFFFFF)\' x=\'1278\' y=\'11\'>1.00</text>\n</g>\n<g><title>Max CPU 1.20</title>\n<polygon points=\'598,26 598,26 598,26 598,26 598,26 598,26 599,26 599,26 599,26 599,26 599,26 600,26 600,26 600,26 600,26 600,26 600,26 600,26 600,26 600,26 601,26 601,26 601,26 601,26 602,26 602,26 602,26 602,26 602,13 602,25 602,26 602,26 602,26 603,26 603,26 \' stroke-width=\'1\' stroke=\'var(--cpu-medium, #A36D7B)\' fill=\'var(--cpu-light, #B78C98)\' />\n</g>\n<g><title>Collect: </title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'38\'>Collect</text>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'22\' y=\'48\'></text></g>\n<g><title>Stage 1, tasks: 1, finished: 1</title>\n<line x1=\'371\' y1=\'27\' x2=\'371\' y2=\'93\' stroke-width=\'6\' stroke=\'var(--stage-text, #262626)\' stroke-dasharray=\'1,1\' />\n  <text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'64\'>1</text>\n</g>\n<g><title>Max MEM 1.00MB</title>\n<polygon points=\'598,58 598,45 603,45 603,58 \' stroke-width=\'1\' stroke=\'var(--mem-medium, #7E4E5B)\' fill=\'var(--mem-medium, #7E4E5B)\' />\n</g>\n<g><title>Max CPU 0.10</title>\n<polygon points=\'598,74 598,74 598,74 598,74 598,74 598,74 599,74 599,74 599,74 599,74 599,74 600,74 600,74 600,74 600,74 600,74 600,74 600,74 600,74 600,74 601,74 601,74 601,74 601,74 602,74 602,74 602,74 602,74 602,74 602,74 602,74 602,74 602,61 603,74 603,74 \' stroke-width=\'1\' stroke=\'var(--cpu-medium, #A36D7B)\' fill=\'var(--cpu-light, #B78C98)\' />\n</g>\n<g><title>Connection: UnionAll</title>\n  <polygon points=\'16,110 0,110 0,96 8,92 16,96\' stroke-width=\'1\' stroke=\'var(--conn-line, #BFBFBF)\' fill=\'var(--conn-fill, #BFBFBF)\'/>\n  <text text-anchor=\'middle\' font-family=\'Verdana\' font-size=\'6px\' fill=\'var(--conn-text, #393939)\' x=\'8\' y=\'106\'>U</text>\n</g>\n<g><title>Stage: </title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'107\'>Stage</text>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'22\' y=\'117\'></text></g>\n<line x1=\'18\' y1=\'119\' x2=\'298\' y2=\'119\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n<g><title>Source s3: h752177879844301271_test_format_inferencefruitbucket.test.csv (Fruit, Price, Weight)</title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'127\'>Source s3</text>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'22\' y=\'137\'>h752177879844301271_test_format_inferencefruitbucket.test.csv (Fruit, Price, Weight)</text></g>\n<g><title>Stage 0, tasks: 1, finished: 1</title>\n<line x1=\'371\' y1=\'96\' x2=\'371\' y2=\'162\' stroke-width=\'6\' stroke=\'var(--stage-text, #262626)\' stroke-dasharray=\'1,1\' />\n  <text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'133\'>1</text>\n</g>\n<g><title>Max MEM 201.00MB</title>\n<polygon points=\'598,127 598,127 602,114 602,127 \' stroke-width=\'1\' stroke=\'var(--mem-medium, #7E4E5B)\' fill=\'var(--mem-medium, #7E4E5B)\' />\n</g>\n<g><title>Max CPU 1.40</title>\n<polygon points=\'598,143 598,143 598,143 598,143 598,143 598,143 598,143 599,143 599,143 599,143 599,143 599,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 601,143 601,143 601,143 601,143 601,143 602,143 602,143 602,143 602,143 602,130 602,142 602,143 \' stroke-width=\'1\' stroke=\'var(--cpu-medium, #A36D7B)\' fill=\'var(--cpu-light, #B78C98)\' />\n</g>\n\n</svg>\n"
  }
}

2025-12-12 13:25:31,791 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r70j5rjboe5ek"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765545929
        nanos: 500790000
      }
      modified_at {
        seconds: 1765545929
        nanos: 500790000
      }
      revision: 1
    }
    started_at {
      seconds: 1765545930
      nanos: 342000000
    }
    finished_at {
      seconds: 1765545931
      nanos: 458000000
    }
    execute_mode: RUN
    status: COMPLETED
    last_job_query_revision: 1
    last_job_id: "ptjudq7r70j5qi9ssi7u-ptqudq7r70j5rjboe5ek"
    result_expire_at {
      seconds: 1765632330
      nanos: 296341000
    }
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765545929
      nanos: 500790000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h752177879844301271_test_format_inferencefruitbucket`.`test.csv`\n            WITH (format=`csv_with_names`, with_infer=\'true\');\n            "
    syntax: YQL_V1
  }
  plan {
    json: "{\"Plan\":{\"Plans\":[{\"PlanNodeId\":5,\"Plans\":[{\"PlanNodeId\":4,\"Plans\":[{\"PlanNodeId\":3,\"Plans\":[{\"PlanNodeId\":2,\"Plans\":[{\"PlanNodeId\":1,\"Operators\":[{\"E-Size\":\"0\",\"Format\":\"csv_with_names\",\"Name\":\"h752177879844301271_test_format_inferencefruitbucket.test.csv \",\"Inputs\":[],\"Path\":\"test.csv \",\"E-Rows\":\"0\",\"ExternalDataSource\":\"h752177879844301271_test_format_inferencefruitbucket\",\"ReadColumns\":[\"Fruit\",\"Price\",\"Weight\"],\"SourceType\":\"s3\",\"E-Cost\":\"0\"}],\"Node Type\":\"Source\"}],\"Node Type\":\"Stage\"}],\"Node Type\":\"UnionAll\",\"PlanNodeType\":\"Connection\"}],\"Node Type\":\"Collect\"}],\"Node Type\":\"ResultSet\",\"PlanNodeType\":\"ResultSet\"}],\"Node Type\":\"Query\",\"PlanNodeType\":\"Query\"},\"meta\":{\"version\":\"0.2\",\"type\":\"query\"}}"
  }
  statistics {
    json: "{\"ResultSet\":{\"Tasks\":{\"sum\":2,\"count\":2,\"avg\":1,\"max\":1,\"min\":1},\"CpuTimeUs\":{\"sum\":\"637us\",\"count\":2,\"avg\":\"318us\",\"max\":\"516us\",\"min\":\"121us\"},\"IngressBytes\":{\"sum\":54,\"count\":1,\"avg\":54,\"max\":54,\"min\":54},\"IngressRows\":{\"sum\":3,\"count\":1,\"avg\":3,\"max\":3,\"min\":3},\"InputBytes\":{\"sum\":31,\"count\":1,\"avg\":31,\"max\":31,\"min\":31},\"InputRows\":{\"sum\":3,\"count\":1,\"avg\":3,\"max\":3,\"min\":3},\"OutputBytes\":{\"sum\":62,\"count\":2,\"avg\":31,\"max\":31,\"min\":31},\"OutputRows\":{\"sum\":6,\"count\":2,\"avg\":3,\"max\":3,\"min\":3},\"ResultBytes\":{\"sum\":31,\"count\":1,\"avg\":31,\"max\":31,\"min\":31},\"ResultRows\":{\"sum\":3,\"count\":1,\"avg\":3,\"max\":3,\"min\":3},\"MaxMemoryUsage\":{\"sum\":211812352,\"count\":2,\"avg\":105906176,\"max\":210763776,\"min\":1048576}}}"
  }
  result_set_meta {
    column {
      name: "Fruit"
      type {
        type_id: UTF8
      }
    }
    column {
      name: "Price"
      type {
        optional_type {
          item {
            type_id: INT64
          }
        }
      }
    }
    column {
      name: "Weight"
      type {
        optional_type {
          item {
            type_id: INT64
          }
        }
      }
    }
    rows_count: 3
  }
  ast {
    data: "(\n(let $1 (DataSource \'\"s3\" \'\"/local/h752177879844301271_test_format_inferencefruitbucket\"))\n(let $2 (Bool \'\"true\"))\n(let $3 \'\"cluster:default_/local/h752177879844301271_test_format_inferencefruitbucket\")\n(let $4 (OptionalType (DataType \'Int64)))\n(let $5 (StructType \'(\'\"Fruit\" (DataType \'Utf8)) \'(\'\"Price\" $4) \'(\'\"Weight\" $4)))\n(let $6 (S3ParseSettings world \'(\'((String \'\"Paths {\\n  Name: \\\"test.csv\\\"\\n  Size: 54\\n  Read: true\\n}\\n\") $2 (AsStruct))) (SecureParam $3) \'\"\" \'\"test.csv \" \'\"csv_with_names\" $5 (lambda \'($11) $2) \'()))\n(let $7 (DqPhyStage \'((DqSource $1 $6)) (lambda \'($12) (block \'(\n  (let $13 (DqSourceWideWrap $12 $1 $5 \'(\'(\'format \'\"csv_with_names\"))))\n  (return (FromFlow (NarrowMap $13 (lambda \'($14 $15 $16) (AsStruct \'(\'\"Fruit\" $14) \'(\'\"Price\" $15) \'(\'\"Weight\" $16))))))\n))) \'(\'(\'\"_logical_id\" \'353) \'(\'\"_id\" \'\"7bbefed5-6de9db02-b9efb2ee-f534def5\"))))\n(let $8 (DqCnUnionAll (TDqOutput $7 \'\"0\")))\n(let $9 (DqPhyStage \'($8) (lambda \'($17) $17) \'(\'(\'\"_logical_id\" \'411) \'(\'\"_id\" \'\"4c2f8c25-86b00b86-4fe6bed3-46f4763c\"))))\n(let $10 (DqCnResult (TDqOutput $9 \'\"0\") \'()))\n(return (KqpPhysicalQuery \'((KqpPhysicalTx \'($7 $9) \'($10) \'() \'(\'(\'\"type\" \'\"generic\")))) \'((KqpTxResultBinding (ListType $5) \'\"0\" \'\"0\")) \'(\'(\'\"type\" \'\"script\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'162\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'162\'/></clipPath>\n\n<defs>\n\n<g id=\'icon_memory\'>\n  <path fill-rule=\'evenodd\' clip-rule=\'evenodd\' d=\'M5 3C3.89543 3 3 3.89543 3 5H1V7H3V9H1V11H3V13H1V15H3V17H1V19H3C3 20.1046 3.89543 21 5 21H9C10.1046 21 11 20.1046 11 19H13C13 20.1046 13.8954 21 15 21H19C20.1046 21 21 20.1046 21 19H23V17H21V15H23V13H21V11H23V9H21V7H23V5H21C21 3.89543 20.1046 3 19 3H15C13.8954 3 13 3.89543 13 5H11C11 3.89543 10.1046 3 9 3H5ZM11 7V9H13V7H11ZM11 11V13H13V11H11ZM11 15V17H13V15H11ZM5 5H9V19H5V5ZM15 5H19V19H15V5Z\' />\n</g>\n\n<g id=\'icon_cpu\'>\n  <path d=\'M13.9802 7.75H10.0102C8.76023 7.75 7.74023 8.76 7.74023 10.02V13.99C7.74023 15.24 8.75023 16.26 10.0102 16.26H13.9802C15.2302 16.26 16.2502 15.25 16.2502 13.99V10.02C16.2502 8.76 15.2402 7.75 13.9802 7.75ZM13.5002 12.98L12.6102 14.53C12.4802 14.76 12.2402 14.88 12.0002 14.88C11.8802 14.88 11.7502 14.85 11.6502 14.79C11.3102 14.6 11.1902 14.17 11.3902 13.83L12.0302 12.72H11.4702C11.0202 12.72 10.6502 12.52 10.4502 12.18C10.2502 11.84 10.2702 11.42 10.5002 11.03L11.3902 9.48C11.5902 9.14 12.0202 9.03 12.3502 9.22C12.6902 9.41 12.8102 9.84 12.6102 10.18L11.9702 11.29H12.5302C12.9802 11.29 13.3502 11.49 13.5502 11.83C13.7502 12.17 13.7302 12.59 13.5002 12.98Z\' />\n  <path d=\'M21.25 12.75C21.67 12.75 22 12.41 22 12C22 11.58 21.67 11.25 21.25 11.25H20V9.05H21.25C21.67 9.05 22 8.72 22 8.3C22 7.89 21.67 7.55 21.25 7.55H19.77C19.29 5.96 18.04 4.71 16.45 4.23V2.75C16.45 2.34 16.11 2 15.7 2C15.29 2 14.95 2.34 14.95 2.75V4H12.75V2.75C12.75 2.34 12.41 2 12 2C11.59 2 11.25 2.34 11.25 2.75V4H9.06V2.75C9.06 2.34 8.72 2 8.31 2C7.89 2 7.56 2.34 7.56 2.75V4.23C5.96 4.71 4.71 5.96 4.23 7.55H2.75C2.34 7.55 2 7.89 2 8.3C2 8.72 2.34 9.05 2.75 9.05H4V11.25H2.75C2.34 11.25 2 11.58 2 12C2 12.41 2.34 12.75 2.75 12.75H4V14.95H2.75C2.34 14.95 2 15.28 2 15.7C2 16.11 2.34 16.45 2.75 16.45H4.23C4.7 18.04 5.96 19.29 7.56 19.77V21.25C7.56 21.66 7.89 22 8.31 22C8.72 22 9.06 21.66 9.06 21.25V20H11.26V21.25C11.26 21.66 11.59 22 12.01 22C12.42 22 12.76 21.66 12.76 21.25V20H14.95V21.25C14.95 21.66 15.29 22 15.7 22C16.11 22 16.45 21.66 16.45 21.25V19.77C18.04 19.29 19.29 18.04 19.77 16.45H21.25C21.67 16.45 22 16.11 22 15.7C22 15.28 21.67 14.95 21.25 14.95H20V12.75H21.25ZM17.26 14.26C17.26 15.91 15.91 17.26 14.26 17.26H9.74C8.09 17.26 6.74 15.91 6.74 14.26V9.74C6.74 8.09 8.09 6.74 9.74 6.74H14.26C15.91 6.74 17.26 8.09 17.26 9.74V14.26Z\' />\n</g>\n\n<g id=\'icon_input\'>\n  <path d=\'M3 6L6 6L6 12L10 12L10 6L13 6V5L8 0L3 5L3 6Z\' />\n  <path d=\'M2 16L14 16V14L2 14V16Z\' />\n</g>\n\n<g id=\'icon_output\'>\n  <path d=\'M13 9H10V16H6V9L3 9V8L8 3L13 8V9Z\' />\n  <path d=\'M14 2H2V0H14V2Z\' />\n</g>\n\n</defs>\n<rect x=\'0\' y=\'27\' width=\'298\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'301\' y=\'27\' width=\'64\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'395\' y=\'27\' width=\'200\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'368\' y=\'27\' width=\'24\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'598\' y=\'27\' width=\'682\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<circle cx=\'8\' cy=\'60\' r=\'7\' stroke=\'var(--stage-main, #F2F2F2)\' stroke-width=\'1\' fill=\'var(--stage-clone, #D9D9D9)\' />\n<text text-anchor=\'middle\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'8\' y=\'64\'>1</text>\n<g><title>Output Rows 33%, 3</title>\n  <rect x=\'303\' y=\'33\' width=\'60\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'303,33 333,33 363,33 363,47 303,47\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'303\' y=\'36\' width=\'5\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'303\' y=\'44\'>3</text>\n</g>\n<g><title>Output 50%, 31B, Rows 50%, 3</title>\n<use href=\'#icon_output\' transform=\'translate(395 29) scale(0.9 0.9)\' fill=\'var(--output-medium, #5781B9)\'/>\n  <rect x=\'413\' y=\'29\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'413,29 503,29 593,29 593,43 413,43\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'413\' y=\'32\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'40\'>31B</text>\n</g>\n<g><title>Output, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'29\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-medium, #5781B9)\'/>\n</g>\n<g><title>Memory 0%, 1.00MB</title>\n<use href=\'#icon_memory\' transform=\'translate(395 45) scale(0.6 0.6)\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <rect x=\'413\' y=\'45\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--mem-light, #AA7785)\'/>  <polygon points=\'413,45 413,45 413,45 413,59 413,59\' stroke=\'none\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n<rect x=\'413\' y=\'48\' width=\'33\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'56\'>1.00MB</text>\n</g>\n<g><title>CPU Usage 18%, 121us</title>\n<use href=\'#icon_cpu\' transform=\'translate(395 61) scale(0.6 0.6)\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <rect x=\'413\' y=\'61\' width=\'42\' height=\'14\' stroke-width=\'0\' fill=\'var(--cpu-light, #B78C98)\'/>  <polygon points=\'413,61 434,61 455,61 455,75 413,75\' stroke=\'none\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n<rect x=\'413\' y=\'64\' width=\'28\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'72\'>121us</text>\n</g>\n<g><title>Input 100%, 31B, Rows 100%, 3, Width 10B</title>\n<use href=\'#icon_input\' transform=\'translate(395 77) scale(0.9 0.9)\' fill=\'var(--input-medium, #5A8183)\'/>\n  <rect x=\'413\' y=\'77\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--input-light, #7CA3A5)\'/>  <polygon points=\'413,77 503,77 593,77 593,91 413,91\' stroke=\'none\' fill=\'var(--input-medium, #5A8183)\'/>\n<rect x=\'413\' y=\'80\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'88\'>31B</text>\n</g>\n<g><title>Input, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'77\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--input-medium, #5A8183)\'/>\n</g>\n<rect x=\'0\' y=\'96\' width=\'298\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'301\' y=\'96\' width=\'64\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'395\' y=\'96\' width=\'200\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'368\' y=\'96\' width=\'24\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'598\' y=\'96\' width=\'682\' height=\'66\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<circle cx=\'8\' cy=\'129\' r=\'7\' stroke=\'var(--stage-main, #F2F2F2)\' stroke-width=\'1\' fill=\'var(--stage-clone, #D9D9D9)\' />\n<text text-anchor=\'middle\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'8\' y=\'133\'>0</text>\n<g><title>Output Rows 33%, 3</title>\n  <rect x=\'303\' y=\'102\' width=\'60\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'303,102 333,102 363,102 363,116 303,116\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'303\' y=\'105\' width=\'5\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'303\' y=\'113\'>3</text>\n</g>\n<g><title>Output Rows 33%, 3, Est: 0 Rows: 0 Size: 0B</title>\n  <rect x=\'303\' y=\'122\' width=\'60\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'303,122 333,122 363,122 363,136 303,136\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'303\' y=\'125\' width=\'5\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'303\' y=\'133\'>3</text>\n</g>\n<g><title>Output 50%, 31B, Rows 50%, 3</title>\n<use href=\'#icon_output\' transform=\'translate(395 98) scale(0.9 0.9)\' fill=\'var(--output-medium, #5781B9)\'/>\n  <rect x=\'413\' y=\'98\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-light, #6F93C3)\'/>  <polygon points=\'413,98 503,98 593,98 593,112 413,112\' stroke=\'none\' fill=\'var(--output-medium, #5781B9)\'/>\n<rect x=\'413\' y=\'101\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'109\'>31B</text>\n</g>\n<g><title>Output, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'98\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--output-medium, #5781B9)\'/>\n</g>\n<g><title>Memory 99%, 201.00MB</title>\n<use href=\'#icon_memory\' transform=\'translate(395 114) scale(0.6 0.6)\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <rect x=\'413\' y=\'114\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--mem-light, #AA7785)\'/>  <polygon points=\'413,114 503,114 593,114 593,128 413,128\' stroke=\'none\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n<rect x=\'413\' y=\'117\' width=\'44\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'125\'>201.00MB</text>\n</g>\n<g><title>CPU Usage 81%, 516us</title>\n<use href=\'#icon_cpu\' transform=\'translate(395 130) scale(0.6 0.6)\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <rect x=\'413\' y=\'130\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--cpu-light, #B78C98)\'/>  <polygon points=\'413,130 503,130 593,130 593,144 413,144\' stroke=\'none\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n<rect x=\'413\' y=\'133\' width=\'28\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'141\'>516us</text>\n</g>\n<g><title>Ingress 100%, 54B, Rows 100%, 3, Width 18B</title>\n<use href=\'#icon_input\' transform=\'translate(395 146) scale(0.9 0.9)\' fill=\'var(--ingress-medium, #466364)\'/>\n  <rect x=\'413\' y=\'146\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--ingress-light, #5A8183)\'/>  <polygon points=\'413,146 503,146 593,146 593,160 413,160\' stroke=\'none\' fill=\'var(--ingress-medium, #466364)\'/>\n<rect x=\'413\' y=\'149\' width=\'16\' height=\'9\' stroke-width=\'0\' opacity=\'0.5\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-summary, #262626)\' x=\'413\' y=\'157\'>54B</text>\n</g>\n<g><title>Ingress, Duration: 0.00 (0.00 | 0.00 | 0.00 - 0.00 | 0.00 | 0.00)</title><rect x=\'602\' y=\'146\' width=\'0\' height=\'14\' stroke-width=\'0\' fill=\'var(--ingress-medium, #466364)\'/>\n</g>\n\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'162\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'602\' y=\'11\'>0:00</text>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'0\' y=\'11\'>ResultSet</text>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'303\' y=\'11\'>Operators</text>\n<text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'397\' y=\'11\'>Stages</text>\n<text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'11\'>Tasks</text>\n<text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'22\'>2</text>\n<g><title>Ingress 54B, Rows 3, Width 18B, Avg 54B/s</title>\n  <rect x=\'395\' y=\'14\' width=\'65\' height=\'10\' stroke-width=\'0\' fill=\'var(--ingress-medium, #466364)\'/>\n  <text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-light, #FFFFFF)\' x=\'397\' y=\'22\'>54B</text>\n</g>\n<g><title>CPU Usage 637us, Avg 0.00 CPU/s</title>\n  <rect x=\'462\' y=\'14\' width=\'66\' height=\'10\' stroke-width=\'0\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-light, #FFFFFF)\' x=\'464\' y=\'22\'>637us</text>\n</g>\n<g><title>Memory 202.00MB</title>\n  <rect x=\'530\' y=\'14\' width=\'65\' height=\'10\' stroke-width=\'0\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <text font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-light, #FFFFFF)\' x=\'532\' y=\'22\'>202.00MB</text>\n</g>\n<g><title>Duration: 1.00, Total 1.00</title>\n  <rect x=\'1215\' y=\'3\' width=\'65\' height=\'10\' stroke-width=\'0\' fill=\'var(--stage-grid, #B2B2B2)\'/>\n  <text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--text-inv, #FFFFFF)\' x=\'1278\' y=\'11\'>1.00</text>\n</g>\n<g><title>Max CPU 1.20</title>\n<polygon points=\'598,26 598,26 598,26 598,26 598,26 598,26 599,26 599,26 599,26 599,26 599,26 600,26 600,26 600,26 600,26 600,26 600,26 600,26 600,26 600,26 601,26 601,26 601,26 601,26 602,26 602,26 602,26 602,26 602,13 602,25 602,26 602,26 602,26 603,26 603,26 \' stroke-width=\'1\' stroke=\'var(--cpu-medium, #A36D7B)\' fill=\'var(--cpu-light, #B78C98)\' />\n</g>\n<g><title>Collect: </title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'38\'>Collect</text>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'22\' y=\'48\'></text></g>\n<g><title>Stage 1, tasks: 1, finished: 1</title>\n<line x1=\'371\' y1=\'27\' x2=\'371\' y2=\'93\' stroke-width=\'6\' stroke=\'var(--stage-text, #262626)\' stroke-dasharray=\'1,1\' />\n  <text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'64\'>1</text>\n</g>\n<g><title>Max MEM 1.00MB</title>\n<polygon points=\'598,58 598,45 603,45 603,58 \' stroke-width=\'1\' stroke=\'var(--mem-medium, #7E4E5B)\' fill=\'var(--mem-medium, #7E4E5B)\' />\n</g>\n<g><title>Max CPU 0.10</title>\n<polygon points=\'598,74 598,74 598,74 598,74 598,74 598,74 599,74 599,74 599,74 599,74 599,74 600,74 600,74 600,74 600,74 600,74 600,74 600,74 600,74 600,74 601,74 601,74 601,74 601,74 602,74 602,74 602,74 602,74 602,74 602,74 602,74 602,74 602,61 603,74 603,74 \' stroke-width=\'1\' stroke=\'var(--cpu-medium, #A36D7B)\' fill=\'var(--cpu-light, #B78C98)\' />\n</g>\n<g><title>Connection: UnionAll</title>\n  <polygon points=\'16,110 0,110 0,96 8,92 16,96\' stroke-width=\'1\' stroke=\'var(--conn-line, #BFBFBF)\' fill=\'var(--conn-fill, #BFBFBF)\'/>\n  <text text-anchor=\'middle\' font-family=\'Verdana\' font-size=\'6px\' fill=\'var(--conn-text, #393939)\' x=\'8\' y=\'106\'>U</text>\n</g>\n<g><title>Stage: </title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'107\'>Stage</text>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'22\' y=\'117\'></text></g>\n<line x1=\'18\' y1=\'119\' x2=\'298\' y2=\'119\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n<g><title>Source s3: h752177879844301271_test_format_inferencefruitbucket.test.csv (Fruit, Price, Weight)</title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'127\'>Source s3</text>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'22\' y=\'137\'>h752177879844301271_test_format_inferencefruitbucket.test.csv (Fruit, Price, Weight)</text></g>\n<g><title>Stage 0, tasks: 1, finished: 1</title>\n<line x1=\'371\' y1=\'96\' x2=\'371\' y2=\'162\' stroke-width=\'6\' stroke=\'var(--stage-text, #262626)\' stroke-dasharray=\'1,1\' />\n  <text text-anchor=\'end\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'390\' y=\'133\'>1</text>\n</g>\n<g><title>Max MEM 201.00MB</title>\n<polygon points=\'598,127 598,127 602,114 602,127 \' stroke-width=\'1\' stroke=\'var(--mem-medium, #7E4E5B)\' fill=\'var(--mem-medium, #7E4E5B)\' />\n</g>\n<g><title>Max CPU 1.40</title>\n<polygon points=\'598,143 598,143 598,143 598,143 598,143 598,143 598,143 599,143 599,143 599,143 599,143 599,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 601,143 601,143 601,143 601,143 601,143 602,143 602,143 602,143 602,143 602,130 602,142 602,143 \' stroke-width=\'1\' stroke=\'var(--cpu-medium, #A36D7B)\' fill=\'var(--cpu-light, #B78C98)\' />\n</g>\n\n</svg>\n"
  }
}

2025-12-12 13:25:31,938 - DEBUG - root - validate_result_inference: columns {
  name: "Fruit"
  type {
    type_id: UTF8
  }
}
columns {
  name: "Price"
  type {
    optional_type {
      item {
        type_id: INT64
      }
    }
  }
}
columns {
  name: "Weight"
  type {
    optional_type {
      item {
        type_id: INT64
      }
    }
  }
}
rows {
  items {
    text_value: "Banana"
  }
  items {
    int64_value: 3
  }
  items {
    int64_value: 100
  }
}
rows {
  items {
    text_value: "Apple"
  }
  items {
    int64_value: 2
  }
  items {
    int64_value: 22
  }
}
rows {
  items {
    text_value: "Pear"
  }
  items {
    int64_value: 15
  }
  items {
    int64_value: 33
  }
}

2025-12-12 13:25:31,940 - INFO - ya.test - pytest_runtest_teardown: Test teardown
