2025-12-12 13:27:16,771 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 13:27:16,772 - INFO - ya.test - pytest_runtest_setup: test_double_optional_types_validation[v2-client0]
2025-12-12 13:27:16,772 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-12-12 13:27:16,772 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-12-12 13:27:17,775 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:14534/1
2025-12-12 13:27:17,777 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17219
2025-12-12 13:27:17,777 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/31743
2025-12-12 13:27:17,778 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/14534
2025-12-12 13:27:17,778 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/26646
2025-12-12 13:27:17,778 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/11053
2025-12-12 13:27:17,778 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/30715
2025-12-12 13:27:24,789 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:11340/1
2025-12-12 13:27:24,790 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/8372
2025-12-12 13:27:24,790 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/7337
2025-12-12 13:27:24,790 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/11340
2025-12-12 13:27:24,790 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/18227
2025-12-12 13:27:24,791 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17399
2025-12-12 13:27:24,886 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 13:27:24,886 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:24,896 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-12-12 13:27:24,896 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 2aa20e73-9c52-448d-933d-1172a810fb55, localhost:5090): creating call state
2025-12-12 13:27:24,897 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 2aa20e73-9c52-448d-933d-1172a810fb55, localhost:5090): request = { database: "local" }
2025-12-12 13:27:24,899 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 2aa20e73-9c52-448d-933d-1172a810fb55, localhost:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-qsiocfpt6q.auto.internal" port: 5090 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-12-12 13:27:24,899 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-qsiocfpt6q.auto.internal:5090, location 1, ssl: False>]>
2025-12-12 13:27:24,900 - INFO - ydb.connection - close: Closing channel for endpoint localhost:5090
2025-12-12 13:27:25,792 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:63931/1
2025-12-12 13:27:25,795 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/1965
2025-12-12 13:27:25,795 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/20259
2025-12-12 13:27:25,795 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/63931
2025-12-12 13:27:25,796 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/5030
2025-12-12 13:27:25,796 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/65377
2025-12-12 13:27:25,796 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/23528
2025-12-12 13:27:25,798 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4901
2025-12-12 13:27:25,799 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5642
2025-12-12 13:27:25,871 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:25,872 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/29582
2025-12-12 13:27:25,872 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/11601
2025-12-12 13:27:25,873 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28181
2025-12-12 13:27:25,874 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:25,876 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 13:27:25,877 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:25,884 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-12-12 13:27:25,884 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, cbfdbfe0-c0cd-4a8a-b0ed-55ea0642995b, localhost:5090): creating call state
2025-12-12 13:27:25,885 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, cbfdbfe0-c0cd-4a8a-b0ed-55ea0642995b, localhost:5090): request = { database: "local" }
2025-12-12 13:27:25,892 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, cbfdbfe0-c0cd-4a8a-b0ed-55ea0642995b, localhost:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-qsiocfpt6q.auto.internal" port: 5090 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-12-12 13:27:25,893 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-qsiocfpt6q.auto.internal:5090, location 1, ssl: False>]>
2025-12-12 13:27:25,893 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:25,897 - INFO - ydb.connection - close: Closing channel for endpoint localhost:5090
2025-12-12 13:27:25,903 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-12 13:27:25,903 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fb55ae9ea90 state=pending>
2025-12-12 13:27:25,904 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-12-12 13:27:25,904 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fb55ae9d4b0>
2025-12-12 13:27:25,904 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fb55ae9d4b0>
2025-12-12 13:27:25,904 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 7ae3d6e1-7f93-4d0e-878d-fea49f4f06a7, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:25,908 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 7ae3d6e1-7f93-4d0e-878d-fea49f4f06a7, ghrun-qsiocfpt6q.auto.internal:5090): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-12 13:27:25,911 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 7ae3d6e1-7f93-4d0e-878d-fea49f4f06a7, ghrun-qsiocfpt6q.auto.internal:5090): on response callback started
2025-12-12 13:27:25,912 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 7ae3d6e1-7f93-4d0e-878d-fea49f4f06a7, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=N2NmNmIxMWItNTMyN2Y5ODEtYjY3MDVhOGQtYWVkYzRmOTE=" } } } }
2025-12-12 13:27:25,912 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55ae9d4b0>
2025-12-12 13:27:25,913 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fb55ae9d4b0>
2025-12-12 13:27:25,914 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, aca4064d-dc33-469f-a292-696f8e5a2b55, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:25,914 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 7ae3d6e1-7f93-4d0e-878d-fea49f4f06a7, ghrun-qsiocfpt6q.auto.internal:5090): on response callback success
2025-12-12 13:27:25,915 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, aca4064d-dc33-469f-a292-696f8e5a2b55, ghrun-qsiocfpt6q.auto.internal:5090): request = { session_id: "ydb://session/3?node_id=1&id=N2NmNmIxMWItNTMyN2Y5ODEtYjY3MDVhOGQtYWVkYzRmOTE=" path: "local/DbPoolStorage_35b84f5c-68e1-42b9-8dcb-d351289c4fbc/tenants" columns { name: "tenant" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } columns { name: "common" type { optional_type { item { type_id: BOOL } } } } columns { name: "state" type { optional_type { item { type_id: UINT32 } } } } columns { name: "state_time" type { optional_type { item { type_id: TIMESTAMP } } } } primary_key: "tenant" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:27:25,955 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, aca4064d-dc33-469f-a292-696f8e5a2b55, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:27:25,956 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55ae9d4b0>
2025-12-12 13:27:25,957 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 64775cb2-9b43-41b7-8680-aef8af34e287, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:25,957 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 64775cb2-9b43-41b7-8680-aef8af34e287, ghrun-qsiocfpt6q.auto.internal:5090): request = { session_id: "ydb://session/3?node_id=1&id=N2NmNmIxMWItNTMyN2Y5ODEtYjY3MDVhOGQtYWVkYzRmOTE=" path: "local/DbPoolStorage_35b84f5c-68e1-42b9-8dcb-d351289c4fbc/mappings" columns { name: "subject_type" type { optional_type { item { type_id: STRING } } } } columns { name: "subject_id" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } primary_key: "subject_type" primary_key: "subject_id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:27:25,991 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 64775cb2-9b43-41b7-8680-aef8af34e287, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:27:25,992 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55ae9d4b0>
2025-12-12 13:27:25,998 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 0c0e6a64-e1c1-4b23-88d5-ea8dddda3918, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:25,998 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 0c0e6a64-e1c1-4b23-88d5-ea8dddda3918, ghrun-qsiocfpt6q.auto.internal:5090): request = { session_id: "ydb://session/3?node_id=1&id=N2NmNmIxMWItNTMyN2Y5ODEtYjY3MDVhOGQtYWVkYzRmOTE=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "--!syntax_v1\n            PRAGMA TablePathPrefix(\"local/DbPoolStorage_35b84f5c-68e1-42b9-8dcb-d351289c4fbc\");\n            UPSERT INTO tenants (tenant, vtenant, common, state, state_time) values(\"/default\", \"/default\", true, 0, CurrentUtcTimestamp());\n                " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:27:26,014 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 0c0e6a64-e1c1-4b23-88d5-ea8dddda3918, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-12-12 13:27:26,015 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55ae9d4b0>
2025-12-12 13:27:26,075 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:26,077 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4960
2025-12-12 13:27:26,077 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4961
2025-12-12 13:27:26,078 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/64924
2025-12-12 13:27:26,079 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/default/kikimr_configs"
2025-12-12 13:27:26,079 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --tenant=/default --node-kind=yq --log-file-name=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/default/node_1/logfile_lr2ht7cm.log --grpc-port=28181 --mon-port=4961 --ic-port=29582
2025-12-12 13:27:26,081 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/default/kikimr_configs/config.yaml', '--node=1', '--tenant=/default', '--node-kind=yq', '--log-file-name=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/default/node_1/logfile_lr2ht7cm.log', '--grpc-port=28181', '--mon-port=4961', '--ic-port=29582')' in '/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/default/node_1' (no wait)
2025-12-12 13:27:26,083 - DEBUG - ya.test - execute: Command pid: 2853310
2025-12-12 13:27:26,083 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:28181/1
2025-12-12 13:27:26,084 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-12-12 13:27:26,090 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/24457
2025-12-12 13:27:26,092 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/5832
2025-12-12 13:27:26,159 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:26,159 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/12474
2025-12-12 13:27:26,160 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/28998
2025-12-12 13:27:26,238 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:26,239 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/16285
2025-12-12 13:27:26,240 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/16285
2025-12-12 13:27:26,240 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/16286
2025-12-12 13:27:26,240 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/64919
2025-12-12 13:27:26,241 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/64920
2025-12-12 13:27:26,241 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/4911
2025-12-12 13:27:26,242 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:26,246 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 13:27:26,247 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:26,252 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-12-12 13:27:26,253 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 99bce22e-1e4d-4ccb-875e-d9686098a2f4, localhost:5090): creating call state
2025-12-12 13:27:26,254 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 99bce22e-1e4d-4ccb-875e-d9686098a2f4, localhost:5090): request = { database: "local" }
2025-12-12 13:27:26,256 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 99bce22e-1e4d-4ccb-875e-d9686098a2f4, localhost:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-qsiocfpt6q.auto.internal" port: 5090 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-12-12 13:27:26,257 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-qsiocfpt6q.auto.internal:5090, location 1, ssl: False>]>
2025-12-12 13:27:26,257 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:26,261 - INFO - ydb.connection - close: Closing channel for endpoint localhost:5090
2025-12-12 13:27:26,262 - DEBUG - ydb.table.SessionPool - subscribe: Active session queue is empty, subscribe waiter for a session
2025-12-12 13:27:26,262 - DEBUG - ydb.table.SessionPool - subscribe: Subscribe waiter <Future at 0x7fb55a825550 state=pending>
2025-12-12 13:27:26,263 - DEBUG - ydb.table.SessionPool - subscribe: Session pool is not large enough (active_count < size: 0 < 1). will create a new session.
2025-12-12 13:27:26,263 - DEBUG - ydb.table.SessionPool - _create: Created session <ydb.table.Session object at 0x7fb55a8271c0>
2025-12-12 13:27:26,263 - DEBUG - ydb.table.SessionPool - _prepare: Preparing session <ydb.table.Session object at 0x7fb55a8271c0>
2025-12-12 13:27:26,263 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 9debebc9-5f89-4bb5-8df1-9c3acb10a752, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:26,264 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 9debebc9-5f89-4bb5-8df1-9c3acb10a752, ghrun-qsiocfpt6q.auto.internal:5090): request = { operation_params { operation_timeout { seconds: 3 } cancel_after { seconds: 3 } } }
2025-12-12 13:27:26,266 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 9debebc9-5f89-4bb5-8df1-9c3acb10a752, ghrun-qsiocfpt6q.auto.internal:5090): on response callback started
2025-12-12 13:27:26,267 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 9debebc9-5f89-4bb5-8df1-9c3acb10a752, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=1&id=ODQ3YTJhMGYtYjMxNGQyNDYtZGM0YTI0ZDYtOGY2YWM4YzI=" } } } }
2025-12-12 13:27:26,267 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55a8271c0>
2025-12-12 13:27:26,268 - DEBUG - ydb.table.SessionPool - put: Replying to waiter with a session <ydb.table.Session object at 0x7fb55a8271c0>
2025-12-12 13:27:26,268 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 1b1d2733-88d5-4f96-87d5-61018626aa7c, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:26,269 - DEBUG - ydb.connection - _on_response_callback: RpcState(CreateSession, 9debebc9-5f89-4bb5-8df1-9c3acb10a752, ghrun-qsiocfpt6q.auto.internal:5090): on response callback success
2025-12-12 13:27:26,270 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 1b1d2733-88d5-4f96-87d5-61018626aa7c, ghrun-qsiocfpt6q.auto.internal:5090): request = { session_id: "ydb://session/3?node_id=1&id=ODQ3YTJhMGYtYjMxNGQyNDYtZGM0YTI0ZDYtOGY2YWM4YzI=" path: "local/DbPoolStorage_7d254db5-3f06-4dd1-b4b1-cb001250f01f/tenants" columns { name: "tenant" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } columns { name: "common" type { optional_type { item { type_id: BOOL } } } } columns { name: "state" type { optional_type { item { type_id: UINT32 } } } } columns { name: "state_time" type { optional_type { item { type_id: TIMESTAMP } } } } primary_key: "tenant" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:27:26,287 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 1b1d2733-88d5-4f96-87d5-61018626aa7c, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:27:26,287 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55a8271c0>
2025-12-12 13:27:26,288 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateTable, 97732d2b-4587-4c48-929b-23262720ce41, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:26,289 - DEBUG - ydb.connection - _log_request: RpcState(CreateTable, 97732d2b-4587-4c48-929b-23262720ce41, ghrun-qsiocfpt6q.auto.internal:5090): request = { session_id: "ydb://session/3?node_id=1&id=ODQ3YTJhMGYtYjMxNGQyNDYtZGM0YTI0ZDYtOGY2YWM4YzI=" path: "local/DbPoolStorage_7d254db5-3f06-4dd1-b4b1-cb001250f01f/mappings" columns { name: "subject_type" type { optional_type { item { type_id: STRING } } } } columns { name: "subject_id" type { optional_type { item { type_id: STRING } } } } columns { name: "vtenant" type { optional_type { item { type_id: STRING } } } } primary_key: "subject_type" primary_key: "subject_id" operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:27:26,304 - DEBUG - ydb.connection - _log_response: RpcState(CreateTable, 97732d2b-4587-4c48-929b-23262720ce41, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS } }
2025-12-12 13:27:26,305 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55a8271c0>
2025-12-12 13:27:26,306 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, aef66e73-f571-45e3-a561-89e3d20cf4e7, ghrun-qsiocfpt6q.auto.internal:5090): creating call state
2025-12-12 13:27:26,307 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, aef66e73-f571-45e3-a561-89e3d20cf4e7, ghrun-qsiocfpt6q.auto.internal:5090): request = { session_id: "ydb://session/3?node_id=1&id=ODQ3YTJhMGYtYjMxNGQyNDYtZGM0YTI0ZDYtOGY2YWM4YzI=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "--!syntax_v1\n            PRAGMA TablePathPrefix(\"local/DbPoolStorage_7d254db5-3f06-4dd1-b4b1-cb001250f01f\");\n            UPSERT INTO tenants (tenant, vtenant, common, state, state_time) values(\"/cp\", \"/cp\", true, 0, CurrentUtcTimestamp());\n                UPSERT INTO tenants (tenant, vtenant, common, state, state_time) values(\"/compute\", \"/compute\", true, 0, CurrentUtcTimestamp());\n                " } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-12-12 13:27:26,329 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, aef66e73-f571-45e3-a561-89e3d20cf4e7, ghrun-qsiocfpt6q.auto.internal:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-12-12 13:27:26,330 - DEBUG - ydb.table.SessionPool - put: Put on session <ydb.table.Session object at 0x7fb55a8271c0>
2025-12-12 13:27:26,330 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/19892
2025-12-12 13:27:26,388 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:26,390 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/22069
2025-12-12 13:27:26,391 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/63217
2025-12-12 13:27:26,397 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/cp/kikimr_configs"
2025-12-12 13:27:26,397 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --tenant=/cp --node-kind=yq --log-file-name=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/cp/node_1/logfile_fxde2lvm.log --grpc-port=4911 --mon-port=22069 --ic-port=12474
2025-12-12 13:27:26,399 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/cp/kikimr_configs/config.yaml', '--node=1', '--tenant=/cp', '--node-kind=yq', '--log-file-name=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/cp/node_1/logfile_fxde2lvm.log', '--grpc-port=4911', '--mon-port=22069', '--ic-port=12474')' in '/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/cp/node_1' (no wait)
2025-12-12 13:27:26,401 - DEBUG - ya.test - execute: Command pid: 2853562
2025-12-12 13:27:26,401 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:4911/1
2025-12-12 13:27:26,402 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-12-12 13:27:26,462 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:26,463 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/12254
2025-12-12 13:27:26,464 - DEBUG - library.python.filelock - acquire: Acquiring FileLock (blocking=False): /home/runner/.ya/build/port_sync_dir/1194
2025-12-12 13:27:26,465 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/compute/kikimr_configs"
2025-12-12 13:27:26,465 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node=1 --log-file-name=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/compute/node_1/logfile_kmsbf_g1.log --grpc-port=19892 --mon-port=12254 --ic-port=16286
2025-12-12 13:27:26,466 - DEBUG - ya.test - execute: Executing '('/home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd', 'server', '--suppress-version-check', '--yaml-config=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/compute/kikimr_configs/config.yaml', '--node=1', '--log-file-name=/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/compute/node_1/logfile_kmsbf_g1.log', '--grpc-port=19892', '--mon-port=12254', '--ic-port=16286')' in '/home/runner/.ya/build/build_root/rvnw/00340b/ydb/tests/fq/s3/test-results/py3test/testing_out_stuff/test_s3_0/testing_out_stuff/test_s3_0.py.TestS3.test_double_optional_types_validation.v2-client0/compute/node_1' (no wait)
2025-12-12 13:27:26,468 - DEBUG - ya.test - execute: Command pid: 2853672
2025-12-12 13:27:26,469 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:19892/1
2025-12-12 13:27:28,421 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:28,423 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.11
2025-12-12 13:27:28,423 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.11
2025-12-12 13:27:28,423 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:19892', '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: 16286\n      }\n      HostConfigId: 1\n    }\n  }\n}\n']' in 'None' (waiting)
2025-12-12 13:27:28,424 - DEBUG - ya.test - execute: Command pid: 2856312
2025-12-12 13:27:28,815 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) rc: 0
2025-12-12 13:27:28,816 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) elapsed time (sec): 0.38960957527160645
2025-12-12 13:27:28,816 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) idrss: 0
2025-12-12 13:27:28,816 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) inblock: 0
2025-12-12 13:27:28,817 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) isrss: 0
2025-12-12 13:27:28,817 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) ixrss: 0
2025-12-12 13:27:28,817 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) majflt: 0
2025-12-12 13:27:28,818 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) maxrss: 529060
2025-12-12 13:27:28,818 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) minflt: 19772
2025-12-12 13:27:28,818 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) msgrcv: 0
2025-12-12 13:27:28,818 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) msgsnd: 0
2025-12-12 13:27:28,818 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) nivcsw: 32
2025-12-12 13:27:28,819 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) nsignals: 0
2025-12-12 13:27:28,819 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) nswap: 0
2025-12-12 13:27:28,819 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) nvcsw: 103
2025-12-12 13:27:28,819 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) oublock: 8
2025-12-12 13:27:28,819 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) stime: 0.250402
2025-12-12 13:27:28,819 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) utime: 0.079995
2025-12-12 13:27:28,820 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) wtime: 0.391
2025-12-12 13:27:28,820 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) output:
Status {
  Success: true
}
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 5

2025-12-12 13:27:28,820 - DEBUG - ya.test - _save_outputs: Command (pid 2856312) errors:

2025-12-12 13:27:28,821 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:28,822 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.12
2025-12-12 13:27:28,823 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.12
2025-12-12 13:27:28,823 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:19892', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 1\n    Name: "dynamic_storage_pool:1"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "hdd"\n    NumGroups: 2\n    PDiskFilter {\n      Property {\n        Type: ROT\n      }\n      Property {\n        Kind: 0\n      }\n    }\n  }\n}\n']' in 'None' (waiting)
2025-12-12 13:27:28,824 - DEBUG - ya.test - execute: Command pid: 2856763
2025-12-12 13:27:29,228 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) rc: 0
2025-12-12 13:27:29,229 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) elapsed time (sec): 0.40367865562438965
2025-12-12 13:27:29,229 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) idrss: 0
2025-12-12 13:27:29,229 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) inblock: 0
2025-12-12 13:27:29,229 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) isrss: 0
2025-12-12 13:27:29,229 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) ixrss: 0
2025-12-12 13:27:29,230 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) majflt: 0
2025-12-12 13:27:29,230 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) maxrss: 529320
2025-12-12 13:27:29,230 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) minflt: 19769
2025-12-12 13:27:29,230 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) msgrcv: 0
2025-12-12 13:27:29,230 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) msgsnd: 0
2025-12-12 13:27:29,230 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) nivcsw: 23
2025-12-12 13:27:29,230 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) nsignals: 0
2025-12-12 13:27:29,231 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) nswap: 0
2025-12-12 13:27:29,231 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) nvcsw: 136
2025-12-12 13:27:29,231 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) oublock: 8
2025-12-12 13:27:29,231 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) stime: 0.27419499999999997
2025-12-12 13:27:29,231 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) utime: 0.08467799999999999
2025-12-12 13:27:29,232 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) wtime: 0.405
2025-12-12 13:27:29,232 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 6

2025-12-12 13:27:29,232 - DEBUG - ya.test - _save_outputs: Command (pid 2856763) errors:

2025-12-12 13:27:29,233 - DEBUG - ya.test - get_binary: Binary was found by /home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd
2025-12-12 13:27:29,234 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.13
2025-12-12 13:27:29,234 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.13
2025-12-12 13:27:29,235 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/rvnw/00340b/ydb/apps/ydbd/ydbd', '--server=grpc://localhost:19892', 'admin', 'blobstorage', 'config', 'invoke', '--proto=Command {\n  DefineStoragePool {\n    BoxId: 1\n    StoragePoolId: 2\n    Name: "dynamic_storage_pool:2"\n    ErasureSpecies: "none"\n    VDiskKind: "Default"\n    Kind: "ssd"\n    NumGroups: 2\n    PDiskFilter {\n      Property {\n        Type: ROT\n      }\n      Property {\n        Kind: 0\n      }\n    }\n  }\n}\n']' in 'None' (waiting)
2025-12-12 13:27:29,236 - DEBUG - ya.test - execute: Command pid: 2857374
2025-12-12 13:27:29,609 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) rc: 0
2025-12-12 13:27:29,609 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) elapsed time (sec): 0.3725605010986328
2025-12-12 13:27:29,609 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) idrss: 0
2025-12-12 13:27:29,609 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) inblock: 0
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) isrss: 0
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) ixrss: 0
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) majflt: 0
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) maxrss: 529064
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) minflt: 19769
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) msgrcv: 0
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) msgsnd: 0
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) nivcsw: 43
2025-12-12 13:27:29,610 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) nsignals: 0
2025-12-12 13:27:29,611 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) nswap: 0
2025-12-12 13:27:29,611 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) nvcsw: 122
2025-12-12 13:27:29,611 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) oublock: 8
2025-12-12 13:27:29,611 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) stime: 0.205946
2025-12-12 13:27:29,611 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) utime: 0.116464
2025-12-12 13:27:29,611 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) wtime: 0.374
2025-12-12 13:27:29,612 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) output:
Status {
  Success: true
}
Success: true
ConfigTxSeqNo: 7

2025-12-12 13:27:29,612 - DEBUG - ya.test - _save_outputs: Command (pid 2857374) errors:

2025-12-12 13:27:29,612 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Binding storage pools to domain local: {'dynamic_storage_pool:1': 'hdd', 'dynamic_storage_pool:2': 'ssd'}
2025-12-12 13:27:29,624 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-12-12 13:27:29,624 - DEBUG - ydb.connection - channel_factory: Channel options: [('grpc.max_receive_message_length', 64000000), ('grpc.max_send_message_length', 64000000), ('grpc.primary_user_agent', 'python-library'), ('grpc.lb_policy_name', 'round_robin')]
2025-12-12 13:27:29,639 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database local
2025-12-12 13:27:29,640 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 574b9782-6410-40dc-8569-9e0189e305f8, localhost:5090): creating call state
2025-12-12 13:27:29,640 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 574b9782-6410-40dc-8569-9e0189e305f8, localhost:5090): request = { database: "local" }
2025-12-12 13:27:29,643 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 574b9782-6410-40dc-8569-9e0189e305f8, localhost:5090): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-qsiocfpt6q.auto.internal" port: 5090 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" location: "1" node_id: 1 } self_location: "1" } } } }
2025-12-12 13:27:29,644 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database local: DiscoveryResult <self_location: 1, endpoints [<Endpoint ghrun-qsiocfpt6q.auto.internal:5090, location 1, ssl: False>]>
2025-12-12 13:27:29,644 - INFO - ydb.connection - close: Closing channel for endpoint localhost:5090
2025-12-12 13:27:29,649 - INFO - ydb.tests.library.harness.kikimr_runner - __run: Cluster started and initialized
2025-12-12 13:27:29,660 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-12-12 13:27:29,689 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-12-12 13:27:29,716 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-12-12 13:27:29,759 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-12-12 13:27:29,811 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_s3_0.py::TestS3, test_name: test_double_optional_types_validation[v2-client0])
2025-12-12 13:27:29,813 - DEBUG - botocore.hooks - _emit: Event choose-service-name: calling handler <function handle_service_name_alias at 0x7fb55be38ad0>
2025-12-12 13:27:29,815 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_post at 0x7fb55bf487d0>
2025-12-12 13:27:29,815 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function lazy_call.<locals>._handler at 0x7fb55b37aa50>
2025-12-12 13:27:29,816 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_url at 0x7fb55bf484d0>
2025-12-12 13:27:29,820 - DEBUG - botocore.endpoint - create_endpoint: Setting s3 timeout as (60, 60)
2025-12-12 13:27:29,824 - DEBUG - botocore.client - _register_legacy_retries: Registering retry handlers for service: s3
2025-12-12 13:27:29,825 - DEBUG - botocore.utils - register: Registering S3 region redirector handler
2025-12-12 13:27:29,826 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:s3
2025-12-12 13:27:29,828 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:Bucket
2025-12-12 13:27:29,829 - DEBUG - boto3.resources.model - _load_name_with_category: Renaming Bucket attribute name
2025-12-12 13:27:29,831 - DEBUG - botocore.hooks - _emit: Event creating-resource-class.s3.Bucket: calling handler <function lazy_call.<locals>._handler at 0x7fb55b37b4d0>
2025-12-12 13:27:29,831 - DEBUG - boto3.resources.action - __call__: Calling s3:create_bucket with {'Bucket': 'fbucket', 'ACL': 'public-read'}
2025-12-12 13:27:29,832 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function validate_bucket_name at 0x7fb55be3a990>
2025-12-12 13:27:29,832 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fb55be61250>
2025-12-12 13:27:29,833 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,833 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.CreateBucket: calling handler <function generate_idempotent_uuid at 0x7fb55be3a750>
2025-12-12 13:27:29,833 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fb55be61490>
2025-12-12 13:27:29,833 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,834 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:9555', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableAccessPoints': True, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:27:29,837 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:9555/fbucket
2025-12-12 13:27:29,838 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:27:29,838 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:27:29,839 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function add_expect_header at 0x7fb55be3ae10>
2025-12-12 13:27:29,840 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function add_recursion_detection_header at 0x7fb55be38d10>
2025-12-12 13:27:29,840 - DEBUG - botocore.hooks - _emit: Event before-call.s3.CreateBucket: calling handler <function inject_api_version_header_if_needed at 0x7fb55be60890>
2025-12-12 13:27:29,842 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=CreateBucket) with params: {'url_path': '', 'query_string': {}, 'method': 'PUT', 'headers': {'x-amz-acl': 'public-read', 'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource'}, 'body': b'', 'auth_path': '/fbucket/', 'url': 'http://localhost:9555/fbucket', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fb541d1e310>, 'has_streaming_input': False, 'auth_type': 'v4', 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Bucket': 'fbucket', 'ACL': 'public-read'}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-12-12 13:27:29,843 - DEBUG - botocore.hooks - _emit: Event request-created.s3.CreateBucket: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fb541d1eae0>>
2025-12-12 13:27:29,844 - 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 0x7fb53ec16900>>
2025-12-12 13:27:29,844 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.CreateBucket: calling handler <function set_operation_specific_signer at 0x7fb55be3a5d0>
2025-12-12 13:27:29,844 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.CreateBucket: calling handler <function remove_arn_from_signing_path at 0x7fb55be613d0>
2025-12-12 13:27:29,845 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:27:29,845 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
PUT
/fbucket

host:localhost:9555
x-amz-acl:public-read
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20251212T132729Z

host;x-amz-acl;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2025-12-12 13:27:29,845 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132729Z
20251212/yandex/s3/aws4_request
f5e2dc9295759e20630a3147377b1f3eb060bfab0a314c6d59ae51c75b35a0a7
2025-12-12 13:27:29,846 - DEBUG - botocore.auth - add_auth: Signature:
c9e6a5c43b8903f06aabf5f6ff06498fe2174324f8765b17979f4dfc509180c7
2025-12-12 13:27:29,846 - DEBUG - botocore.hooks - _emit: Event request-created.s3.CreateBucket: calling handler <function add_retry_headers at 0x7fb55be61190>
2025-12-12 13:27:29,846 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=PUT, url=http://localhost:9555/fbucket, headers={'x-amz-acl': b'public-read', 'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'X-Amz-Date': b'20251212T132729Z', 'X-Amz-Content-SHA256': b'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=host;x-amz-acl;x-amz-content-sha256;x-amz-date, Signature=c9e6a5c43b8903f06aabf5f6ff06498fe2174324f8765b17979f4dfc509180c7', 'amz-sdk-invocation-id': b'e8e24cec-5404-4bda-8aa7-a4661aa828e8', 'amz-sdk-request': b'attempt=1', 'Content-Length': '0'}>
2025-12-12 13:27:29,862 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:27:29 GMT', 'x-amzn-requestid': 'w3qDhIk65Al3Zd89nkb5Y2R3ZfSPqWvcCLjlhCzari6h4lInkbYf', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '161', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:27:29,862 - DEBUG - botocore.parsers - parse: Response body:
b'<CreateBucketResponse xmlns="http://s3.amazonaws.com/doc/2006-03-01"><CreateBucketResponse><Bucket>fbucket</Bucket></CreateBucketResponse></CreateBucketResponse>'
2025-12-12 13:27:29,863 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.CreateBucket: calling handler <botocore.retryhandler.RetryHandler object at 0x7fb53f175460>
2025-12-12 13:27:29,864 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:27:29,864 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.CreateBucket: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,864 - DEBUG - boto3.resources.action - __call__: Response: {'ResponseMetadata': {'RequestId': 'w3qDhIk65Al3Zd89nkb5Y2R3ZfSPqWvcCLjlhCzari6h4lInkbYf', 'HTTPStatusCode': 200, 'HTTPHeaders': {'server': 'Werkzeug/2.2.3 Python/3.12.9', 'date': 'Fri, 12 Dec 2025 13:27:29 GMT', 'x-amzn-requestid': 'w3qDhIk65Al3Zd89nkb5Y2R3ZfSPqWvcCLjlhCzari6h4lInkbYf', 'content-type': 'text/html; charset=utf-8', 'content-length': '161', 'access-control-allow-origin': '*', 'connection': 'close'}, 'RetryAttempts': 0}}
2025-12-12 13:27:29,865 - DEBUG - boto3.resources.collection - pages: Calling paginated s3:list_objects with {'Bucket': 'fbucket'}
2025-12-12 13:27:29,866 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function set_list_objects_encoding_type_url at 0x7fb55be60290>
2025-12-12 13:27:29,866 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function validate_bucket_name at 0x7fb55be3a990>
2025-12-12 13:27:29,866 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fb55be61250>
2025-12-12 13:27:29,867 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,867 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.ListObjects: calling handler <function generate_idempotent_uuid at 0x7fb55be3a750>
2025-12-12 13:27:29,867 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fb55be61490>
2025-12-12 13:27:29,868 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,868 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:9555', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:27:29,869 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:9555/fbucket
2025-12-12 13:27:29,870 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:27:29,870 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:27:29,871 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function add_expect_header at 0x7fb55be3ae10>
2025-12-12 13:27:29,871 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function add_recursion_detection_header at 0x7fb55be38d10>
2025-12-12 13:27:29,871 - DEBUG - botocore.hooks - _emit: Event before-call.s3.ListObjects: calling handler <function inject_api_version_header_if_needed at 0x7fb55be60890>
2025-12-12 13:27:29,871 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=ListObjects) with params: {'url_path': '', 'query_string': {'encoding-type': 'url'}, 'method': 'GET', 'headers': {'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource'}, 'body': b'', 'auth_path': '/fbucket/', 'url': 'http://localhost:9555/fbucket?encoding-type=url', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fb541d1e310>, 'has_streaming_input': False, 'auth_type': 'v4', 'encoding_type_auto_set': True, 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Bucket': 'fbucket', 'EncodingType': 'url'}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-12-12 13:27:29,873 - DEBUG - botocore.hooks - _emit: Event request-created.s3.ListObjects: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fb541d1eae0>>
2025-12-12 13:27:29,874 - 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 0x7fb53ec16900>>
2025-12-12 13:27:29,875 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.ListObjects: calling handler <function set_operation_specific_signer at 0x7fb55be3a5d0>
2025-12-12 13:27:29,875 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.ListObjects: calling handler <function remove_arn_from_signing_path at 0x7fb55be613d0>
2025-12-12 13:27:29,876 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:27:29,876 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
GET
/fbucket
encoding-type=url
host:localhost:9555
x-amz-content-sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
x-amz-date:20251212T132729Z

host;x-amz-content-sha256;x-amz-date
e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855
2025-12-12 13:27:29,876 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132729Z
20251212/yandex/s3/aws4_request
79935cf61a92b70fd270465b1c005c08be9a91ce8e5dbd8df4350f71dcb81c49
2025-12-12 13:27:29,876 - DEBUG - botocore.auth - add_auth: Signature:
7ba07352277500eea107c73b08da61703f429216fb0c7c9429a600b512e17a2d
2025-12-12 13:27:29,877 - DEBUG - botocore.hooks - _emit: Event request-created.s3.ListObjects: calling handler <function add_retry_headers at 0x7fb55be61190>
2025-12-12 13:27:29,877 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=GET, url=http://localhost:9555/fbucket?encoding-type=url, headers={'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'X-Amz-Date': b'20251212T132729Z', 'X-Amz-Content-SHA256': b'e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=7ba07352277500eea107c73b08da61703f429216fb0c7c9429a600b512e17a2d', 'amz-sdk-invocation-id': b'9de59015-1662-4a9a-8aa2-7f611a0222bc', 'amz-sdk-request': b'attempt=1'}>
2025-12-12 13:27:29,885 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:27:29 GMT', 'x-amzn-requestid': 'dXosuvW4mUwnbDKhqcwAEKRso9rOy1sSodjvT4E1sNFUEqsFRPEc', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '554', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:27:29,885 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?><ListBucketResult xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Name>fbucket</Name><MaxKeys>1000</MaxKeys><EncodingType>url</EncodingType><IsTruncated>false</IsTruncated><Contents><Key>fruits.csv</Key><LastModified>2025-12-12T13:25:35.000Z</LastModified><ETag>&#34;e39a9ea5256659abbca6b8b24c67876e&#34;</ETag><Size>47</Size><StorageClass>STANDARD</StorageClass><Owner><ID>75aa57f09aa0c8caeab4f8c24e99d10f8e7faeebf76c078efc7c6caea54ba06a</ID><DisplayName>webfile</DisplayName></Owner></Contents></ListBucketResult>'
2025-12-12 13:27:29,896 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.ListObjects: calling handler <botocore.retryhandler.RetryHandler object at 0x7fb53f175460>
2025-12-12 13:27:29,897 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:27:29,897 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.ListObjects: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,897 - DEBUG - botocore.hooks - _emit: Event after-call.s3.ListObjects: calling handler <function decode_list_object at 0x7fb55be60350>
2025-12-12 13:27:29,898 - DEBUG - boto3.resources.factory - load_from_definition: Loading s3:ObjectSummary
2025-12-12 13:27:29,898 - DEBUG - boto3.resources.model - _load_name_with_category: Renaming ObjectSummary attribute key
2025-12-12 13:27:29,900 - DEBUG - botocore.hooks - _emit: Event creating-resource-class.s3.ObjectSummary: calling handler <function lazy_call.<locals>._handler at 0x7fb55b37b650>
2025-12-12 13:27:29,900 - DEBUG - boto3.resources.action - __call__: Calling s3:delete_objects with {'Bucket': 'fbucket', 'Delete': {'Objects': [{'Key': 'fruits.csv'}]}}
2025-12-12 13:27:29,901 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <function validate_bucket_name at 0x7fb55be3a990>
2025-12-12 13:27:29,901 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fb55be61250>
2025-12-12 13:27:29,902 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,902 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.DeleteObjects: calling handler <function generate_idempotent_uuid at 0x7fb55be3a750>
2025-12-12 13:27:29,902 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fb55be61490>
2025-12-12 13:27:29,902 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,903 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:9555', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:27:29,911 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:9555/fbucket
2025-12-12 13:27:29,912 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:27:29,912 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:27:29,914 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function escape_xml_payload at 0x7fb55be3a390>
2025-12-12 13:27:29,914 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function add_expect_header at 0x7fb55be3ae10>
2025-12-12 13:27:29,914 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function add_recursion_detection_header at 0x7fb55be38d10>
2025-12-12 13:27:29,914 - DEBUG - botocore.hooks - _emit: Event before-call.s3.DeleteObjects: calling handler <function inject_api_version_header_if_needed at 0x7fb55be60890>
2025-12-12 13:27:29,915 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=DeleteObjects) with params: {'url_path': '?delete', 'query_string': {}, 'method': 'POST', 'headers': {'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'Content-MD5': 'qhYwzsEvymlDQ0qxfrex2g=='}, 'body': b'<Delete xmlns="http://s3.amazonaws.com/doc/2006-03-01/"><Object><Key>fruits.csv</Key></Object></Delete>', 'auth_path': '/fbucket/', 'url': 'http://localhost:9555/fbucket?delete', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fb541d1e310>, 'has_streaming_input': False, 'auth_type': 'v4', 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Bucket': 'fbucket', 'Delete': {'Objects': [{'Key': 'fruits.csv'}]}}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}, 'checksum': {'request_algorithm': 'conditional-md5'}}}
2025-12-12 13:27:29,920 - DEBUG - botocore.hooks - _emit: Event request-created.s3.DeleteObjects: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fb541d1eae0>>
2025-12-12 13:27:29,921 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.DeleteObjects: calling handler <bound method ClientCreator._default_s3_presign_to_sigv2 of <botocore.client.ClientCreator object at 0x7fb53ec16900>>
2025-12-12 13:27:29,921 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.DeleteObjects: calling handler <function set_operation_specific_signer at 0x7fb55be3a5d0>
2025-12-12 13:27:29,921 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.DeleteObjects: calling handler <function remove_arn_from_signing_path at 0x7fb55be613d0>
2025-12-12 13:27:29,922 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:27:29,922 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
POST
/fbucket
delete=
content-md5:qhYwzsEvymlDQ0qxfrex2g==
host:localhost:9555
x-amz-content-sha256:c1e075aa57263477fc032bb83fe20baad49e1b1d446bac947bae3aca35a1d621
x-amz-date:20251212T132729Z

content-md5;host;x-amz-content-sha256;x-amz-date
c1e075aa57263477fc032bb83fe20baad49e1b1d446bac947bae3aca35a1d621
2025-12-12 13:27:29,923 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132729Z
20251212/yandex/s3/aws4_request
582755199f7acf55b496065944bec0273fd9168b3554bc10d3ba81c22457eaf3
2025-12-12 13:27:29,927 - DEBUG - botocore.auth - add_auth: Signature:
8d396b65271360904769767e7efb2b5d2fe68efcc6ca869b9cfd6aaba0273113
2025-12-12 13:27:29,928 - DEBUG - botocore.hooks - _emit: Event request-created.s3.DeleteObjects: calling handler <function add_retry_headers at 0x7fb55be61190>
2025-12-12 13:27:29,928 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=POST, url=http://localhost:9555/fbucket?delete, headers={'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80 Resource', 'Content-MD5': b'qhYwzsEvymlDQ0qxfrex2g==', 'X-Amz-Date': b'20251212T132729Z', 'X-Amz-Content-SHA256': b'c1e075aa57263477fc032bb83fe20baad49e1b1d446bac947bae3aca35a1d621', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=content-md5;host;x-amz-content-sha256;x-amz-date, Signature=8d396b65271360904769767e7efb2b5d2fe68efcc6ca869b9cfd6aaba0273113', 'amz-sdk-invocation-id': b'c22569b4-ac71-45e8-99ed-c76019398471', 'amz-sdk-request': b'attempt=1', 'Content-Length': '103'}>
2025-12-12 13:27:29,936 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:27:29 GMT', 'x-amzn-requestid': 'R5WMLe29qITAFfuPso2285x1F9AmGr3e3eeucTBSxjq6PuzOQIRT', 'Content-Type': 'text/html; charset=utf-8', 'Content-Length': '154', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:27:29,936 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?><DeleteResult xmlns="http://s3.amazonaws.com/doc/2006-03-01"><Deleted><Key>fruits.csv</Key></Deleted></DeleteResult>'
2025-12-12 13:27:29,937 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.DeleteObjects: calling handler <botocore.retryhandler.RetryHandler object at 0x7fb53f175460>
2025-12-12 13:27:29,938 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:27:29,938 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.DeleteObjects: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb530f36360>>
2025-12-12 13:27:29,938 - DEBUG - boto3.resources.action - __call__: Response: {'ResponseMetadata': {'RequestId': 'R5WMLe29qITAFfuPso2285x1F9AmGr3e3eeucTBSxjq6PuzOQIRT', 'HTTPStatusCode': 200, 'HTTPHeaders': {'server': 'Werkzeug/2.2.3 Python/3.12.9', 'date': 'Fri, 12 Dec 2025 13:27:29 GMT', 'x-amzn-requestid': 'R5WMLe29qITAFfuPso2285x1F9AmGr3e3eeucTBSxjq6PuzOQIRT', 'content-type': 'text/html; charset=utf-8', 'content-length': '154', 'access-control-allow-origin': '*', 'connection': 'close'}, 'RetryAttempts': 0}, 'Deleted': [{'Key': 'fruits.csv'}]}
2025-12-12 13:27:29,939 - DEBUG - botocore.hooks - _emit: Event choose-service-name: calling handler <function handle_service_name_alias at 0x7fb55be38ad0>
2025-12-12 13:27:29,942 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_post at 0x7fb55bf487d0>
2025-12-12 13:27:29,943 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function lazy_call.<locals>._handler at 0x7fb55b37aa50>
2025-12-12 13:27:29,943 - DEBUG - botocore.hooks - _emit: Event creating-client-class.s3: calling handler <function add_generate_presigned_url at 0x7fb55bf484d0>
2025-12-12 13:27:29,949 - DEBUG - botocore.endpoint - create_endpoint: Setting s3 timeout as (60, 60)
2025-12-12 13:27:29,954 - DEBUG - botocore.client - _register_legacy_retries: Registering retry handlers for service: s3
2025-12-12 13:27:29,955 - DEBUG - botocore.utils - register: Registering S3 region redirector handler
2025-12-12 13:27:29,957 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function validate_ascii_metadata at 0x7fb55be3ba10>
2025-12-12 13:27:29,958 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function sse_md5 at 0x7fb55be3aa50>
2025-12-12 13:27:29,958 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function convert_body_to_file_like_object at 0x7fb55be60710>
2025-12-12 13:27:29,958 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function validate_bucket_name at 0x7fb55be3a990>
2025-12-12 13:27:29,958 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function remove_bucket_from_url_paths_from_model at 0x7fb55be61250>
2025-12-12 13:27:29,958 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <bound method S3RegionRedirectorv2.annotate_request_context of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb53f387350>>
2025-12-12 13:27:29,959 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.s3.PutObject: calling handler <function generate_idempotent_uuid at 0x7fb55be3a750>
2025-12-12 13:27:29,959 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <function customize_endpoint_resolver_builtins at 0x7fb55be61490>
2025-12-12 13:27:29,959 - DEBUG - botocore.hooks - _emit: Event before-endpoint-resolution.s3: calling handler <bound method S3RegionRedirectorv2.redirect_from_cache of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb53f387350>>
2025-12-12 13:27:29,960 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Bucket': 'fbucket', 'Region': 'yandex', 'UseFIPS': False, 'UseDualStack': False, 'Endpoint': 'http://localhost:9555', 'ForcePathStyle': True, 'Accelerate': False, 'UseGlobalEndpoint': False, 'DisableMultiRegionAccessPoints': False, 'UseArnRegion': True}
2025-12-12 13:27:29,961 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:9555/fbucket
2025-12-12 13:27:29,961 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selecting from endpoint provider's list of auth schemes: "sigv4". User selected auth scheme is: "None"
2025-12-12 13:27:29,962 - DEBUG - botocore.regions - auth_schemes_to_signing_ctx: Selected auth type "v4" as "v4" with signing context params: {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}
2025-12-12 13:27:29,963 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function conditionally_calculate_md5 at 0x7fb55c05f950>
2025-12-12 13:27:29,963 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function add_expect_header at 0x7fb55be3ae10>
2025-12-12 13:27:29,963 - DEBUG - botocore.handlers - add_expect_header: Adding expect 100 continue header to request.
2025-12-12 13:27:29,963 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function add_recursion_detection_header at 0x7fb55be38d10>
2025-12-12 13:27:29,964 - DEBUG - botocore.hooks - _emit: Event before-call.s3.PutObject: calling handler <function inject_api_version_header_if_needed at 0x7fb55be60890>
2025-12-12 13:27:29,964 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=PutObject) with params: {'url_path': '/fruits.csv', 'query_string': {}, 'method': 'PUT', 'headers': {'Content-Type': 'text/plain', 'User-Agent': 'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80', 'Content-MD5': 'syluNHiGATUP+5/OfJsmcg==', 'Expect': '100-continue'}, 'body': <_io.BytesIO object at 0x7fb53f13bc40>, 'auth_path': '/fbucket/fruits.csv', 'url': 'http://localhost:9555/fbucket/fruits.csv', 'context': {'client_region': 'yandex', 'client_config': <botocore.config.Config object at 0x7fb54719dff0>, 'has_streaming_input': True, 'auth_type': 'v4', 's3_redirect': {'redirected': False, 'bucket': 'fbucket', 'params': {'Body': <_io.BytesIO object at 0x7fb53f13bc40>, 'Bucket': 'fbucket', 'Key': 'fruits.csv', 'ContentType': 'text/plain'}}, 'signing': {'region': 'yandex', 'signing_name': 's3', 'disableDoubleEncoding': True}}}
2025-12-12 13:27:29,965 - DEBUG - botocore.hooks - _emit: Event request-created.s3.PutObject: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7fb54719e220>>
2025-12-12 13:27:29,965 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.PutObject: calling handler <bound method ClientCreator._default_s3_presign_to_sigv2 of <botocore.client.ClientCreator object at 0x7fb5471c6d10>>
2025-12-12 13:27:29,965 - DEBUG - botocore.hooks - _emit: Event choose-signer.s3.PutObject: calling handler <function set_operation_specific_signer at 0x7fb55be3a5d0>
2025-12-12 13:27:29,966 - DEBUG - botocore.hooks - _emit: Event before-sign.s3.PutObject: calling handler <function remove_arn_from_signing_path at 0x7fb55be613d0>
2025-12-12 13:27:29,966 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-12-12 13:27:29,967 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
PUT
/fbucket/fruits.csv

content-md5:syluNHiGATUP+5/OfJsmcg==
content-type:text/plain
host:localhost:9555
x-amz-content-sha256:be1c1c4a83c407c74f1385ef6ac12822772856cf51582ff70769720688989a00
x-amz-date:20251212T132729Z

content-md5;content-type;host;x-amz-content-sha256;x-amz-date
be1c1c4a83c407c74f1385ef6ac12822772856cf51582ff70769720688989a00
2025-12-12 13:27:29,967 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251212T132729Z
20251212/yandex/s3/aws4_request
b8916dbb08570812d0d1c03908df3fc7c11c7e74356d422c8a577bb7ffd4ccd6
2025-12-12 13:27:29,967 - DEBUG - botocore.auth - add_auth: Signature:
ff00e6ce14c6df9e2ef808b1d2038a6a5d3ff211eb6b4f1476ad1f9a3a2f4307
2025-12-12 13:27:29,967 - DEBUG - botocore.hooks - _emit: Event request-created.s3.PutObject: calling handler <function add_retry_headers at 0x7fb55be61190>
2025-12-12 13:27:29,968 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=PUT, url=http://localhost:9555/fbucket/fruits.csv, headers={'Content-Type': b'text/plain', 'User-Agent': b'Boto3/1.29.6 md/Botocore#1.31.80 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.9 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.31.80', 'Content-MD5': b'syluNHiGATUP+5/OfJsmcg==', 'Expect': b'100-continue', 'X-Amz-Date': b'20251212T132729Z', 'X-Amz-Content-SHA256': b'be1c1c4a83c407c74f1385ef6ac12822772856cf51582ff70769720688989a00', 'Authorization': b'AWS4-HMAC-SHA256 Credential=key/20251212/yandex/s3/aws4_request, SignedHeaders=content-md5;content-type;host;x-amz-content-sha256;x-amz-date, Signature=ff00e6ce14c6df9e2ef808b1d2038a6a5d3ff211eb6b4f1476ad1f9a3a2f4307', 'amz-sdk-invocation-id': b'889fa8e6-03c5-4b1c-a6c7-b8fc70ae2bc0', 'amz-sdk-request': b'attempt=1', 'Content-Length': '53'}>
2025-12-12 13:27:29,970 - DEBUG - botocore.awsrequest - _send_output: Waiting for 100 Continue response.
2025-12-12 13:27:29,971 - DEBUG - botocore.awsrequest - _handle_expect_response: 100 Continue response seen, now sending request body.
2025-12-12 13:27:29,975 - DEBUG - botocore.parsers - parse: Response headers: {'Server': 'Werkzeug/2.2.3 Python/3.12.9', 'Date': 'Fri, 12 Dec 2025 13:27:29 GMT', 'ETag': '"b3296e34788601350ffb9fce7c9b2672"', 'last-modified': 'Fri, 12 Dec 2025 13:27:29 GMT', 'Content-Length': '0', 'x-amzn-requestid': 'IPvWK0kT4cRwhp8gMCztBQwx1ztTmvEsROqvwGMScGj4CNMUGvNc', 'Content-Type': 'text/html; charset=utf-8', 'Access-Control-Allow-Origin': '*', 'Connection': 'close'}
2025-12-12 13:27:29,980 - DEBUG - botocore.parsers - parse: Response body:
b''
2025-12-12 13:27:29,981 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.PutObject: calling handler <botocore.retryhandler.RetryHandler object at 0x7fb53f3853c0>
2025-12-12 13:27:29,981 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-12-12 13:27:29,981 - DEBUG - botocore.hooks - _emit: Event needs-retry.s3.PutObject: calling handler <bound method S3RegionRedirectorv2.redirect_from_error of <botocore.utils.S3RegionRedirectorv2 object at 0x7fb53f387350>>
2025-12-12 13:27:29,982 - DEBUG - root - wait_bootstrap: Wait for node 1 to bootstrap
2025-12-12 13:27:30,010 - DEBUG - root - wait_bootstrap: Node 1 has been bootstrapped
2025-12-12 13:27:30,546 - DEBUG - root - create_query_impl: Request: content {
  type: ANALYTICS
  name: "simple"
  acl {
    visibility: PRIVATE
  }
  limits {
    execution_timeout {
    }
  }
  text: "\n            SELECT *\n            FROM `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`fruits.csv`\n            WITH (format=\'csv_with_names\', SCHEMA (\n                Name Int32??,\n            ));\n            "
  syntax: YQL_V1
}
execute_mode: RUN
idempotency_key: "80a79d07-0b48-4d06-aea7-7a93865f9eb6"

2025-12-12 13:27:30,757 - DEBUG - root - create_query_impl: Result: query_id: "ptqudq7r3d50n30ugrmm"

2025-12-12 13:27:30,828 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r3d50n30ugrmm"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765546050
        nanos: 551045000
      }
      modified_at {
        seconds: 1765546050
        nanos: 551045000
      }
      revision: 1
    }
    execute_mode: RUN
    status: STARTING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r3d50l38r6vho-ptqudq7r3d50n30ugrmm"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765546050
      nanos: 551045000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`fruits.csv`\n            WITH (format=\'csv_with_names\', SCHEMA (\n                Name Int32??,\n            ));\n            "
    syntax: YQL_V1
  }
}

2025-12-12 13:27:31,353 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r3d50n30ugrmm"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765546050
        nanos: 551045000
      }
      modified_at {
        seconds: 1765546050
        nanos: 551045000
      }
      revision: 1
    }
    started_at {
      seconds: 1765546051
      nanos: 146000000
    }
    execute_mode: RUN
    status: STARTING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r3d50l38r6vho-ptqudq7r3d50n30ugrmm"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765546050
      nanos: 551045000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`fruits.csv`\n            WITH (format=\'csv_with_names\', SCHEMA (\n                Name Int32??,\n            ));\n            "
    syntax: YQL_V1
  }
}

2025-12-12 13:27:31,874 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r3d50n30ugrmm"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765546050
        nanos: 551045000
      }
      modified_at {
        seconds: 1765546050
        nanos: 551045000
      }
      revision: 1
    }
    started_at {
      seconds: 1765546051
      nanos: 146000000
    }
    execute_mode: RUN
    status: RUNNING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r3d50l38r6vho-ptqudq7r3d50n30ugrmm"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765546050
      nanos: 551045000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`fruits.csv`\n            WITH (format=\'csv_with_names\', SCHEMA (\n                Name Int32??,\n            ));\n            "
    syntax: YQL_V1
  }
  plan {
    json: "{}"
  }
  issue {
    message: "Type annotation"
    issue_code: 1030
    severity: 1
    issues {
      position {
        row: 3
        column: 18
      }
      message: "At function: S3ReadObject!"
      end_position {
        row: 3
        column: 18
      }
      severity: 1
      issues {
        position {
          row: 4
          column: 44
        }
        message: "Field \'Name\' has incompatible with S3 csv_with_names input format type: Optional<Int32> (double optional types are not supported)"
        end_position {
          row: 4
          column: 44
        }
        severity: 1
      }
    }
  }
  statistics {
    json: "{}"
  }
  ast {
    data: "(\n(let $1 \'\"/local/h3631900025822173095_test_double_optional_types_validationfruitbucket\")\n(let $2 (S3Object \'(\'((String \'\"Paths {\\n  Name: \\\"fruits.csv\\\"\\n  Size: 53\\n  Read: true\\n}\\n\") (Bool \'\"true\") (AsStruct))) \'\"csv_with_names\" \'()))\n(let $3 (StructType \'(\'\"Name\" (OptionalType (OptionalType (DataType \'Int32))))))\n(let $4 \'(\'\"Name\"))\n(let $5 (DataSink \'result))\n(let $6 (S3Object \'(\'((String \'\"Paths {\\n  Name: \\\"fruits.csv\\\"\\n  Size: 53\\n  Read: true\\n}\\n\") (Bool \'\"true\") (AsStruct))) \'\"csv_with_names\" \'()))\n(let $7 (Right! (S3ReadObject! world (DataSource \'\"s3\" $1) $6 $3 \'\"fruits.csv \" (lambda \'($10) (Bool \'\"true\")) $4)))\n(let $8 (ResWrite! (Left! (S3ReadObject! world (DataSource \'\"s3\" $1) $2 $3 \'\"fruits.csv \" (lambda \'($9) (Bool \'\"true\")) $4)) $5 (Key) (RemovePrefixMembers (RemoveSystemMembers (PersistableRepr (SqlProject $7 \'((SqlProjectStarItem (TypeOf $7) \'\"\" (lambda \'($11) $11) \'()))))) \'(\'_yql_sys_)) \'(\'(\'type) \'(\'autoref))))\n(return (Commit! (Commit! $8 $5) (DataSink \'\"kikimr\" \'\"db\") \'(\'(\'\"mode\" \'\"flush\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'0\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'0\'/></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\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'0\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n\n</svg>\n"
  }
}

2025-12-12 13:27:32,384 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r3d50n30ugrmm"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765546050
        nanos: 551045000
      }
      modified_at {
        seconds: 1765546050
        nanos: 551045000
      }
      revision: 1
    }
    started_at {
      seconds: 1765546051
      nanos: 146000000
    }
    finished_at {
      seconds: 1765546052
      nanos: 69000000
    }
    execute_mode: RUN
    status: FAILED
    last_job_query_revision: 1
    last_job_id: "ptjudq7r3d50l38r6vho-ptqudq7r3d50n30ugrmm"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765546050
      nanos: 551045000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            SELECT *\n            FROM `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`fruits.csv`\n            WITH (format=\'csv_with_names\', SCHEMA (\n                Name Int32??,\n            ));\n            "
    syntax: YQL_V1
  }
  plan {
    json: "{}"
  }
  issue {
    message: "Query failed with code GENERIC_ERROR at 2025-12-12T13:27:31.972415Z"
    severity: 1
    issues {
      message: "Type annotation"
      issue_code: 1030
      severity: 1
      issues {
        position {
          row: 3
          column: 18
        }
        message: "At function: S3ReadObject!"
        end_position {
          row: 3
          column: 18
        }
        severity: 1
        issues {
          position {
            row: 4
            column: 44
          }
          message: "Field \'Name\' has incompatible with S3 csv_with_names input format type: Optional<Int32> (double optional types are not supported)"
          end_position {
            row: 4
            column: 44
          }
          severity: 1
        }
      }
    }
  }
  statistics {
    json: "{}"
  }
  ast {
    data: "(\n(let $1 \'\"/local/h3631900025822173095_test_double_optional_types_validationfruitbucket\")\n(let $2 (S3Object \'(\'((String \'\"Paths {\\n  Name: \\\"fruits.csv\\\"\\n  Size: 53\\n  Read: true\\n}\\n\") (Bool \'\"true\") (AsStruct))) \'\"csv_with_names\" \'()))\n(let $3 (StructType \'(\'\"Name\" (OptionalType (OptionalType (DataType \'Int32))))))\n(let $4 \'(\'\"Name\"))\n(let $5 (DataSink \'result))\n(let $6 (S3Object \'(\'((String \'\"Paths {\\n  Name: \\\"fruits.csv\\\"\\n  Size: 53\\n  Read: true\\n}\\n\") (Bool \'\"true\") (AsStruct))) \'\"csv_with_names\" \'()))\n(let $7 (Right! (S3ReadObject! world (DataSource \'\"s3\" $1) $6 $3 \'\"fruits.csv \" (lambda \'($10) (Bool \'\"true\")) $4)))\n(let $8 (ResWrite! (Left! (S3ReadObject! world (DataSource \'\"s3\" $1) $2 $3 \'\"fruits.csv \" (lambda \'($9) (Bool \'\"true\")) $4)) $5 (Key) (RemovePrefixMembers (RemoveSystemMembers (PersistableRepr (SqlProject $7 \'((SqlProjectStarItem (TypeOf $7) \'\"\" (lambda \'($11) $11) \'()))))) \'(\'_yql_sys_)) \'(\'(\'type) \'(\'autoref))))\n(return (Commit! (Commit! $8 $5) (DataSink \'\"kikimr\" \'\"db\") \'(\'(\'\"mode\" \'\"flush\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'0\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'0\'/></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\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'0\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n\n</svg>\n"
  }
}

2025-12-12 13:27:32,392 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-12-12 13:27:32,393 - DEBUG - root - create_query_impl: Request: content {
  type: ANALYTICS
  name: "simple"
  acl {
    visibility: PRIVATE
  }
  limits {
    execution_timeout {
    }
  }
  text: "\n            INSERT INTO `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`insert/`\n            WITH\n            (\n                FORMAT=\"csv_with_names\"\n            )\n            SELECT CAST(42 AS Int32??) as Weight;"
  syntax: YQL_V1
}
execute_mode: RUN
idempotency_key: "aa8c914d-cf00-4a5f-b39b-8147c19a1d5e"

2025-12-12 13:27:32,414 - DEBUG - root - create_query_impl: Result: query_id: "ptqudq7r3bckt4gro38d"

2025-12-12 13:27:32,425 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r3bckt4gro38d"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765546052
        nanos: 398160000
      }
      modified_at {
        seconds: 1765546052
        nanos: 398160000
      }
      revision: 1
    }
    execute_mode: RUN
    status: STARTING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r3bckqfglso9g-ptqudq7r3bckt4gro38d"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765546052
      nanos: 398160000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            INSERT INTO `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`insert/`\n            WITH\n            (\n                FORMAT=\"csv_with_names\"\n            )\n            SELECT CAST(42 AS Int32??) as Weight;"
    syntax: YQL_V1
  }
}

2025-12-12 13:27:32,942 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-12-12 13:27:33,462 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r3bckt4gro38d"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765546052
        nanos: 398160000
      }
      modified_at {
        seconds: 1765546052
        nanos: 398160000
      }
      revision: 1
    }
    started_at {
      seconds: 1765546053
      nanos: 60000000
    }
    execute_mode: RUN
    status: FAILING
    last_job_query_revision: 1
    last_job_id: "ptjudq7r3bckqfglso9g-ptqudq7r3bckt4gro38d"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765546052
      nanos: 398160000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            INSERT INTO `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`insert/`\n            WITH\n            (\n                FORMAT=\"csv_with_names\"\n            )\n            SELECT CAST(42 AS Int32??) as Weight;"
    syntax: YQL_V1
  }
  plan {
    json: "{}"
  }
  issue {
    message: "Query failed with code GENERIC_ERROR at 2025-12-12T13:27:33.166886Z"
    severity: 1
    issues {
      message: "Type annotation"
      issue_code: 1030
      severity: 1
      issues {
        position {
          row: 5
          column: 24
        }
        message: "At function: S3WriteObject!"
        end_position {
          row: 5
          column: 24
        }
        severity: 1
        issues {
          position {
            row: 7
            column: 13
          }
          message: "Field \'Weight\' has incompatible with S3 csv_with_names output format type: Optional<Int32> (double optional types are not supported)"
          end_position {
            row: 7
            column: 13
          }
          severity: 1
        }
      }
    }
  }
  statistics {
    json: "{}"
  }
  ast {
    data: "(\n(let $1 \'\"/local/h3631900025822173095_test_double_optional_types_validationfruitbucket\")\n(let $2 (S3Target \'\"insert/\" \'\"csv_with_names\" \'(\'(\'mode \'insert_abort))))\n(let $3 (S3WriteObject! world (DataSink \'\"s3\" $1) $2 (OrderedSqlProject (AsList (AsStruct)) \'((SqlProjectItem (ListType (StructType)) \'\"Weight\" (lambda \'($4) (SafeCast (Int32 \'\"42\") (OptionalType (OptionalType (DataType \'Int32))))))))))\n(return (Commit! $3 (DataSink \'\"kikimr\" \'\"db\") \'(\'(\'\"mode\" \'\"flush\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'0\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'0\'/></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\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'0\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n\n</svg>\n"
  }
}

2025-12-12 13:27:33,973 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-12-12 13:27:34,492 - DEBUG - root - describe_query: Result: query {
  meta {
    common {
      id: "ptqudq7r3bckt4gro38d"
      created_by: "root@builtin"
      modified_by: "root@builtin"
      created_at {
        seconds: 1765546052
        nanos: 398160000
      }
      modified_at {
        seconds: 1765546052
        nanos: 398160000
      }
      revision: 1
    }
    started_at {
      seconds: 1765546053
      nanos: 60000000
    }
    finished_at {
      seconds: 1765546054
      nanos: 60000000
    }
    execute_mode: RUN
    status: FAILED
    last_job_query_revision: 1
    last_job_id: "ptjudq7r3bckqfglso9g-ptqudq7r3bckt4gro38d"
    started_by: "root@builtin"
    submitted_at {
      seconds: 1765546052
      nanos: 398160000
    }
  }
  content {
    type: ANALYTICS
    name: "simple"
    acl {
      visibility: PRIVATE
    }
    limits {
      execution_timeout {
      }
    }
    text: "\n            INSERT INTO `h3631900025822173095_test_double_optional_types_validationfruitbucket`.`insert/`\n            WITH\n            (\n                FORMAT=\"csv_with_names\"\n            )\n            SELECT CAST(42 AS Int32??) as Weight;"
    syntax: YQL_V1
  }
  plan {
    json: "{}"
  }
  issue {
    message: "Query failed with code GENERIC_ERROR at 2025-12-12T13:27:33.166886Z"
    severity: 1
    issues {
      message: "Type annotation"
      issue_code: 1030
      severity: 1
      issues {
        position {
          row: 5
          column: 24
        }
        message: "At function: S3WriteObject!"
        end_position {
          row: 5
          column: 24
        }
        severity: 1
        issues {
          position {
            row: 7
            column: 13
          }
          message: "Field \'Weight\' has incompatible with S3 csv_with_names output format type: Optional<Int32> (double optional types are not supported)"
          end_position {
            row: 7
            column: 13
          }
          severity: 1
        }
      }
    }
  }
  statistics {
    json: "{}"
  }
  ast {
    data: "(\n(let $1 \'\"/local/h3631900025822173095_test_double_optional_types_validationfruitbucket\")\n(let $2 (S3Target \'\"insert/\" \'\"csv_with_names\" \'(\'(\'mode \'insert_abort))))\n(let $3 (S3WriteObject! world (DataSink \'\"s3\" $1) $2 (OrderedSqlProject (AsList (AsStruct)) \'((SqlProjectItem (ListType (StructType)) \'\"Weight\" (lambda \'($4) (SafeCast (Int32 \'\"42\") (OptionalType (OptionalType (DataType \'Int32))))))))))\n(return (Commit! $3 (DataSink \'\"kikimr\" \'\"db\") \'(\'(\'\"mode\" \'\"flush\"))))\n)\n"
  }
  timeline {
    svg: "<svg width=\'1280\' height=\'0\' xmlns=\'http://www.w3.org/2000/svg\'>\n<clipPath id=\'clipTextPath\'><rect x=\'0\' y=\'0\' width=\'298\' height=\'0\'/></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\n<line x1=\'600\' y1=\'0\' x2=\'600\' y2=\'0\' stroke-width=\'1\' stroke=\'var(--stage-grid, #B2B2B2)\' stroke-dasharray=\'1,2\'/>\n\n</svg>\n"
  }
}

2025-12-12 13:27:34,512 - DEBUG - root - describe_query: Result: ... (repeated, see above) ...
2025-12-12 13:27:34,516 - INFO - ya.test - pytest_runtest_teardown: Test teardown
