2025-11-14 10:09:23,729 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 10:09:23,729 - INFO - ya.test - pytest_runtest_setup: test_s3_insert[v2-kikimr_settings0-client0]
2025-11-14 10:09:23,729 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-14 10:09:23,729 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-14 10:09:23,732 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5914
2025-11-14 10:09:23,732 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/5914
2025-11-14 10:09:23,732 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5915
2025-11-14 10:09:23,733 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/contrib/python/moto/bin/moto_server
2025-11-14 10:09:23,749 - DEBUG - root - is_s3_ready: HTTPConnectionPool(host='localhost', port=5915): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fd6dbb44060>: Failed to establish a new connection: [Errno 111] Connection refused'))
2025-11-14 10:09:24,754 - DEBUG - root - is_s3_ready: HTTPConnectionPool(host='localhost', port=5915): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPConnection object at 0x7fd6dbb46cc0>: Failed to establish a new connection: [Errno 111] Connection refused'))
2025-11-14 10:09:26,501 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/8145
2025-11-14 10:09:26,504 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/19449
2025-11-14 10:09:26,614 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:26,615 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5295
2025-11-14 10:09:26,616 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/24723
2025-11-14 10:09:26,617 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/8115
2025-11-14 10:09:26,618 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-11-14 10:09:26,624 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 10:09:26,625 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-11-14 10:09:26,661 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-11-14 10:09:26,662 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 9e4af419-08bf-4212-830c-632c6da73b3c, localhost:23522): creating call state
2025-11-14 10:09:26,662 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 9e4af419-08bf-4212-830c-632c6da73b3c, localhost:23522): request = { database: "local" }
2025-11-14 10:09:26,669 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 9e4af419-08bf-4212-830c-632c6da73b3c, localhost:23522): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-adxazuzm5e.auto.internal" port: 23522 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-11-14 10:09:26,670 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-adxazuzm5e.auto.internal:23522, location 1, ssl: False>]>
2025-11-14 10:09:26,670 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-11-14 10:09:26,685 - INFO - ydb.connection - close: Closing channel for endpoint localhost:23522
2025-11-14 10:09:26,687 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 10:09:26,687 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fd6dbc96040 state=pending>
2025-11-14 10:09:26,694 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-11-14 10:09:26,694 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fd6dbc974e0>
2025-11-14 10:09:26,695 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fd6dbc974e0>
2025-11-14 10:09:26,695 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 3c006f6a-1975-4213-a8fe-aee63e88f703, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:26,696 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 3c006f6a-1975-4213-a8fe-aee63e88f703, ghrun-adxazuzm5e.auto.internal:23522): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 10:09:26,706 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 3c006f6a-1975-4213-a8fe-aee63e88f703, ghrun-adxazuzm5e.auto.internal:23522): on response callback started
2025-11-14 10:09:26,707 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 3c006f6a-1975-4213-a8fe-aee63e88f703, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=NjNiODFlZTUtZGIyMmNlZmEtZjQ4ZjM3NDktZDBmZDViZDc=" } } } }
2025-11-14 10:09:26,707 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 3c006f6a-1975-4213-a8fe-aee63e88f703, ghrun-adxazuzm5e.auto.internal:23522): on response callback success
2025-11-14 10:09:26,708 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbc974e0>
2025-11-14 10:09:26,710 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fd6dbc974e0>
2025-11-14 10:09:26,711 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, a8ec5737-cafd-4f96-9349-d0c381544beb, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:26,712 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, a8ec5737-cafd-4f96-9349-d0c381544beb, ghrun-adxazuzm5e.auto.internal:23522): request = { session_id: "ydb://session/3?node_id=1&id=NjNiODFlZTUtZGIyMmNlZmEtZjQ4ZjM3NDktZDBmZDViZDc=" path: "local/DbPoolStorage_ed2f05ea-c591-4a5c-80f7-505a13b56ea6/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-11-14 10:09:26,786 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, a8ec5737-cafd-4f96-9349-d0c381544beb, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS } }
2025-11-14 10:09:26,787 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbc974e0>
2025-11-14 10:09:26,788 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 9c18c0a4-1209-4e2b-83b2-1e6d90a30bee, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:26,798 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 9c18c0a4-1209-4e2b-83b2-1e6d90a30bee, ghrun-adxazuzm5e.auto.internal:23522): request = { session_id: "ydb://session/3?node_id=1&id=NjNiODFlZTUtZGIyMmNlZmEtZjQ4ZjM3NDktZDBmZDViZDc=" path: "local/DbPoolStorage_ed2f05ea-c591-4a5c-80f7-505a13b56ea6/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-11-14 10:09:26,855 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 9c18c0a4-1209-4e2b-83b2-1e6d90a30bee, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS } }
2025-11-14 10:09:26,855 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbc974e0>
2025-11-14 10:09:26,856 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, f1601b68-7d56-40e4-8b73-ddabac31ae0b, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:26,857 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, f1601b68-7d56-40e4-8b73-ddabac31ae0b, ghrun-adxazuzm5e.auto.internal:23522): request = { session_id: "ydb://session/3?node_id=1&id=NjNiODFlZTUtZGIyMmNlZmEtZjQ4ZjM3NDktZDBmZDViZDc=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "--!syntax_v1\n            PRAGMA TablePathPrefix(\"local/DbPoolStorage_ed2f05ea-c591-4a5c-80f7-505a13b56ea6\");\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-11-14 10:09:26,962 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, f1601b68-7d56-40e4-8b73-ddabac31ae0b, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 10:09:26,963 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbc974e0>
2025-11-14 10:09:27,076 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:27,077 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/31241
2025-11-14 10:09:27,080 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/14946
2025-11-14 10:09:27,081 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/default/kikimr_configs"
2025-11-14 10:09:27,081 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/wp2g/003106/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/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/default/node_1/logfile_9lu4wrky.log --grpc-port=8115 --mon-port=31241 --ic-port=5295
2025-11-14 10:09:27,083 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/default/kikimr_configs/config.yaml', '--node=1', '--tenant=/default', '--node-kind=yq', '--log-file-name=/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/default/node_1/logfile_9lu4wrky.log', '--grpc-port=8115', '--mon-port=31241', '--ic-port=5295')' in '/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/default/node_1' (no wait)
2025-11-14 10:09:27,092 - DEBUG - ya.test - execute: Command pid: 470346
2025-11-14 10:09:27,094 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:8115/1
2025-11-14 10:09:27,095 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-14 10:09:27,100 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22703
2025-11-14 10:09:27,101 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1314
2025-11-14 10:09:27,181 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:27,182 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/61853
2025-11-14 10:09:27,183 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/31700
2025-11-14 10:09:27,278 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:27,279 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22961
2025-11-14 10:09:27,280 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/20744
2025-11-14 10:09:27,281 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4209
2025-11-14 10:09:27,282 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-11-14 10:09:27,285 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-14 10:09:27,286 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-11-14 10:09:27,300 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-11-14 10:09:27,301 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 706368af-58a7-4fd4-83bc-a272da2c348e, localhost:23522): creating call state
2025-11-14 10:09:27,302 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 706368af-58a7-4fd4-83bc-a272da2c348e, localhost:23522): request = { database: "local" }
2025-11-14 10:09:27,316 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 706368af-58a7-4fd4-83bc-a272da2c348e, localhost:23522): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-adxazuzm5e.auto.internal" port: 23522 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-11-14 10:09:27,317 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-adxazuzm5e.auto.internal:23522, location 1, ssl: False>]>
2025-11-14 10:09:27,317 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-11-14 10:09:27,338 - INFO - ydb.connection - close: Closing channel for endpoint localhost:23522
2025-11-14 10:09:27,405 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-11-14 10:09:27,406 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fd6dbab46f0 state=pending>
2025-11-14 10:09:27,406 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-11-14 10:09:27,407 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fd6dbab55a0>
2025-11-14 10:09:27,407 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fd6dbab55a0>
2025-11-14 10:09:27,408 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 7ed6333e-5296-49eb-a2ab-f3a785cc1449, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:27,408 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 7ed6333e-5296-49eb-a2ab-f3a785cc1449, ghrun-adxazuzm5e.auto.internal:23522): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-11-14 10:09:27,419 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 7ed6333e-5296-49eb-a2ab-f3a785cc1449, ghrun-adxazuzm5e.auto.internal:23522): on response callback started
2025-11-14 10:09:27,436 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 7ed6333e-5296-49eb-a2ab-f3a785cc1449, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ZWRjZTA0NWEtNGJlNDAwOGMtNTkwNGM5NGEtODMyYjQ3MjA=" } } } }
2025-11-14 10:09:27,436 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 7ed6333e-5296-49eb-a2ab-f3a785cc1449, ghrun-adxazuzm5e.auto.internal:23522): on response callback success
2025-11-14 10:09:27,437 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbab55a0>
2025-11-14 10:09:27,437 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fd6dbab55a0>
2025-11-14 10:09:27,438 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 62d46ae2-419b-4605-b0b9-3845579a01ce, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:27,439 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 62d46ae2-419b-4605-b0b9-3845579a01ce, ghrun-adxazuzm5e.auto.internal:23522): request = { session_id: "ydb://session/3?node_id=1&id=ZWRjZTA0NWEtNGJlNDAwOGMtNTkwNGM5NGEtODMyYjQ3MjA=" path: "local/DbPoolStorage_4eeaafe9-9d81-48d4-83bd-833f17fa060e/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-11-14 10:09:27,468 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 62d46ae2-419b-4605-b0b9-3845579a01ce, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS } }
2025-11-14 10:09:27,469 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbab55a0>
2025-11-14 10:09:27,470 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, d68a33bd-f2d6-4b47-a163-97bfbc5eca0a, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:27,471 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, d68a33bd-f2d6-4b47-a163-97bfbc5eca0a, ghrun-adxazuzm5e.auto.internal:23522): request = { session_id: "ydb://session/3?node_id=1&id=ZWRjZTA0NWEtNGJlNDAwOGMtNTkwNGM5NGEtODMyYjQ3MjA=" path: "local/DbPoolStorage_4eeaafe9-9d81-48d4-83bd-833f17fa060e/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-11-14 10:09:27,500 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, d68a33bd-f2d6-4b47-a163-97bfbc5eca0a, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS } }
2025-11-14 10:09:27,501 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbab55a0>
2025-11-14 10:09:27,502 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 812f33ba-2f26-4074-a51e-910c2febfac9, ghrun-adxazuzm5e.auto.internal:23522): creating call state
2025-11-14 10:09:27,503 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 812f33ba-2f26-4074-a51e-910c2febfac9, ghrun-adxazuzm5e.auto.internal:23522): request = { session_id: "ydb://session/3?node_id=1&id=ZWRjZTA0NWEtNGJlNDAwOGMtNTkwNGM5NGEtODMyYjQ3MjA=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "--!syntax_v1\n            PRAGMA TablePathPrefix(\"local/DbPoolStorage_4eeaafe9-9d81-48d4-83bd-833f17fa060e\");\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-11-14 10:09:27,557 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 812f33ba-2f26-4074-a51e-910c2febfac9, ghrun-adxazuzm5e.auto.internal:23522): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-14 10:09:27,557 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fd6dbab55a0>
2025-11-14 10:09:27,558 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/65407
2025-11-14 10:09:27,692 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:27,694 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/19998
2025-11-14 10:09:27,694 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/21260
2025-11-14 10:09:27,695 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/cp/kikimr_configs"
2025-11-14 10:09:27,696 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/wp2g/003106/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/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/cp/node_1/logfile_pl1rmvyg.log --grpc-port=4209 --mon-port=19998 --ic-port=61853
2025-11-14 10:09:27,697 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/cp/kikimr_configs/config.yaml', '--node=1', '--tenant=/cp', '--node-kind=yq', '--log-file-name=/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/cp/node_1/logfile_pl1rmvyg.log', '--grpc-port=4209', '--mon-port=19998', '--ic-port=61853')' in '/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/cp/node_1' (no wait)
2025-11-14 10:09:27,709 - DEBUG - ya.test - execute: Command pid: 471445
2025-11-14 10:09:27,710 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:4209/1
2025-11-14 10:09:27,711 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-14 10:09:27,776 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:27,777 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/14117
2025-11-14 10:09:27,777 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/25048
2025-11-14 10:09:27,778 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/compute/kikimr_configs"
2025-11-14 10:09:27,778 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/wp2g/003106/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/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/compute/node_1/logfile_q4god3qs.log --grpc-port=65407 --mon-port=14117 --ic-port=22961
2025-11-14 10:09:27,779 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/compute/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/compute/node_1/logfile_q4god3qs.log', '--grpc-port=65407', '--mon-port=14117', '--ic-port=22961')' in '/home/runner/.ya/build/build_root/wp2g/003106/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_bindings_1/testing_out_stuff/test_bindings_1.py.TestBindings.test_s3_insert.v2-kikimr_settings0-client0/compute/node_1' (no wait)
2025-11-14 10:09:27,788 - DEBUG - ya.test - execute: Command pid: 471559
2025-11-14 10:09:27,789 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:65407/1
2025-11-14 10:09:32,261 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:32,263 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out
2025-11-14 10:09:32,264 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err
2025-11-14 10:09:32,264 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:65407', '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: 22961\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-14 10:09:32,270 - DEBUG - ya.test - execute: Command pid: 476689
2025-11-14 10:09:33,298 - DEBUG - ya.test - _save_outputs: Command (pid 476689) rc: 0
2025-11-14 10:09:33,299 - DEBUG - ya.test - _save_outputs: Command (pid 476689) elapsed time (sec): 1.0271580219268799
2025-11-14 10:09:33,299 - DEBUG - ya.test - _save_outputs: Command (pid 476689) idrss: 0
2025-11-14 10:09:33,299 - DEBUG - ya.test - _save_outputs: Command (pid 476689) inblock: 0
2025-11-14 10:09:33,299 - DEBUG - ya.test - _save_outputs: Command (pid 476689) isrss: 0
2025-11-14 10:09:33,299 - DEBUG - ya.test - _save_outputs: Command (pid 476689) ixrss: 0
2025-11-14 10:09:33,300 - DEBUG - ya.test - _save_outputs: Command (pid 476689) majflt: 0
2025-11-14 10:09:33,300 - DEBUG - ya.test - _save_outputs: Command (pid 476689) maxrss: 525776
2025-11-14 10:09:33,300 - DEBUG - ya.test - _save_outputs: Command (pid 476689) minflt: 19685
2025-11-14 10:09:33,300 - DEBUG - ya.test - _save_outputs: Command (pid 476689) msgrcv: 0
2025-11-14 10:09:33,300 - DEBUG - ya.test - _save_outputs: Command (pid 476689) msgsnd: 0
2025-11-14 10:09:33,300 - DEBUG - ya.test - _save_outputs: Command (pid 476689) nivcsw: 234
2025-11-14 10:09:33,300 - DEBUG - ya.test - _save_outputs: Command (pid 476689) nsignals: 0
2025-11-14 10:09:33,301 - DEBUG - ya.test - _save_outputs: Command (pid 476689) nswap: 0
2025-11-14 10:09:33,301 - DEBUG - ya.test - _save_outputs: Command (pid 476689) nvcsw: 99
2025-11-14 10:09:33,301 - DEBUG - ya.test - _save_outputs: Command (pid 476689) oublock: 8
2025-11-14 10:09:33,301 - DEBUG - ya.test - _save_outputs: Command (pid 476689) stime: 0.452428
2025-11-14 10:09:33,301 - DEBUG - ya.test - _save_outputs: Command (pid 476689) utime: 0.124304
2025-11-14 10:09:33,301 - DEBUG - ya.test - _save_outputs: Command (pid 476689) wtime: 1.033
2025-11-14 10:09:33,302 - DEBUG - ya.test - _save_outputs: Command (pid 476689) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-11-14 10:09:33,303 - DEBUG - ya.test - _save_outputs: Command (pid 476689) errors:

2025-11-14 10:09:33,304 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:33,305 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.0
2025-11-14 10:09:33,306 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.0
2025-11-14 10:09:33,306 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:65407', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 1\n    Name: "dynamic_storage_pool:1"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "hdd"\n    NumGroups: 2\n    PDiskFilter {\n      Property {\n        Type: ROT\n      }\n      Property {\n        Kind: 0\n      }\n    }\n  }\n}\n']' in 'None' (waiting)
2025-11-14 10:09:33,313 - DEBUG - ya.test - execute: Command pid: 477468
2025-11-14 10:09:33,933 - DEBUG - ya.test - _save_outputs: Command (pid 477468) rc: 0
2025-11-14 10:09:33,933 - DEBUG - ya.test - _save_outputs: Command (pid 477468) elapsed time (sec): 0.6188006401062012
2025-11-14 10:09:33,933 - DEBUG - ya.test - _save_outputs: Command (pid 477468) idrss: 0
2025-11-14 10:09:33,934 - DEBUG - ya.test - _save_outputs: Command (pid 477468) inblock: 0
2025-11-14 10:09:33,934 - DEBUG - ya.test - _save_outputs: Command (pid 477468) isrss: 0
2025-11-14 10:09:33,934 - DEBUG - ya.test - _save_outputs: Command (pid 477468) ixrss: 0
2025-11-14 10:09:33,934 - DEBUG - ya.test - _save_outputs: Command (pid 477468) majflt: 0
2025-11-14 10:09:33,934 - DEBUG - ya.test - _save_outputs: Command (pid 477468) maxrss: 525764
2025-11-14 10:09:33,934 - DEBUG - ya.test - _save_outputs: Command (pid 477468) minflt: 19683
2025-11-14 10:09:33,935 - DEBUG - ya.test - _save_outputs: Command (pid 477468) msgrcv: 0
2025-11-14 10:09:33,935 - DEBUG - ya.test - _save_outputs: Command (pid 477468) msgsnd: 0
2025-11-14 10:09:33,935 - DEBUG - ya.test - _save_outputs: Command (pid 477468) nivcsw: 137
2025-11-14 10:09:33,935 - DEBUG - ya.test - _save_outputs: Command (pid 477468) nsignals: 0
2025-11-14 10:09:33,935 - DEBUG - ya.test - _save_outputs: Command (pid 477468) nswap: 0
2025-11-14 10:09:33,936 - DEBUG - ya.test - _save_outputs: Command (pid 477468) nvcsw: 94
2025-11-14 10:09:33,936 - DEBUG - ya.test - _save_outputs: Command (pid 477468) oublock: 8
2025-11-14 10:09:33,936 - DEBUG - ya.test - _save_outputs: Command (pid 477468) stime: 0.31210899999999997
2025-11-14 10:09:33,936 - DEBUG - ya.test - _save_outputs: Command (pid 477468) utime: 0.11145899999999999
2025-11-14 10:09:33,936 - DEBUG - ya.test - _save_outputs: Command (pid 477468) wtime: 0.626
2025-11-14 10:09:33,936 - DEBUG - ya.test - _save_outputs: Command (pid 477468) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 6

2025-11-14 10:09:33,937 - DEBUG - ya.test - _save_outputs: Command (pid 477468) errors:

2025-11-14 10:09:33,939 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd
2025-11-14 10:09:33,940 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.1
2025-11-14 10:09:33,940 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.1
2025-11-14 10:09:33,941 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/wp2g/003106/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:65407', '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-11-14 10:09:33,946 - DEBUG - ya.test - execute: Command pid: 477962
2025-11-14 10:09:34,493 - DEBUG - ya.test - _save_outputs: Command (pid 477962) rc: 0
2025-11-14 10:09:34,493 - DEBUG - ya.test - _save_outputs: Command (pid 477962) elapsed time (sec): 0.5451090335845947
2025-11-14 10:09:34,494 - DEBUG - ya.test - _save_outputs: Command (pid 477962) idrss: 0
2025-11-14 10:09:34,494 - DEBUG - ya.test - _save_outputs: Command (pid 477962) inblock: 0
2025-11-14 10:09:34,494 - DEBUG - ya.test - _save_outputs: Command (pid 477962) isrss: 0
2025-11-14 10:09:34,494 - DEBUG - ya.test - _save_outputs: Command (pid 477962) ixrss: 0
2025-11-14 10:09:34,494 - DEBUG - ya.test - _save_outputs: Command (pid 477962) majflt: 0
2025-11-14 10:09:34,495 - DEBUG - ya.test - _save_outputs: Command (pid 477962) maxrss: 525760
2025-11-14 10:09:34,495 - DEBUG - ya.test - _save_outputs: Command (pid 477962) minflt: 19684
2025-11-14 10:09:34,495 - DEBUG - ya.test - _save_outputs: Command (pid 477962) msgrcv: 0
2025-11-14 10:09:34,495 - DEBUG - ya.test - _save_outputs: Command (pid 477962) msgsnd: 0
2025-11-14 10:09:34,495 - DEBUG - ya.test - _save_outputs: Command (pid 477962) nivcsw: 91
2025-11-14 10:09:34,495 - DEBUG - ya.test - _save_outputs: Command (pid 477962) nsignals: 0
2025-11-14 10:09:34,496 - DEBUG - ya.test - _save_outputs: Command (pid 477962) nswap: 0
2025-11-14 10:09:34,496 - DEBUG - ya.test - _save_outputs: Command (pid 477962) nvcsw: 111
2025-11-14 10:09:34,496 - DEBUG - ya.test - _save_outputs: Command (pid 477962) oublock: 8
2025-11-14 10:09:34,496 - DEBUG - ya.test - _save_outputs: Command (pid 477962) stime: 0.326964
2025-11-14 10:09:34,496 - DEBUG - ya.test - _save_outputs: Command (pid 477962) utime: 0.115633
2025-11-14 10:09:34,496 - DEBUG - ya.test - _save_outputs: Command (pid 477962) wtime: 0.551
2025-11-14 10:09:34,497 - DEBUG - ya.test - _save_outputs: Command (pid 477962) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 7

2025-11-14 10:09:34,497 - DEBUG - ya.test - _save_outputs: Command (pid 477962) errors:

2025-11-14 10:09:34,497 - 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-11-14 10:09:34,522 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-11-14 10:09:34,546 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-11-14 10:09:34,605 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-11-14 10:09:34,662 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-11-14 10:09:34,764 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-11-14 10:09:34,877 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_bindings_1.py::TestBindings, test_name: test_s3_insert[v2-kikimr_settings0-client0])
2025-11-14 10:09:34,885 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from creating-client-class.iot-data to creating-client-class.iot-data-plane
2025-11-14 10:09:34,892 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-call.apigateway to before-call.api-gateway
2025-11-14 10:09:34,895 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from request-created.machinelearning.Predict to request-created.machine-learning.Predict
2025-11-14 10:09:34,902 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.autoscaling.CreateLaunchConfiguration to before-parameter-build.auto-scaling.CreateLaunchConfiguration
2025-11-14 10:09:34,902 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.route53 to before-parameter-build.route-53
2025-11-14 10:09:34,905 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from request-created.cloudsearchdomain.Search to request-created.cloudsearch-domain.Search
2025-11-14 10:09:34,907 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from docs.*.autoscaling.CreateLaunchConfiguration.complete-section to docs.*.auto-scaling.CreateLaunchConfiguration.complete-section
2025-11-14 10:09:34,926 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.logs.CreateExportTask to before-parameter-build.cloudwatch-logs.CreateExportTask
2025-11-14 10:09:34,927 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from docs.*.logs.CreateExportTask.complete-section to docs.*.cloudwatch-logs.CreateExportTask.complete-section
2025-11-14 10:09:34,928 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.cloudsearchdomain.Search to before-parameter-build.cloudsearch-domain.Search
2025-11-14 10:09:34,928 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from docs.*.cloudsearchdomain.Search.complete-section to docs.*.cloudsearch-domain.Search.complete-section
2025-11-14 10:09:35,048 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/boto3/py3/boto3/data/s3/2006-03-01/resources-1.json
2025-11-14 10:09:35,072 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/endpoints.json
2025-11-14 10:09:35,179 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/sdk-default-configuration.json
2025-11-14 10:09:35,180 - DEBUG - botocore.hooks - _emit: Event choose-service-name: calling handler <function handle_service_name_alias at 0x7fd6dc720dd0>
2025-11-14 10:09:35,186 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/s3/2006-03-01/service-2.json
2025-11-14 10:09:35,218 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/s3/2006-03-01/endpoint-rule-set-1.json.gz
2025-11-14 10:09:35,244 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/partitions.json
2025-11-14 10:09:35,247 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_post at 0x7fd6dc830ad0>
2025-11-14 10:09:35,248 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function lazy_call.<locals>._handler at 0x7fd6dbbb3710>
2025-11-14 10:09:35,286 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_url at 0x7fd6dc8307d0>
2025-11-14 10:09:35,294 - DEBUG - botocore.endpoint - create_endpoint: Setting s3 timeout as (60, 60)
2025-11-14 10:09:35,300 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/_retry.json
2025-11-14 10:09:35,302 - DEBUG - botocore.client - _register_legacy_retries: Registering retry handlers for service: s3
2025-11-14 10:09:35,303 - DEBUG - botocore.utils - register: Registering S3 region redirector handler
2025-11-14 10:09:35,305 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:s3
2025-11-14 10:09:35,308 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:Bucket
2025-11-14 10:09:35,309 - DEBUG - boto3.resources.model - _load_name_with_category: Renaming Bucket attribute name
2025-11-14 10:09:35,312 - DEBUG - botocore.hooks - _emit: Event creating-resource-class.s3.Bucket: calling handler <function lazy_call.<locals>._handler at 0x7fd6dbc081d0>
2025-11-14 10:09:35,312 - DEBUG - boto3.resources.action - __call__: Calling s3:create_bucket with {'Bucket': 'bindbucket', 'ACL': 'public-read'}
2025-11-14 10:09:35,313 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function validate_bucket_name at 0x7fd6dc722c90>
2025-11-14 10:09:35,314 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fd6dc745550>
2025-11-14 10:09:35,314 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fd6bf505640>>
2025-11-14 10:09:35,314 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function generate_idempotent_uuid at 0x7fd6dc722a50>
2025-11-14 10:09:35,315 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fd6dc745790>
2025-11-14 10:09:35,315 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fd6bf505640>>
2025-11-14 10:09:35,315 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'bindbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:5915', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableAccessPoints': True, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-11-14 10:09:35,317 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:5915/bindbucket
2025-11-14 10:09:35,317 - 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-11-14 10:09:35,318 - 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-11-14 10:09:35,319 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function add_expect_header at 0x7fd6dc723110>
2025-11-14 10:09:35,320 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function add_recursion_detection_header at 0x7fd6dc721010>
2025-11-14 10:09:35,320 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function inject_api_version_header_if_needed at 0x7fd6dc744b90>
2025-11-14 10:09:35,321 - 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': '/bindbucket/', 'url': 'http://localhost:5915/bindbucket', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fd6bf5055a0>, 'has_streaming_input': False, 'auth_type': 'v4', 's3_redirect': {'redirected': False, 'bucket': 'bindbucket', 'params': {'Bucket': 'bindbucket', 'ACL': 'public-read'}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-11-14 10:09:35,322 - DEBUG - botocore.hooks - _emit: Event request-created.s3.CreateBucket: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fd6bf505550>>
2025-11-14 10:09:35,322 - 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 0x7fd6c043eef0>>
2025-11-14 10:09:35,323 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.CreateBucket: calling handler <function set_operation_specific_signer at 0x7fd6dc7228d0>
2025-11-14 10:09:35,323 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.CreateBucket: calling handler <function remove_arn_from_signing_path at 0x7fd6dc7456d0>
2025-11-14 10:09:35,325 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-11-14 10:09:35,325 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
PUT
/bindbucket

host:localhost:5915
x-amz-acl:public-read
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20251114T100935Z

host;x-amz-acl;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2025-11-14 10:09:35,325 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251114T100935Z
20251114/yandex/s3/aws4_request
a56c4c17d2f6e819f3512d94f6543543dcedefd589a01b507e3059c90cafb0f1
2025-11-14 10:09:35,325 - DEBUG - botocore.auth - add_auth: Signature:
e8d849ec3864a4696e90135bd58a8c5e0c349fe979dfe0073360908530f6c3f9
2025-11-14 10:09:35,327 - DEBUG - botocore.hooks - _emit: Event request-created.s3.CreateBucket: calling handler <function add_retry_headers at 0x7fd6dc745490>
2025-11-14 10:09:35,327 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=PUT, url=http://localhost:5915/bindbucket, 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'20251114T100935Z', 'X-Amz-Content-SHA256': b'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251114/yandex/s3/aws4_request, SignedHeaders=host;x-amz-acl;x-amz-content-sha256;x-amz-date, Signature=e8d849ec3864a4696e90135bd58a8c5e0c349fe979dfe0073360908530f6c3f9', 'amz-sdk-invocation-id': b'4f32723a-63f3-4aef-870f-f569b8a3a67f', 'amz-sdk-request': b'attempt=1', 'Content-Length': '0'}>
2025-11-14 10:09:35,342 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 14 Nov 2025 10:09:35 GMT', 'x-amzn-requestid': 'zzzQQqDJQwaIUgH2LLxnJFLrJmntDiDGICbSE2OK9E2n9JxegxaG', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '164', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-11-14 10:09:35,343 - DEBUG - botocore.parsers - parse: Response body:
b'<CreateBucketResponse xmlns="http://s3.amazonaws.com/doc/2006-03-01"><CreateBucketResponse><Bucket>bindbucket</Bucket></CreateBucketResponse></CreateBucketResponse>'
2025-11-14 10:09:35,344 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.CreateBucket: calling handler <botocore.retryhandler.RetryHandler object at 0x7fd6dc69af90>
2025-11-14 10:09:35,345 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-11-14 10:09:35,345 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.CreateBucket: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fd6bf505640>>
2025-11-14 10:09:35,345 - DEBUG - boto3.resources.action - __call__: Response: {'ResponseMetadata': {'RequestId': 'zzzQQqDJQwaIUgH2LLxnJFLrJmntDiDGICbSE2OK9E2n9JxegxaG', 'HTTPStatusCode': 200, 'HTTPHeaders': {'server': 'Werkzeug/2.2.3 Python/3.12.9', 'date': 'Fri, 14 Nov 2025 10:09:35 GMT', 'x-amzn-requestid': 'zzzQQqDJQwaIUgH2LLxnJFLrJmntDiDGICbSE2OK9E2n9JxegxaG', 'content-type': 'text/html; charset=utf-8', 'content-length': '164', 'access-control-allow-origin': '*', 'connection': 'close'}, 'RetryAttempts': 0}}
2025-11-14 10:09:35,347 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/s3/2006-03-01/paginators-1.json
2025-11-14 10:09:35,347 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/s3/2006-03-01/paginators-1.sdk-extras.json
2025-11-14 10:09:35,348 - DEBUG - boto3.resources.collection - pages: Calling paginated s3:list_objects with {'Bucket': 'bindbucket'}
2025-11-14 10:09:35,350 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function set_list_objects_encoding_type_url at 0x7fd6dc744590>
2025-11-14 10:09:35,350 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function validate_bucket_name at 0x7fd6dc722c90>
2025-11-14 10:09:35,350 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fd6dc745550>
2025-11-14 10:09:35,351 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fd6bf505640>>
2025-11-14 10:09:35,351 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function generate_idempotent_uuid at 0x7fd6dc722a50>
2025-11-14 10:09:35,351 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fd6dc745790>
2025-11-14 10:09:35,352 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fd6bf505640>>
2025-11-14 10:09:35,352 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'bindbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:5915', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-11-14 10:09:35,354 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:5915/bindbucket
2025-11-14 10:09:35,354 - 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-11-14 10:09:35,354 - 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-11-14 10:09:35,356 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function add_expect_header at 0x7fd6dc723110>
2025-11-14 10:09:35,356 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function add_recursion_detection_header at 0x7fd6dc721010>
2025-11-14 10:09:35,356 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function inject_api_version_header_if_needed at 0x7fd6dc744b90>
2025-11-14 10:09:35,356 - 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': '/bindbucket/', 'url': 'http://localhost:5915/bindbucket?encoding-type=url', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fd6bf5055a0>, 'has_streaming_input': False, 'auth_type': 'v4', 'encoding_type_auto_set': True, 's3_redirect': {'redirected': False, 'bucket': 'bindbucket', 'params': {'Bucket': 'bindbucket', 'EncodingType': 'url'}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-11-14 10:09:35,358 - DEBUG - botocore.hooks - _emit: Event request-created.s3.ListObjects: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fd6bf505550>>
2025-11-14 10:09:35,358 - 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 0x7fd6c043eef0>>
2025-11-14 10:09:35,359 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.ListObjects: calling handler <function set_operation_specific_signer at 0x7fd6dc7228d0>
2025-11-14 10:09:35,359 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.ListObjects: calling handler <function remove_arn_from_signing_path at 0x7fd6dc7456d0>
2025-11-14 10:09:35,361 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-11-14 10:09:35,361 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
GET
/bindbucket
encoding-type=url
host:localhost:5915
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20251114T100935Z

host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2025-11-14 10:09:35,362 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251114T100935Z
20251114/yandex/s3/aws4_request
c558494ba63f5768d2aa625b16325bcb12d9fa942633688e2ed1315144437858
2025-11-14 10:09:35,362 - DEBUG - botocore.auth - add_auth: Signature:
43793169715a5940ad8861cdf7b9ea12ff1cdf007a285379792ff2c8362c2218
2025-11-14 10:09:35,362 - DEBUG - botocore.hooks - _emit: Event request-created.s3.ListObjects: calling handler <function add_retry_headers at 0x7fd6dc745490>
2025-11-14 10:09:35,363 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=GET, url=http://localhost:5915/bindbucket?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'20251114T100935Z', 'X-Amz-Content-SHA256': b'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251114/yandex/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=43793169715a5940ad8861cdf7b9ea12ff1cdf007a285379792ff2c8362c2218', 'amz-sdk-invocation-id': b'e521dd48-b87e-4241-a651-a9df6e755f80', 'amz-sdk-request': b'attempt=1'}>
2025-11-14 10:09:35,390 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 14 Nov 2025 10:09:35 GMT', 'x-amzn-requestid': 'GCuMrIIrb01dDHsmSrBgJbymBojqbfjFwJpO76ifnYXkP8onjIgl', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '233', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-11-14 10:09:35,391 - 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>bindbucket</Name><MaxKeys>1000</MaxKeys><EncodingType>url</EncodingType><IsTruncated>false</IsTruncated></ListBucketResult>'
2025-11-14 10:09:35,392 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.ListObjects: calling handler <botocore.retryhandler.RetryHandler object at 0x7fd6dc69af90>
2025-11-14 10:09:35,392 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-11-14 10:09:35,393 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.ListObjects: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fd6bf505640>>
2025-11-14 10:09:35,393 - DEBUG - botocore.hooks - _emit: Event after-call.s3.ListObjects: calling handler <function decode_list_object at 0x7fd6dc744650>
2025-11-14 10:09:35,401 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:ObjectSummary
2025-11-14 10:09:35,402 - DEBUG - boto3.resources.model - _load_name_with_category: Renaming ObjectSummary attribute key
2025-11-14 10:09:35,403 - DEBUG - botocore.hooks - _emit: Event creating-resource-class.s3.ObjectSummary: calling handler <function lazy_call.<locals>._handler at 0x7fd6dbc08350>
2025-11-14 10:09:35,409 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-11-14 10:09:35,528 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-11-14 10:09:36,705 - DEBUG - root - create_query_impl: Request: content {
  type: ANALYTICS
  name: "simple"
  acl {
    visibility: PRIVATE
  }
  limits {
    execution_timeout {
    }
  }
  text: "\n            insert into bindings.`h1445379926556884511_test_s3_inserts3binding`\n            select * from AS_TABLE([<|foo:123, bar:\"xxx\"u|>,<|foo:456, bar:\"yyy\"u|>]);\n            "
  syntax: YQL_V1
}
execute_mode: RUN
idempotency_key: "2a97478a-2304-4dbf-a40c-5b1b1c8aeeb2"

2025-11-14 10:09:37,058 - DEBUG - root - create_query_impl: Result: query_id: "ptqudsej71qqe5lhb16r"

2025-11-14 10:09:37,157 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudsej71qqe5lhb16r"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1763114976
        nanos: 712226000
      }
      modified_at {
        seconds: 1763114976
        nanos: 712226000
      }
      revision: 1
    }
    execute_mode: RUN
    status: STARTING
    last_job_query_revision: 1
    last_job_id: "ptjudsej71qqdcq74d4r-ptqudsej71qqe5lhb16r"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1763114976
      nanos: 712226000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            insert into bindings.`h1445379926556884511_test_s3_inserts3binding`\n            select * from AS_TABLE([<|foo:123, bar:\"xxx\"u|>,<|foo:456, bar:\"yyy\"u|>]);\n            "
    syntax: YQL_V1
  }
}

2025-11-14 10:09:37,687 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-11-14 10:09:38,220 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-11-14 10:09:38,749 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudsej71qqe5lhb16r"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1763114976
        nanos: 712226000
      }
      modified_at {
        seconds: 1763114976
        nanos: 712226000
      }
      revision: 1
    }
    started_at {
      seconds: 1763114978
      nanos: 55000000
    }
    execute_mode: RUN
    status: RUNNING
    last_job_query_revision: 1
    last_job_id: "ptjudsej71qqdcq74d4r-ptqudsej71qqe5lhb16r"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1763114976
      nanos: 712226000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            insert into bindings.`h1445379926556884511_test_s3_inserts3binding`\n            select * from AS_TABLE([<|foo:123, bar:\"xxx\"u|>,<|foo:456, bar:\"yyy\"u|>]);\n            "
    syntax: YQL_V1
  }
}

2025-11-14 10:09:39,288 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudsej71qqe5lhb16r"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1763114976
        nanos: 712226000
      }
      modified_at {
        seconds: 1763114976
        nanos: 712226000
      }
      revision: 1
    }
    started_at {
      seconds: 1763114978
      nanos: 55000000
    }
    execute_mode: RUN
    status: COMPLETING
    last_job_query_revision: 1
    last_job_id: "ptjudsej71qqdcq74d4r-ptqudsej71qqe5lhb16r"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1763114976
      nanos: 712226000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            insert into bindings.`h1445379926556884511_test_s3_inserts3binding`\n            select * from AS_TABLE([<|foo:123, bar:\"xxx\"u|>,<|foo:456, bar:\"yyy\"u|>]);\n            "
    syntax: YQL_V1
  }
  plan {
    json: "{\"Plan\":{\"Plans\":[{\"PlanNodeId\":2,\"Plans\":[{\"PlanNodeId\":1,\"Node Type\":\"Stage\"}],\"Operators\":[{\"Inputs\":[],\"ExternalDataSource\":\"h1445379926556884511_test_s3_insertbb\",\"Extension\":\".csv\",\"Name\":\"Write h1445379926556884511_test_s3_insertbb\",\"SinkType\":\"s3\"}],\"Node Type\":\"Sink\"}],\"Node Type\":\"Query\",\"PlanNodeType\":\"Query\"},\"meta\":{\"version\":\"0.2\",\"type\":\"query\"}}"
  }
  issue {
    position {
      row: 2
      column: 25
    }
    message: "Please remove \'bindings.\' from your query, the support for this syntax will be dropped soon"
    end_position {
      row: 2
      column: 25
    }
    issue_code: 4538
    severity: 2
  }
  statistics {
    json: "{\"Sink\":{\"Tasks\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1},\"CpuTimeUs\":{\"sum\":\"303us\",\"count\":1,\"avg\":\"303us\",\"max\":\"303us\",\"min\":\"303us\"},\"EgressBytes\":{\"sum\":32,\"count\":1,\"avg\":32,\"max\":32,\"min\":32},\"EgressRows\":{\"sum\":2,\"count\":1,\"avg\":2,\"max\":2,\"min\":2},\"MaxMemoryUsage\":{\"sum\":1048576,\"count\":1,\"avg\":1048576,\"max\":1048576,\"min\":1048576}}}"
  }
  ast {
    data: "(\n(let $1 (S3SinkSettings \'\"path1/\" \'(\'(\'\"multipart\" \'\"true\")) (SecureParam \'\"cluster:default_/local/h1445379926556884511_test_s3_insertbb\") \'\".csv\" (StructType \'(\'\"bar\" (DataType \'Utf8)) \'(\'\"foo\" (DataType \'Int32)))))\n(let $2 (DqPhyStage \'() (lambda \'() (block \'(\n  (let $3 \'(\'(\'\"data.datetime.formatname\" \'\"POSIX\") \'(\'\"data.timestamp.formatname\" \'\"POSIX\") \'(\'\"file_size_limit\" \'\"52428800\")))\n  (return (FromFlow (S3SinkOutput (ToFlow (AsList (AsStruct \'(\'\"bar\" (Utf8 \'\"xxx\")) \'(\'\"foo\" (Int32 \'\"123\"))) (AsStruct \'(\'\"bar\" (Utf8 \'\"yyy\")) \'(\'\"foo\" (Int32 \'\"456\"))))) \'\"csv_with_names\" \'() $3)))\n))) \'(\'(\'\"_logical_id\" \'273) \'(\'\"_id\" \'\"61de44d0-528d0aa7-ab3eac15-4677ec6\")) \'((DqSink \'0 (DataSink \'\"s3\" \'\"/local/h1445379926556884511_test_s3_insertbb\") $1))))\n(return (KqpPhysicalQuery \'((KqpPhysicalTx \'($2) \'() \'() \'(\'(\'\"type\" \'\"generic\") \'(\'\"with_effects\")))) \'() \'(\'(\'\"type\" \'\"script\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'61\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'61\'/></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=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'301\' y=\'27\' width=\'64\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'395\' y=\'27\' width=\'200\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'368\' y=\'27\' width=\'24\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'598\' y=\'27\' width=\'682\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<circle cx=\'8\' cy=\'44\' 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=\'48\'>0</text>\n<g><title>Memory 100%, 1.00MB</title>\n<use href=\'#icon_memory\' transform=\'translate(395 29) scale(0.6 0.6)\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <rect x=\'413\' y=\'29\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--mem-light, #AA7785)\'/>  <polygon points=\'413,29 503,29 593,29 593,43 413,43\' stroke=\'none\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n<rect x=\'413\' y=\'32\' 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=\'40\'>1.00MB</text>\n</g>\n<g><title>CPU Usage 100%, 303us</title>\n<use href=\'#icon_cpu\' transform=\'translate(395 45) scale(0.6 0.6)\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <rect x=\'413\' y=\'45\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--cpu-light, #B78C98)\'/>  <polygon points=\'413,45 503,45 593,45 593,59 413,59\' stroke=\'none\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n<rect x=\'413\' y=\'48\' 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=\'56\'>303us</text>\n</g>\n\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'61\' 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\'>Sink</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\'>1</text>\n<g><title>Ingress 0B, Rows 0, Avg 0B/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\'>0B</text>\n</g>\n<g><title>CPU Usage 303us, 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\'>303us</text>\n</g>\n<g><title>Memory 1.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\'>1.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>Stage: </title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'38\'>Stage</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 0, tasks: 1, finished: 1</title>\n<line x1=\'371\' y1=\'27\' x2=\'371\' y2=\'61\' 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=\'48\'>1</text>\n</g>\n\n</svg>\n"
  }
}

2025-11-14 10:09:39,810 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudsej71qqe5lhb16r"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1763114976
        nanos: 712226000
      }
      modified_at {
        seconds: 1763114976
        nanos: 712226000
      }
      revision: 1
    }
    started_at {
      seconds: 1763114978
      nanos: 55000000
    }
    finished_at {
      seconds: 1763114979
      nanos: 640000000
    }
    execute_mode: RUN
    status: COMPLETED
    last_job_query_revision: 1
    last_job_id: "ptjudsej71qqdcq74d4r-ptqudsej71qqe5lhb16r"
    result_expire_at {
      seconds: 1763201377
      nanos: 957361000
    }
    started_by: "root@builtin"
    submitted_at {
      seconds: 1763114976
      nanos: 712226000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            insert into bindings.`h1445379926556884511_test_s3_inserts3binding`\n            select * from AS_TABLE([<|foo:123, bar:\"xxx\"u|>,<|foo:456, bar:\"yyy\"u|>]);\n            "
    syntax: YQL_V1
  }
  plan {
    json: "{\"Plan\":{\"Plans\":[{\"PlanNodeId\":2,\"Plans\":[{\"PlanNodeId\":1,\"Node Type\":\"Stage\"}],\"Operators\":[{\"Inputs\":[],\"ExternalDataSource\":\"h1445379926556884511_test_s3_insertbb\",\"Extension\":\".csv\",\"Name\":\"Write h1445379926556884511_test_s3_insertbb\",\"SinkType\":\"s3\"}],\"Node Type\":\"Sink\"}],\"Node Type\":\"Query\",\"PlanNodeType\":\"Query\"},\"meta\":{\"version\":\"0.2\",\"type\":\"query\"}}"
  }
  issue {
    position {
      row: 2
      column: 25
    }
    message: "Please remove \'bindings.\' from your query, the support for this syntax will be dropped soon"
    end_position {
      row: 2
      column: 25
    }
    issue_code: 4538
    severity: 2
  }
  statistics {
    json: "{\"Sink\":{\"Tasks\":{\"sum\":1,\"count\":1,\"avg\":1,\"max\":1,\"min\":1},\"CpuTimeUs\":{\"sum\":\"303us\",\"count\":1,\"avg\":\"303us\",\"max\":\"303us\",\"min\":\"303us\"},\"EgressBytes\":{\"sum\":32,\"count\":1,\"avg\":32,\"max\":32,\"min\":32},\"EgressRows\":{\"sum\":2,\"count\":1,\"avg\":2,\"max\":2,\"min\":2},\"MaxMemoryUsage\":{\"sum\":1048576,\"count\":1,\"avg\":1048576,\"max\":1048576,\"min\":1048576}}}"
  }
  ast {
    data: "(\n(let $1 (S3SinkSettings \'\"path1/\" \'(\'(\'\"multipart\" \'\"true\")) (SecureParam \'\"cluster:default_/local/h1445379926556884511_test_s3_insertbb\") \'\".csv\" (StructType \'(\'\"bar\" (DataType \'Utf8)) \'(\'\"foo\" (DataType \'Int32)))))\n(let $2 (DqPhyStage \'() (lambda \'() (block \'(\n  (let $3 \'(\'(\'\"data.datetime.formatname\" \'\"POSIX\") \'(\'\"data.timestamp.formatname\" \'\"POSIX\") \'(\'\"file_size_limit\" \'\"52428800\")))\n  (return (FromFlow (S3SinkOutput (ToFlow (AsList (AsStruct \'(\'\"bar\" (Utf8 \'\"xxx\")) \'(\'\"foo\" (Int32 \'\"123\"))) (AsStruct \'(\'\"bar\" (Utf8 \'\"yyy\")) \'(\'\"foo\" (Int32 \'\"456\"))))) \'\"csv_with_names\" \'() $3)))\n))) \'(\'(\'\"_logical_id\" \'273) \'(\'\"_id\" \'\"61de44d0-528d0aa7-ab3eac15-4677ec6\")) \'((DqSink \'0 (DataSink \'\"s3\" \'\"/local/h1445379926556884511_test_s3_insertbb\") $1))))\n(return (KqpPhysicalQuery \'((KqpPhysicalTx \'($2) \'() \'() \'(\'(\'\"type\" \'\"generic\") \'(\'\"with_effects\")))) \'() \'(\'(\'\"type\" \'\"script\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'61\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'61\'/></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=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'301\' y=\'27\' width=\'64\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'395\' y=\'27\' width=\'200\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'368\' y=\'27\' width=\'24\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<rect x=\'598\' y=\'27\' width=\'682\' height=\'34\' stroke-width=\'0\' fill=\'var(--stage-main, #F2F2F2)\'/>\n<circle cx=\'8\' cy=\'44\' 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=\'48\'>0</text>\n<g><title>Memory 100%, 1.00MB</title>\n<use href=\'#icon_memory\' transform=\'translate(395 29) scale(0.6 0.6)\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n  <rect x=\'413\' y=\'29\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--mem-light, #AA7785)\'/>  <polygon points=\'413,29 503,29 593,29 593,43 413,43\' stroke=\'none\' fill=\'var(--mem-medium, #7E4E5B)\'/>\n<rect x=\'413\' y=\'32\' 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=\'40\'>1.00MB</text>\n</g>\n<g><title>CPU Usage 100%, 303us</title>\n<use href=\'#icon_cpu\' transform=\'translate(395 45) scale(0.6 0.6)\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n  <rect x=\'413\' y=\'45\' width=\'180\' height=\'14\' stroke-width=\'0\' fill=\'var(--cpu-light, #B78C98)\'/>  <polygon points=\'413,45 503,45 593,45 593,59 413,59\' stroke=\'none\' fill=\'var(--cpu-medium, #A36D7B)\'/>\n<rect x=\'413\' y=\'48\' 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=\'56\'>303us</text>\n</g>\n\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'61\' 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\'>Sink</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\'>1</text>\n<g><title>Ingress 0B, Rows 0, Avg 0B/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\'>0B</text>\n</g>\n<g><title>CPU Usage 303us, 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\'>303us</text>\n</g>\n<g><title>Memory 1.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\'>1.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>Stage: </title>  <text clip-path=\'url(#clipTextPath)\' font-family=\'Verdana\' font-size=\'8px\' fill=\'var(--stage-text, #262626)\' x=\'18\' y=\'38\'>Stage</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 0, tasks: 1, finished: 1</title>\n<line x1=\'371\' y1=\'27\' x2=\'371\' y2=\'61\' 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=\'48\'>1</text>\n</g>\n\n</svg>\n"
  }
}

2025-11-14 10:09:39,836 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-11-14 10:09:39,836 - DEBUG - root - create_query_impl: Request: content {
  type: ANALYTICS
  name: "simple"
  acl {
    visibility: PRIVATE
  }
  limits {
    execution_timeout {
    }
  }
  text: "\n            select foo, bar from bindings.`h1445379926556884511_test_s3_inserts3binding`;\n            "
  syntax: YQL_V1
}
execute_mode: RUN
idempotency_key: "d5e40a67-55eb-44a3-8918-74cff05a98c5"

2025-11-14 10:09:39,881 - DEBUG - root - create_query_impl: Result: query_id: "ptqudsej6ur4tfbdg2i0"

2025-11-14 10:09:39,903 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudsej6ur4tfbdg2i0"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1763114979
        nanos: 847238000
      }
      modified_at {
        seconds: 1763114979
        nanos: 847238000
      }
      revision: 1
    }
    execute_mode: RUN
    status: STARTING
    last_job_query_revision: 1
    last_job_id: "ptjudsej6ur4smp1o109-ptqudsej6ur4tfbdg2i0"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1763114979
      nanos: 847238000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            select foo, bar from bindings.`h1445379926556884511_test_s3_inserts3binding`;\n            "
    syntax: YQL_V1
  }
}

2025-11-14 10:09:40,429 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudsej6ur4tfbdg2i0"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1763114979
        nanos: 847238000
      }
      modified_at {
        seconds: 1763114979
        nanos: 847238000
      }
      revision: 1
    }
    started_at {
      seconds: 1763114979
      nanos: 916000000
    }
    finished_at {
      seconds: 1763114980
      nanos: 370000000
    }
    execute_mode: RUN
    status: COMPLETED
    last_job_query_revision: 1
    last_job_id: "ptjudsej6ur4smp1o109-ptqudsej6ur4tfbdg2i0"
    result_expire_at {
      seconds: 1763201379
      nanos: 897501000
    }
    started_by: "root@builtin"
    submitted_at {
      seconds: 1763114979
      nanos: 847238000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            select foo, bar from bindings.`h1445379926556884511_test_s3_inserts3binding`;\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\":\"18.82352941\",\"Format\":\"csv_with_names\",\"Name\":\"h1445379926556884511_test_s3_inserts3binding\",\"Inputs\":[],\"Path\":\"path1/ \",\"E-Rows\":\"0.5882352941\",\"ExternalDataSource\":\"h1445379926556884511_test_s3_insertbb\",\"ReadColumns\":[\"bar\",\"foo\"],\"SourceType\":\"s3\",\"E-Cost\":\"32\"}],\"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\"}}"
  }
  issue {
    position {
      row: 2
      column: 34
    }
    message: "Please remove \'bindings.\' from your query, the support for this syntax will be dropped soon"
    end_position {
      row: 2
      column: 34
    }
    issue_code: 4538
    severity: 2
  }
  statistics {
    json: "{\"ResultSet\":{\"Tasks\":{\"sum\":2,\"count\":2,\"avg\":1,\"max\":1,\"min\":1},\"CpuTimeUs\":{\"sum\":\"557us\",\"count\":2,\"avg\":\"278us\",\"max\":\"455us\",\"min\":\"102us\"},\"IngressBytes\":{\"sum\":32,\"count\":1,\"avg\":32,\"max\":32,\"min\":32},\"IngressRows\":{\"sum\":2,\"count\":1,\"avg\":2,\"max\":2,\"min\":2},\"InputBytes\":{\"sum\":17,\"count\":1,\"avg\":17,\"max\":17,\"min\":17},\"InputRows\":{\"sum\":2,\"count\":1,\"avg\":2,\"max\":2,\"min\":2},\"OutputBytes\":{\"sum\":34,\"count\":2,\"avg\":17,\"max\":17,\"min\":17},\"OutputRows\":{\"sum\":4,\"count\":2,\"avg\":2,\"max\":2,\"min\":2},\"ResultBytes\":{\"sum\":17,\"count\":1,\"avg\":17,\"max\":17,\"min\":17},\"ResultRows\":{\"sum\":2,\"count\":1,\"avg\":2,\"max\":2,\"min\":2},\"MaxMemoryUsage\":{\"sum\":211812352,\"count\":2,\"avg\":105906176,\"max\":210763776,\"min\":1048576}}}"
  }
  result_set_meta {
    column {
      name: "foo"
      type {
        type_id: INT32
      }
    }
    column {
      name: "bar"
      type {
        type_id: UTF8
      }
    }
    rows_count: 2
  }
  ast {
    data: "(\n(let $1 (DataSource \'\"s3\" \'\"/local/h1445379926556884511_test_s3_insertbb\" \'\"/local/h1445379926556884511_test_s3_inserts3binding\"))\n(let $2 \'\"Paths {\\n  Name: \\\"path1\\\"\\n  Children {\\n    Name: \\\"ptjudsej71qqdcq74d4r_0_rvZMaa6hMUGzdYOPDtlNtbyUxeobrfFg.csv\\\"\\n    Size: 32\\n    Read: true\\n  }\\n  IsDirectory: true\\n}\\n\")\n(let $3 (Bool \'\"true\"))\n(let $4 (StructType \'(\'\"bar\" (DataType \'Utf8)) \'(\'\"foo\" (DataType \'Int32))))\n(let $5 (S3ParseSettings world \'(\'((String $2) $3 (AsStruct))) (SecureParam \'\"cluster:default_/local/h1445379926556884511_test_s3_insertbb\") \'\"\" \'\"path1/ \" \'\"csv_with_names\" $4 (lambda \'($10) $3) \'()))\n(let $6 (DqPhyStage \'((DqSource $1 $5)) (lambda \'($11) (block \'(\n  (let $12 (DqSourceWideWrap $11 $1 $4 \'(\'(\'format \'\"csv_with_names\"))))\n  (return (FromFlow (NarrowMap $12 (lambda \'($13 $14) (AsStruct \'(\'\"bar\" $13) \'(\'\"foo\" $14))))))\n))) \'(\'(\'\"_logical_id\" \'397) \'(\'\"_id\" \'\"71aba73f-b2845875-a4bf0af4-21f77d57\"))))\n(let $7 (DqCnUnionAll (TDqOutput $6 \'\"0\")))\n(let $8 (DqPhyStage \'($7) (lambda \'($15) $15) \'(\'(\'\"_logical_id\" \'453) \'(\'\"_id\" \'\"6a68dbe5-cfe2659a-28ff6bd0-d983f7f8\"))))\n(let $9 (DqCnResult (TDqOutput $8 \'\"0\") \'(\'\"foo\" \'\"bar\")))\n(return (KqpPhysicalQuery \'((KqpPhysicalTx \'($6 $8) \'($9) \'() \'(\'(\'\"type\" \'\"generic\")))) \'((KqpTxResultBinding (ListType $4) \'\"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%, 2</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\'>2</text>\n</g>\n<g><title>Output 50%, 17B, Rows 50%, 2</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\'>17B</text>\n</g>\n<g><title>Output, Duration: 0.00 (0.01 | 0.01 | 0.01 - 0.01 | 0.01 | 0.01)</title><rect x=\'604\' 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%, 102us</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=\'40\' height=\'14\' stroke-width=\'0\' fill=\'var(--cpu-light, #B78C98)\'/>  <polygon points=\'413,61 433,61 453,61 453,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\'>102us</text>\n</g>\n<g><title>Input 100%, 17B, Rows 100%, 2, Width 8B</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\'>17B</text>\n</g>\n<g><title>Input, Duration: 0.00 (0.01 | 0.01 | 0.01 - 0.01 | 0.01 | 0.01)</title><rect x=\'604\' 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%, 2</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\'>2</text>\n</g>\n<g><title>Output Rows 33%, 2, Est: 32 Rows: 0 Size: 18B</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\'>2</text>\n</g>\n<g><title>Output 50%, 17B, Rows 50%, 2</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\'>17B</text>\n</g>\n<g><title>Output, Duration: 0.00 (0.01 | 0.01 | 0.01 - 0.01 | 0.01 | 0.01)</title><rect x=\'604\' 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%, 455us</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\'>455us</text>\n</g>\n<g><title>Ingress 100%, 32B, Rows 100%, 2, Width 16B</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\'>32B</text>\n</g>\n<g><title>Ingress, Duration: 0.00 (0.01 | 0.01 | 0.01 - 0.01 | 0.01 | 0.01)</title><rect x=\'604\' 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 32B, Rows 2, Width 16B, Avg 32B/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\'>32B</text>\n</g>\n<g><title>CPU Usage 557us, 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\'>557us</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 0.64</title>\n<polygon points=\'598,26 598,26 598,26 598,26 598,26 599,26 599,26 599,26 600,26 600,26 600,26 600,26 600,26 600,26 601,26 601,26 601,26 602,26 602,26 602,26 602,26 602,26 602,26 602,26 603,26 603,26 603,26 604,26 604,26 604,13 604,26 604,26 604,26 605,25 605,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 605,45 605,58 \' stroke-width=\'1\' stroke=\'var(--mem-medium, #7E4E5B)\' fill=\'var(--mem-medium, #7E4E5B)\' />\n</g>\n<g><title>Max CPU 0.08</title>\n<polygon points=\'598,74 598,74 598,74 598,74 598,74 599,74 599,74 599,74 600,74 600,74 600,74 600,74 600,74 600,74 601,74 601,74 601,74 602,74 602,74 602,74 602,74 602,74 602,74 602,74 603,74 603,74 603,74 604,74 604,74 604,74 604,74 604,74 604,61 605,74 605,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: h1445379926556884511_test_s3_inserts3binding(bar, foo)</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\'>h1445379926556884511_test_s3_inserts3binding(bar, foo)</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 604,114 604,127 \' stroke-width=\'1\' stroke=\'var(--mem-medium, #7E4E5B)\' fill=\'var(--mem-medium, #7E4E5B)\' />\n</g>\n<g><title>Max CPU 0.71</title>\n<polygon points=\'598,143 598,143 598,143 598,143 598,143 599,143 599,143 599,143 599,143 600,143 600,143 600,143 600,143 600,143 600,143 600,143 601,143 601,143 601,143 602,143 602,143 602,143 602,143 602,143 602,143 602,143 603,143 603,143 603,143 603,143 604,143 604,143 604,130 604,143 604,143 \' stroke-width=\'1\' stroke=\'var(--cpu-medium, #A36D7B)\' fill=\'var(--cpu-light, #B78C98)\' />\n</g>\n\n</svg>\n"
  }
}

2025-11-14 10:09:40,449 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-11-14 10:09:40,630 - INFO - ya.test - pytest_runtest_teardown: Test teardown
