2025-11-04 12:10:27,298 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-04 12:10:27,299 - INFO - ya.test - pytest_runtest_setup: test_retryable_iam_error[tables_format_v1]
2025-11-04 12:10:27,299 - INFO - ya.test - pytest_runtest_setup: ####################################################################################################
2025-11-04 12:10:27,299 - INFO - ya.test - pytest_runtest_setup: Test setup
2025-11-04 12:10:27,300 - DEBUG - root - setup_method: Test started: test_retryable_iam_error
2025-11-04 12:10:27,300 - DEBUG - root - setup_method: Kikimr working dir: /home/runner/.ya/build/build_root/6mpi/001b0a/ydb/tests/functional/sqs/cloud/test-results/py3test/testing_out_stuff/chunk35/testing_out_stuff/test_yandex_cloud_mode.py.TestSqsYandexCloudMode.test_retryable_iam_error.tables_format_v0
2025-11-04 12:10:27,301 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/6mpi/001b0a/ydb/tests/functional/sqs/cloud/test-results/py3test/testing_out_stuff/chunk35/testing_out_stuff/test_yandex_cloud_mode.py.TestSqsYandexCloudMode.test_retryable_iam_error.tables_format_v0/cluster/kikimr_configs"
2025-11-04 12:10:27,301 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/6mpi/001b0a/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/6mpi/001b0a/ydb/tests/functional/sqs/cloud/test-results/py3test/testing_out_stuff/chunk35/testing_out_stuff/test_yandex_cloud_mode.py.TestSqsYandexCloudMode.test_retryable_iam_error.tables_format_v0/cluster/node_1/logfile_swt3p9q6.log --grpc-port=6384 --mon-port=10155 --ic-port=21661 --sqs-port=29296
2025-11-04 12:10:27,301 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:6384/1
2025-11-04 12:10:27,302 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.5
2025-11-04 12:10:27,303 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.5
2025-11-04 12:10:27,304 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6mpi/001b0a/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-04 12:10:27,305 - DEBUG - ya.test - execute: Command pid: 2760097
2025-11-04 12:10:27,678 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) rc: 0
2025-11-04 12:10:27,679 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) elapsed time (sec): 0.37322473526000977
2025-11-04 12:10:27,680 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) idrss: 0
2025-11-04 12:10:27,681 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) inblock: 0
2025-11-04 12:10:27,681 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) isrss: 0
2025-11-04 12:10:27,682 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) ixrss: 0
2025-11-04 12:10:27,682 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) majflt: 0
2025-11-04 12:10:27,682 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) maxrss: 538572
2025-11-04 12:10:27,682 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) minflt: 16127
2025-11-04 12:10:27,683 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) msgrcv: 0
2025-11-04 12:10:27,684 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) msgsnd: 0
2025-11-04 12:10:27,684 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) nivcsw: 5
2025-11-04 12:10:27,685 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) nsignals: 0
2025-11-04 12:10:27,686 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) nswap: 0
2025-11-04 12:10:27,687 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) nvcsw: 13
2025-11-04 12:10:27,687 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) oublock: 8
2025-11-04 12:10:27,687 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) stime: 0.21273899999999998
2025-11-04 12:10:27,688 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) utime: 0.11238999999999999
2025-11-04 12:10:27,689 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) wtime: 0.374
2025-11-04 12:10:27,690 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) output:
Git info:
    Commit: 1929c9518fdd96b4e46371c8ffa93f5a23ca8f28
    Branch: 
    Author: AlexSm <alex@ydb.tech>
    Summary: Merge eceb86f303f339ed52a89fe27dbbc6af3d6e1458 into f5ad9b55634ac97de44bee49e39356e042dc62cf

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-txp46ju72i
    Host information: 
        Linux ghrun-txp46ju72i 5.15.0-157-generic #167-Ubuntu SMP Wed Sep 17 21:35:53 UTC 2025 x86_64

    
Build info:
    Compiler: /home/runner/.ya/tools/v4/9944335923/bin/clang++
    Compiler version: 
        clang version 20.1.8
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/9944335923/bin
    Compile flags: -Xclang -fdebug-compilation-dir -Xclang /tmp -pipe -m64 -O3 -gline-tables-only -fno-common -ffunction-sections -fdata-sections -fsized-deallocation -fexceptions -fuse-init-array -fcolor-diagnostics -faligned-allocation -Werror -Wall -Wextra -Wno-parentheses -Wno-implicit-const-int-float-conversion -Wno-unknown-warning-option -D_THREAD_SAFE -D_PTHREADS -D_REENTRANT -D_LARGEFILE_SOURCE -D__STDC_CONSTANT_MACROS -D__STDC_FORMAT_MACROS -D_FILE_OFFSET_BITS=64 -D_GNU_SOURCE -D_YNDX_LIBUNWIND_ENABLE_EXCEPTION_BACKTRACE -D__LONG_LONG_SUPPORTED -fno-omit-frame-pointer -Wno-unknown-argument -UNDEBUG -Wno-array-parameter -Wno-deprecate-lax-vec-conv-all -Wno-unqualified-std-cast-call -Wno-unused-but-set-parameter -Wno-implicit-function-declaration -Wno-int-conversion -Wno-incompatible-function-pointer-types -Wno-address-of-packed-member -Wno-deprecated-this-capture -Wno-missing-designated-field-initializers -Wno-format -Wno-vla-cxx-extension -Wno-invalid-offsetof -Wno-alias-template-in-declaration-name -Wno-cast-function-type-mismatch -Wno-explicit-specialization-storage-class -Wno-extraneous-template-head -Wno-missing-template-arg-list-after-template-kw -Wno-nontrivial-memcall -Wno-strict-primary-template-shadow -DCATBOOST_OPENSOURCE=yes -msse2 -msse3 -mssse3 -msse4.1 -msse4.2 -mpopcnt -mcx16 -UNDEBUG -Wno-array-parameter -Wno-deprecate-lax-vec-conv-all -Wno-unqualified-std-cast-call -Wno-unused-but-set-parameter -Wno-implicit-function-declaration -Wno-int-conversion -Wno-incompatible-function-pointer-types -Wno-address-of-packed-member -Wno-deprecated-this-capture -Wno-missing-designated-field-initializers -Wno-format -Wno-vla-cxx-extension -Wno-invalid-offsetof -Wno-alias-template-in-declaration-name -Wno-cast-function-type-mismatch -Wno-explicit-specialization-storage-class -Wno-extraneous-template-head -Wno-missing-template-arg-list-after-template-kw -Wno-nontrivial-memcall -Wno-strict-primary-template-shadow -std=c++20 -Wimport-preprocessor-directive-pedantic -Woverloaded-virtual -Wno-ambiguous-reversed-operator -Wno-defaulted-function-deleted -Wno-deprecated-anon-enum-enum-conversion -Wno-deprecated-enum-enum-conversion -Wno-deprecated-enum-float-conversion -Wno-deprecated-volatile -Wno-pessimizing-move -Wno-undefined-var-template -nostdinc++ -DCATBOOST_OPENSOURCE=yes -nostdinc++

2025-11-04 12:10:27,690 - DEBUG - ya.test - _save_outputs: Command (pid 2760097) errors:

2025-11-04 12:10:27,691 - INFO - ydb.tests.library.harness.kikimr_runner - start: Node 1 version:
Git info:
    Commit: 1929c9518fdd96b4e46371c8ffa93f5a23ca8f28
    Branch: 
    Author: AlexSm <alex@ydb.tech>
    Summary: Merge eceb86f303f339ed52a89fe27dbbc6af3d6e1458 into f5ad9b55634ac97de44bee49e39356e042dc62cf
2025-11-04 12:10:27,692 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: CFG_DIR_PATH="/home/runner/.ya/build/build_root/6mpi/001b0a/ydb/tests/functional/sqs/cloud/test-results/py3test/testing_out_stuff/chunk35/testing_out_stuff/test_yandex_cloud_mode.py.TestSqsYandexCloudMode.test_retryable_iam_error.tables_format_v0/cluster/kikimr_configs"
2025-11-04 12:10:27,694 - INFO - ydb.tests.library.harness.kikimr_runner - __make_run_command: Final command: /home/runner/.ya/build/build_root/6mpi/001b0a/ydb/apps/ydbd/ydbd server --suppress-version-check --yaml-config=$CFG_DIR_PATH/config.yaml --node-broker=localhost:6384 --tenant=/Root/TenantSQS --log-file-name=/home/runner/.ya/build/build_root/6mpi/001b0a/ydb/tests/functional/sqs/cloud/test-results/py3test/testing_out_stuff/chunk35/testing_out_stuff/test_yandex_cloud_mode.py.TestSqsYandexCloudMode.test_retryable_iam_error.tables_format_v0/cluster/slot_1/logfile_mppfnyaz.log --grpc-port=4121 --mon-port=24072 --ic-port=17014 --sqs-port=29312
2025-11-04 12:10:27,694 - INFO - ydb.tests.library.harness.kikimr_runner - start: Started node localhost:4121/1
2025-11-04 12:10:27,696 - DEBUG - ya.test - _get_command_output_file: Command out will be placed to ydbd.out.6
2025-11-04 12:10:27,698 - DEBUG - ya.test - _get_command_output_file: Command err will be placed to ydbd.err.6
2025-11-04 12:10:27,699 - DEBUG - ya.test - execute: Executing '['/home/runner/.ya/build/build_root/6mpi/001b0a/ydb/apps/ydbd/ydbd', '-V']' in 'None' (waiting)
2025-11-04 12:10:27,700 - DEBUG - ya.test - execute: Command pid: 2760137
2025-11-04 12:10:28,092 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) rc: 0
2025-11-04 12:10:28,093 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) elapsed time (sec): 0.3912007808685303
2025-11-04 12:10:28,093 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) idrss: 0
2025-11-04 12:10:28,093 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) inblock: 0
2025-11-04 12:10:28,094 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) isrss: 0
2025-11-04 12:10:28,094 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) ixrss: 0
2025-11-04 12:10:28,094 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) majflt: 0
2025-11-04 12:10:28,094 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) maxrss: 538572
2025-11-04 12:10:28,094 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) minflt: 16127
2025-11-04 12:10:28,094 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) msgrcv: 0
2025-11-04 12:10:28,095 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) msgsnd: 0
2025-11-04 12:10:28,095 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) nivcsw: 8
2025-11-04 12:10:28,096 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) nsignals: 0
2025-11-04 12:10:28,096 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) nswap: 0
2025-11-04 12:10:28,096 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) nvcsw: 13
2025-11-04 12:10:28,097 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) oublock: 8
2025-11-04 12:10:28,098 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) stime: 0.218019
2025-11-04 12:10:28,098 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) utime: 0.125159
2025-11-04 12:10:28,099 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) wtime: 0.393
2025-11-04 12:10:28,099 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) output:
Git info:
    Commit: 1929c9518fdd96b4e46371c8ffa93f5a23ca8f28
    Branch: 
    Author: AlexSm <alex@ydb.tech>
    Summary: Merge eceb86f303f339ed52a89fe27dbbc6af3d6e1458 into f5ad9b55634ac97de44bee49e39356e042dc62cf

Other info:
    Build by: runner
    Top src dir: /home/runner/actions_runner/_work/ydb/ydb
    Top build dir: /home/runner/.ya/build
    Hostname: ghrun-txp46ju72i
    Host information: 
        Linux ghrun-txp46ju72i 5.15.0-157-generic #167-Ubuntu SMP Wed Sep 17 21:35:53 UTC 2025 x86_64

    
Build info:
    Compiler: /home/runner/.ya/tools/v4/9944335923/bin/clang++
    Compiler version: 
        clang version 20.1.8
        Target: x86_64-unknown-linux-gnu
        Thread model: posix
        InstalledDir: /home/runner/.ya/tools/v4/9944335923/bin
    Compile flags: -Xclang -fdebug-compilation-dir -Xclang /tmp -pipe -m64 -O3 -gline-tables-only -fno-common -ffunction-sections -fdata-sections -fsized-deallocation -fexceptions -fuse-init-array -fcolor-diagnostics -faligned-allocation -Werror -Wall -Wextra -Wno-parentheses -Wno-implicit-const-int-float-conversion -Wno-unknown-warning-option -D_THREAD_SAFE -D_PTHREADS -D_REENTRANT -D_LARGEFILE_SOURCE -D__STDC_CONSTANT_MACROS -D__STDC_FORMAT_MACROS -D_FILE_OFFSET_BITS=64 -D_GNU_SOURCE -D_YNDX_LIBUNWIND_ENABLE_EXCEPTION_BACKTRACE -D__LONG_LONG_SUPPORTED -fno-omit-frame-pointer -Wno-unknown-argument -UNDEBUG -Wno-array-parameter -Wno-deprecate-lax-vec-conv-all -Wno-unqualified-std-cast-call -Wno-unused-but-set-parameter -Wno-implicit-function-declaration -Wno-int-conversion -Wno-incompatible-function-pointer-types -Wno-address-of-packed-member -Wno-deprecated-this-capture -Wno-missing-designated-field-initializers -Wno-format -Wno-vla-cxx-extension -Wno-invalid-offsetof -Wno-alias-template-in-declaration-name -Wno-cast-function-type-mismatch -Wno-explicit-specialization-storage-class -Wno-extraneous-template-head -Wno-missing-template-arg-list-after-template-kw -Wno-nontrivial-memcall -Wno-strict-primary-template-shadow -DCATBOOST_OPENSOURCE=yes -msse2 -msse3 -mssse3 -msse4.1 -msse4.2 -mpopcnt -mcx16 -UNDEBUG -Wno-array-parameter -Wno-deprecate-lax-vec-conv-all -Wno-unqualified-std-cast-call -Wno-unused-but-set-parameter -Wno-implicit-function-declaration -Wno-int-conversion -Wno-incompatible-function-pointer-types -Wno-address-of-packed-member -Wno-deprecated-this-capture -Wno-missing-designated-field-initializers -Wno-format -Wno-vla-cxx-extension -Wno-invalid-offsetof -Wno-alias-template-in-declaration-name -Wno-cast-function-type-mismatch -Wno-explicit-specialization-storage-class -Wno-extraneous-template-head -Wno-missing-template-arg-list-after-template-kw -Wno-nontrivial-memcall -Wno-strict-primary-template-shadow -std=c++20 -Wimport-preprocessor-directive-pedantic -Woverloaded-virtual -Wno-ambiguous-reversed-operator -Wno-defaulted-function-deleted -Wno-deprecated-anon-enum-enum-conversion -Wno-deprecated-enum-enum-conversion -Wno-deprecated-enum-float-conversion -Wno-deprecated-volatile -Wno-pessimizing-move -Wno-undefined-var-template -nostdinc++ -DCATBOOST_OPENSOURCE=yes -nostdinc++

2025-11-04 12:10:28,100 - DEBUG - ya.test - _save_outputs: Command (pid 2760137) errors:

2025-11-04 12:10:28,101 - INFO - ydb.tests.library.harness.kikimr_runner - start: Node 1 version:
Git info:
    Commit: 1929c9518fdd96b4e46371c8ffa93f5a23ca8f28
    Branch: 
    Author: AlexSm <alex@ydb.tech>
    Summary: Merge eceb86f303f339ed52a89fe27dbbc6af3d6e1458 into f5ad9b55634ac97de44bee49e39356e042dc62cf
2025-11-04 12:10:28,103 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:24072
2025-11-04 12:10:28,108 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:24072 "GET /tablets/app?TabletID=72057594037968897&node=1&page=SetDown&down=0 HTTP/1.1" 200 33
2025-11-04 12:10:28,109 - DEBUG - root - _enable_tablets_on_node: Toggle up reply: {"NodeId":1,"Down":false}
2025-11-04 12:10:28,111 - INFO - ydb.tests.library.sqs.test_base - wait_can_list_users: Listing SQS users
2025-11-04 12:10:28,111 - DEBUG - ydb.tests.library.sqs.requests_client - execute_request: Execute request POST http://localhost:29312 from user U_retryable_iam_error_40653162-b977-11f0-95db-d00dc3df7f25 with params: Action=ListQueues
2025-11-04 12:10:28,114 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:29312
2025-11-04 12:10:28,116 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:29312 "POST / HTTP/1.1" 400 279
2025-11-04 12:10:28,126 - DEBUG - charset_normalizer - from_bytes: Encoding detection: utf_8 is most likely the one.
2025-11-04 12:10:28,127 - WARNING - ydb.tests.library.sqs.requests_client - _process_response: Last request failed with code 400, reason 'Bad request' and text '<?xml version="1.0" encoding="UTF-8"?>
<ErrorResponse><Error><Message>Credential should be scoped to a valid region, not 'yandex'. Request id to report: a736c95c-d634ce9b-4571f619-9a298f53.</Message><Code>IncompleteSignature</Code></Error><RequestId></RequestId></ErrorResponse>
'
2025-11-04 12:10:28,128 - DEBUG - charset_normalizer - from_bytes: Encoding detection: utf_8 is most likely the one.
2025-11-04 12:10:28,129 - DEBUG - charset_normalizer - from_bytes: Encoding detection: utf_8 is most likely the one.
2025-11-04 12:10:28,129 - INFO - ydb.tests.library.sqs.test_base - wait_can_list_users: Success. Api is up.
2025-11-04 12:10:28,130 - 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'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-11-04 12:10:28,132 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-04 12:10:28,132 - 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'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-11-04 12:10:28,139 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/TenantSQS
2025-11-04 12:10:28,139 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, e1769843-14de-4e40-a639-49ac5172792a, localhost:4121): creating call state
2025-11-04 12:10:28,140 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, e1769843-14de-4e40-a639-49ac5172792a, localhost:4121): request = { database: "/Root/TenantSQS" }
2025-11-04 12:10:28,143 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, e1769843-14de-4e40-a639-49ac5172792a, localhost:4121): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-txp46ju72i.auto.internal" port: 4121 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" node_id: 50000 } } } } }
2025-11-04 12:10:28,143 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/TenantSQS: DiscoveryResult <self_location: , endpoints [<Endpoint ghrun-txp46ju72i.auto.internal:4121, location , ssl: False>]>
2025-11-04 12:10:28,144 - 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'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-11-04 12:10:28,151 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:4121
2025-11-04 12:10:28,152 - INFO - root - _before_test_start: run test with cloud_id=CLOUD_FOR_folder_acc_406b88e2-b977-11f0-8331-d00dc3df7f25 folder_id=folder_acc_406b88e2-b977-11f0-8331-d00dc3df7f25
2025-11-04 12:10:28,154 - INFO - ya.test - pytest_runtest_call: Test call (class_name: test_yandex_cloud_mode.py::TestSqsYandexCloudMode, test_name: test_retryable_iam_error[tables_format_v1])
2025-11-04 12:10:28,155 - DEBUG - root - _execute_yql_query: Executing database query: "UPSERT INTO `/Root/TenantSQS/.Settings` (Account, Name, Value)                 VALUES ("CLOUD_FOR_folder_acc_406b88e2-b977-11f0-8331-d00dc3df7f25", "CreateQueuesWithTabletFormat", "1")"
2025-11-04 12:10:28,156 - DEBUG - ydb.connection - _prepare_call: RpcState(CreateSession, 19d29757-9209-4ecf-8238-792bcd63ba63, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:10:28,156 - DEBUG - ydb.connection - _log_request: RpcState(CreateSession, 19d29757-9209-4ecf-8238-792bcd63ba63, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-04 12:10:28,160 - DEBUG - ydb.connection - _log_response: RpcState(CreateSession, 19d29757-9209-4ecf-8238-792bcd63ba63, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.CreateSessionResult] { session_id: "ydb://session/3?node_id=50000&id=ZmMwMzNmZTctOGE1MDk0YzktM2Y0YjY2NTktMjUwYjJlMmQ=" } } } }
2025-11-04 12:10:28,161 - DEBUG - ydb.connection - _prepare_call: RpcState(ExecuteDataQuery, 3fefbe8d-b388-4216-994f-ad4a32b20ff2, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:10:28,162 - DEBUG - ydb.connection - _log_request: RpcState(ExecuteDataQuery, 3fefbe8d-b388-4216-994f-ad4a32b20ff2, ghrun-txp46ju72i.auto.internal:4121): request = { session_id: "ydb://session/3?node_id=50000&id=ZmMwMzNmZTctOGE1MDk0YzktM2Y0YjY2NTktMjUwYjJlMmQ=" tx_control { begin_tx { serializable_read_write { } } commit_tx: true } query { yql_text: "UPSERT INTO `/Root/TenantSQS/.Settings` (Account, Name, Value)                 VALUES (\"CLOUD_FOR_folder_acc_406b88e2-b977-11f0-8331-d00dc3df7f25\", \"CreateQueuesWithTabletFormat\", \"1\")" } operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } }
2025-11-04 12:10:28,181 - DEBUG - ydb.connection - _log_response: RpcState(ExecuteDataQuery, 3fefbe8d-b388-4216-994f-ad4a32b20ff2, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Table.ExecuteQueryResult] { tx_meta { } } } } }
2025-11-04 12:10:28,185 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from creating-client-class.iot-data to creating-client-class.iot-data-plane
2025-11-04 12:10:28,190 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-call.apigateway to before-call.api-gateway
2025-11-04 12:10:28,194 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from request-created.machinelearning.Predict to request-created.machine-learning.Predict
2025-11-04 12:10:28,199 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.autoscaling.CreateLaunchConfiguration to before-parameter-build.auto-scaling.CreateLaunchConfiguration
2025-11-04 12:10:28,199 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.route53 to before-parameter-build.route-53
2025-11-04 12:10:28,202 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from request-created.cloudsearchdomain.Search to request-created.cloudsearch-domain.Search
2025-11-04 12:10:28,204 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from docs.*.autoscaling.CreateLaunchConfiguration.complete-section to docs.*.auto-scaling.CreateLaunchConfiguration.complete-section
2025-11-04 12:10:28,212 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.logs.CreateExportTask to before-parameter-build.cloudwatch-logs.CreateExportTask
2025-11-04 12:10:28,213 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from docs.*.logs.CreateExportTask.complete-section to docs.*.cloudwatch-logs.CreateExportTask.complete-section
2025-11-04 12:10:28,214 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from before-parameter-build.cloudsearchdomain.Search to before-parameter-build.cloudsearch-domain.Search
2025-11-04 12:10:28,215 - DEBUG - botocore.hooks - _alias_event_name: Changing event name from docs.*.cloudsearchdomain.Search.complete-section to docs.*.cloudsearch-domain.Search.complete-section
2025-11-04 12:10:28,224 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/endpoints.json
2025-11-04 12:10:28,272 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/sdk-default-configuration.json
2025-11-04 12:10:28,274 - DEBUG - botocore.hooks - _emit: Event choose-service-name: calling handler <function handle_service_name_alias at 0x7f07b42881d0>
2025-11-04 12:10:28,275 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/sqs/2012-11-05/service-2.json
2025-11-04 12:10:28,279 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/sqs/2012-11-05/endpoint-rule-set-1.json
2025-11-04 12:10:28,280 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/partitions.json
2025-11-04 12:10:28,282 - DEBUG - botocore.hooks - _emit: Event creating-client-class.sqs: calling handler <function add_generate_presigned_url at 0x7f07b437b590>
2025-11-04 12:10:28,283 - DEBUG - botocore.regions - _endpoint_for_partition: Creating a regex based endpoint for sqs, ru-central1
2025-11-04 12:10:28,286 - DEBUG - botocore.endpoint - create_endpoint: Setting sqs timeout as (60, 60)
2025-11-04 12:10:28,288 - DEBUG - botocore.loaders - _load_resource: Loading JSON file: contrib/python/botocore/py3/botocore/data/_retry.json
2025-11-04 12:10:28,289 - DEBUG - botocore.client - _register_legacy_retries: Registering retry handlers for service: sqs
2025-11-04 12:10:28,290 - DEBUG - botocore.hooks - _emit: Event before-parameter-build.sqs.ListQueues: calling handler <function generate_idempotent_uuid at 0x7f07b4289e50>
2025-11-04 12:10:28,291 - DEBUG - botocore.regions - construct_endpoint: Calling endpoint provider with parameters: {'Region': 'ru-central1', 'UseDualStack': False, 'UseFIPS': False, 'Endpoint': 'http://localhost:29312'}
2025-11-04 12:10:28,292 - DEBUG - botocore.regions - construct_endpoint: Endpoint provider result: http://localhost:29312
2025-11-04 12:10:28,293 - DEBUG - botocore.hooks - _emit: Event before-call.sqs.ListQueues: calling handler <function add_recursion_detection_header at 0x7f07b4288410>
2025-11-04 12:10:28,293 - DEBUG - botocore.hooks - _emit: Event before-call.sqs.ListQueues: calling handler <function inject_api_version_header_if_needed at 0x7f07b428bf50>
2025-11-04 12:10:28,293 - DEBUG - botocore.endpoint - make_request: Making request for OperationModel(name=ListQueues) with params: {'url_path': '/', 'query_string': '', 'method': 'POST', 'headers': {'Content-Type': 'application/x-www-form-urlencoded; charset=utf-8', 'User-Agent': 'Boto3/1.34.89 md/Botocore#1.34.89 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.34.89'}, 'body': {'Action': 'ListQueues', 'Version': '2012-11-05'}, 'url': 'http://localhost:29312/', 'context': {'client_region': 'ru-central1', 'client_config': <botocore.config.Config object at 0x7f07b23ff2b0>, 'has_streaming_input': False, 'auth_type': None}}
2025-11-04 12:10:28,294 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7f07b23ff260>>
2025-11-04 12:10:28,295 - DEBUG - botocore.hooks - _emit: Event choose-signer.sqs.ListQueues: calling handler <function set_operation_specific_signer at 0x7f07b4289cd0>
2025-11-04 12:10:28,295 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-11-04 12:10:28,296 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
POST
/

content-type:application/x-www-form-urlencoded; charset=utf-8
host:localhost:29312
x-amz-date:20251104T121028Z
x-amz-security-token:unused

content-type;host;x-amz-date;x-amz-security-token
48a38266faf90970d6c7fea9b15e6ba366e5f6397c2970fc893f8a7b5e207bd0
2025-11-04 12:10:28,296 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251104T121028Z
20251104/ru-central1/sqs/aws4_request
dba8237a15a76a8ff9d5b56fba22c8c204ebe0cef21a5075da5a9586d1d98657
2025-11-04 12:10:28,297 - DEBUG - botocore.auth - add_auth: Signature:
1f06adbc3a6fee3d393cb409e07aca4cb7175d94380f83fc1319a27b2615e19a
2025-11-04 12:10:28,298 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <function add_retry_headers at 0x7f07b42a8890>
2025-11-04 12:10:28,298 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=POST, url=http://localhost:29312/, headers={'Content-Type': b'application/x-www-form-urlencoded; charset=utf-8', 'User-Agent': b'Boto3/1.34.89 md/Botocore#1.34.89 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.34.89', 'X-Amz-Date': b'20251104T121028Z', 'X-Amz-Security-Token': b'unused', 'Authorization': b'AWS4-HMAC-SHA256 Credential=TEST_ID_FOR_RETRYIES/20251104/ru-central1/sqs/aws4_request, SignedHeaders=content-type;host;x-amz-date;x-amz-security-token, Signature=1f06adbc3a6fee3d393cb409e07aca4cb7175d94380f83fc1319a27b2615e19a', 'amz-sdk-invocation-id': b'70dad376-4730-4e79-8d9e-0588ab94a16b', 'amz-sdk-request': b'attempt=1', 'Content-Length': '36'}>
2025-11-04 12:10:28,300 - DEBUG - urllib3.connectionpool - _new_conn: Starting new HTTP connection (1): localhost:29312
2025-11-04 12:10:58,415 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:29312 "POST / HTTP/1.1" 503 241
2025-11-04 12:10:58,416 - DEBUG - botocore.parsers - parse: Response headers: {'Content-Type': 'application/xml', 'Content-Length': '241', 'Connection': 'Keep-Alive'}
2025-11-04 12:10:58,417 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?>\n<ErrorResponse><Error><Message>IAM authorization error. Request id to report: 6376e65-b3c7e447-23bae452-f6904f39.</Message><Code>ServiceUnavailable</Code></Error><RequestId></RequestId></ErrorResponse>\n'
2025-11-04 12:10:58,419 - DEBUG - botocore.hooks - _emit: Event needs-retry.sqs.ListQueues: calling handler <botocore.retryhandler.RetryHandler object at 0x7f07b2386680>
2025-11-04 12:10:58,419 - DEBUG - botocore.retryhandler - _check_response: retry needed: retryable HTTP status code received: 503
2025-11-04 12:10:58,419 - DEBUG - botocore.retryhandler - __call__: Retry needed, action of: 0.9754989668387458
2025-11-04 12:10:58,419 - DEBUG - botocore.endpoint - _needs_retry: Response received to retry, sleeping for 0.9754989668387458 seconds
2025-11-04 12:10:59,396 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7f07b23ff260>>
2025-11-04 12:10:59,396 - DEBUG - botocore.hooks - _emit: Event choose-signer.sqs.ListQueues: calling handler <function set_operation_specific_signer at 0x7f07b4289cd0>
2025-11-04 12:10:59,397 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-11-04 12:10:59,398 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
POST
/

content-type:application/x-www-form-urlencoded; charset=utf-8
host:localhost:29312
x-amz-date:20251104T121059Z
x-amz-security-token:unused

content-type;host;x-amz-date;x-amz-security-token
48a38266faf90970d6c7fea9b15e6ba366e5f6397c2970fc893f8a7b5e207bd0
2025-11-04 12:10:59,398 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251104T121059Z
20251104/ru-central1/sqs/aws4_request
e564e6ffa2c47128d1ead74c4f9c914bf96cee093df56637527eca770eda0ba7
2025-11-04 12:10:59,398 - DEBUG - botocore.auth - add_auth: Signature:
b5f123d2bdf04314c601da8bef01d0661fd2f2b2eca54f1b7c4433eede6258cb
2025-11-04 12:10:59,399 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <function add_retry_headers at 0x7f07b42a8890>
2025-11-04 12:10:59,399 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=POST, url=http://localhost:29312/, headers={'Content-Type': b'application/x-www-form-urlencoded; charset=utf-8', 'User-Agent': b'Boto3/1.34.89 md/Botocore#1.34.89 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.34.89', 'X-Amz-Date': b'20251104T121059Z', 'X-Amz-Security-Token': b'unused', 'Authorization': b'AWS4-HMAC-SHA256 Credential=TEST_ID_FOR_RETRYIES/20251104/ru-central1/sqs/aws4_request, SignedHeaders=content-type;host;x-amz-date;x-amz-security-token, Signature=b5f123d2bdf04314c601da8bef01d0661fd2f2b2eca54f1b7c4433eede6258cb', 'amz-sdk-invocation-id': b'70dad376-4730-4e79-8d9e-0588ab94a16b', 'amz-sdk-request': b'attempt=2; max=5', 'Content-Length': '36'}>
2025-11-04 12:11:29,526 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:29312 "POST / HTTP/1.1" 503 242
2025-11-04 12:11:29,528 - DEBUG - botocore.parsers - parse: Response headers: {'Content-Type': 'application/xml', 'Content-Length': '242', 'Connection': 'Keep-Alive'}
2025-11-04 12:11:29,528 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?>\n<ErrorResponse><Error><Message>IAM authorization error. Request id to report: 759773cd-e5c28493-a065f8bc-db0038d9.</Message><Code>ServiceUnavailable</Code></Error><RequestId></RequestId></ErrorResponse>\n'
2025-11-04 12:11:29,529 - DEBUG - botocore.hooks - _emit: Event needs-retry.sqs.ListQueues: calling handler <botocore.retryhandler.RetryHandler object at 0x7f07b2386680>
2025-11-04 12:11:29,529 - DEBUG - botocore.retryhandler - _check_response: retry needed: retryable HTTP status code received: 503
2025-11-04 12:11:29,529 - DEBUG - botocore.retryhandler - __call__: Retry needed, action of: 1.3539264171207754
2025-11-04 12:11:29,529 - DEBUG - botocore.endpoint - _needs_retry: Response received to retry, sleeping for 1.3539264171207754 seconds
2025-11-04 12:11:30,884 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7f07b23ff260>>
2025-11-04 12:11:30,885 - DEBUG - botocore.hooks - _emit: Event choose-signer.sqs.ListQueues: calling handler <function set_operation_specific_signer at 0x7f07b4289cd0>
2025-11-04 12:11:30,885 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-11-04 12:11:30,886 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
POST
/

content-type:application/x-www-form-urlencoded; charset=utf-8
host:localhost:29312
x-amz-date:20251104T121130Z
x-amz-security-token:unused

content-type;host;x-amz-date;x-amz-security-token
48a38266faf90970d6c7fea9b15e6ba366e5f6397c2970fc893f8a7b5e207bd0
2025-11-04 12:11:30,888 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251104T121130Z
20251104/ru-central1/sqs/aws4_request
f2a04abf31b2014715dcdfb9b1f2a7957e2395d415c6fd5eb3956ab45561c73e
2025-11-04 12:11:30,888 - DEBUG - botocore.auth - add_auth: Signature:
81ce63b4e01bf713667bf9f32deb3ac0444e8335d5a9631e12a941db9d6bd3a8
2025-11-04 12:11:30,889 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <function add_retry_headers at 0x7f07b42a8890>
2025-11-04 12:11:30,889 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=POST, url=http://localhost:29312/, headers={'Content-Type': b'application/x-www-form-urlencoded; charset=utf-8', 'User-Agent': b'Boto3/1.34.89 md/Botocore#1.34.89 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.34.89', 'X-Amz-Date': b'20251104T121130Z', 'X-Amz-Security-Token': b'unused', 'Authorization': b'AWS4-HMAC-SHA256 Credential=TEST_ID_FOR_RETRYIES/20251104/ru-central1/sqs/aws4_request, SignedHeaders=content-type;host;x-amz-date;x-amz-security-token, Signature=81ce63b4e01bf713667bf9f32deb3ac0444e8335d5a9631e12a941db9d6bd3a8', 'amz-sdk-invocation-id': b'70dad376-4730-4e79-8d9e-0588ab94a16b', 'amz-sdk-request': b'attempt=3; max=5', 'Content-Length': '36'}>
2025-11-04 12:11:34,173 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Preparing initial endpoint to resolve endpoints
2025-11-04 12:11:34,174 - 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'), ('grpc.keepalive_time_ms', 1250), ('grpc.keepalive_timeout_ms', 10000), ('grpc.http2.max_pings_without_data', 0), ('grpc.keepalive_permit_without_calls', 0)]
2025-11-04 12:11:34,179 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - context_resolve: Resolving endpoints for database /Root/TenantSQS
2025-11-04 12:11:34,180 - DEBUG - ydb.connection - _prepare_call: RpcState(ListEndpoints, 4c614a10-ce3f-4136-8a1e-adfa3e2fc737, localhost:4121): creating call state
2025-11-04 12:11:34,180 - DEBUG - ydb.connection - _log_request: RpcState(ListEndpoints, 4c614a10-ce3f-4136-8a1e-adfa3e2fc737, localhost:4121): request = { database: "/Root/TenantSQS" }
2025-11-04 12:11:34,183 - DEBUG - ydb.connection - _log_response: RpcState(ListEndpoints, 4c614a10-ce3f-4136-8a1e-adfa3e2fc737, localhost:4121): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Discovery.ListEndpointsResult] { endpoints { address: "ghrun-txp46ju72i.auto.internal" port: 4121 service: "legacy" service: "tablet_service" service: "yql" service: "discovery" service: "cms" service: "locking" service: "kesus" service: "pq" service: "pqcd" service: "pqv1" service: "topic" service: "datastreams" service: "scripting" service: "clickhouse_internal" service: "rate_limiter" service: "analytics" service: "export" service: "import" service: "yq" service: "keyvalue" service: "monitoring" service: "auth" service: "query_service" service: "view" node_id: 50000 } } } } }
2025-11-04 12:11:34,183 - DEBUG - ydb.resolver.DiscoveryEndpointsResolver - _add_debug_details: Resolved endpoints for database /Root/TenantSQS: DiscoveryResult <self_location: , endpoints [<Endpoint ghrun-txp46ju72i.auto.internal:4121, location , ssl: False>]>
2025-11-04 12:11:34,184 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:4121
2025-11-04 12:12:01,005 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:29312 "POST / HTTP/1.1" 503 242
2025-11-04 12:12:01,006 - DEBUG - botocore.parsers - parse: Response headers: {'Content-Type': 'application/xml', 'Content-Length': '242', 'Connection': 'Keep-Alive'}
2025-11-04 12:12:01,006 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?>\n<ErrorResponse><Error><Message>IAM authorization error. Request id to report: f5bdb241-ed1c7cb1-a1160e34-d2695e5e.</Message><Code>ServiceUnavailable</Code></Error><RequestId></RequestId></ErrorResponse>\n'
2025-11-04 12:12:01,007 - DEBUG - botocore.hooks - _emit: Event needs-retry.sqs.ListQueues: calling handler <botocore.retryhandler.RetryHandler object at 0x7f07b2386680>
2025-11-04 12:12:01,009 - DEBUG - botocore.retryhandler - _check_response: retry needed: retryable HTTP status code received: 503
2025-11-04 12:12:01,009 - DEBUG - botocore.retryhandler - __call__: Retry needed, action of: 1.387407468913676
2025-11-04 12:12:01,010 - DEBUG - botocore.endpoint - _needs_retry: Response received to retry, sleeping for 1.387407468913676 seconds
2025-11-04 12:12:02,399 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7f07b23ff260>>
2025-11-04 12:12:02,400 - DEBUG - botocore.hooks - _emit: Event choose-signer.sqs.ListQueues: calling handler <function set_operation_specific_signer at 0x7f07b4289cd0>
2025-11-04 12:12:02,401 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-11-04 12:12:02,401 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
POST
/

content-type:application/x-www-form-urlencoded; charset=utf-8
host:localhost:29312
x-amz-date:20251104T121202Z
x-amz-security-token:unused

content-type;host;x-amz-date;x-amz-security-token
48a38266faf90970d6c7fea9b15e6ba366e5f6397c2970fc893f8a7b5e207bd0
2025-11-04 12:12:02,403 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251104T121202Z
20251104/ru-central1/sqs/aws4_request
7c22228d5435ffb2d511b511815d8099d6daf355359fc00c4f796df1710bf26b
2025-11-04 12:12:02,403 - DEBUG - botocore.auth - add_auth: Signature:
4d3c0faa2d2df9b56f982e0d4e367795d05c3453aa44369922c75e47eb35cbba
2025-11-04 12:12:02,404 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <function add_retry_headers at 0x7f07b42a8890>
2025-11-04 12:12:02,404 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=POST, url=http://localhost:29312/, headers={'Content-Type': b'application/x-www-form-urlencoded; charset=utf-8', 'User-Agent': b'Boto3/1.34.89 md/Botocore#1.34.89 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.34.89', 'X-Amz-Date': b'20251104T121202Z', 'X-Amz-Security-Token': b'unused', 'Authorization': b'AWS4-HMAC-SHA256 Credential=TEST_ID_FOR_RETRYIES/20251104/ru-central1/sqs/aws4_request, SignedHeaders=content-type;host;x-amz-date;x-amz-security-token, Signature=4d3c0faa2d2df9b56f982e0d4e367795d05c3453aa44369922c75e47eb35cbba', 'amz-sdk-invocation-id': b'70dad376-4730-4e79-8d9e-0588ab94a16b', 'amz-sdk-request': b'attempt=4; max=5', 'Content-Length': '36'}>
2025-11-04 12:12:32,531 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:29312 "POST / HTTP/1.1" 503 242
2025-11-04 12:12:32,532 - DEBUG - botocore.parsers - parse: Response headers: {'Content-Type': 'application/xml', 'Content-Length': '242', 'Connection': 'Keep-Alive'}
2025-11-04 12:12:32,532 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?>\n<ErrorResponse><Error><Message>IAM authorization error. Request id to report: 87694668-541e4f79-d889db84-56fccc9e.</Message><Code>ServiceUnavailable</Code></Error><RequestId></RequestId></ErrorResponse>\n'
2025-11-04 12:12:32,532 - DEBUG - botocore.hooks - _emit: Event needs-retry.sqs.ListQueues: calling handler <botocore.retryhandler.RetryHandler object at 0x7f07b2386680>
2025-11-04 12:12:32,533 - DEBUG - botocore.retryhandler - _check_response: retry needed: retryable HTTP status code received: 503
2025-11-04 12:12:32,533 - DEBUG - botocore.retryhandler - __call__: Retry needed, action of: 2.665105259246573
2025-11-04 12:12:32,533 - DEBUG - botocore.endpoint - _needs_retry: Response received to retry, sleeping for 2.665105259246573 seconds
2025-11-04 12:12:35,199 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <bound method RequestSigner.handler of <botocore.signers.RequestSigner object at 0x7f07b23ff260>>
2025-11-04 12:12:35,199 - DEBUG - botocore.hooks - _emit: Event choose-signer.sqs.ListQueues: calling handler <function set_operation_specific_signer at 0x7f07b4289cd0>
2025-11-04 12:12:35,200 - DEBUG - botocore.auth - add_auth: Calculating signature using v4 auth.
2025-11-04 12:12:35,201 - DEBUG - botocore.auth - add_auth: CanonicalRequest:
POST
/

content-type:application/x-www-form-urlencoded; charset=utf-8
host:localhost:29312
x-amz-date:20251104T121235Z
x-amz-security-token:unused

content-type;host;x-amz-date;x-amz-security-token
48a38266faf90970d6c7fea9b15e6ba366e5f6397c2970fc893f8a7b5e207bd0
2025-11-04 12:12:35,201 - DEBUG - botocore.auth - add_auth: StringToSign:
AWS4-HMAC-SHA256
20251104T121235Z
20251104/ru-central1/sqs/aws4_request
8a3629a29cd355f002065ab35d0ffe0a90207641cbaaac26d942659d800363ec
2025-11-04 12:12:35,221 - DEBUG - botocore.auth - add_auth: Signature:
c064ab0f93ff6bcf5f8dd13d228614798eb3b854c8577f7678dffd889064a748
2025-11-04 12:12:35,222 - DEBUG - botocore.hooks - _emit: Event request-created.sqs.ListQueues: calling handler <function add_retry_headers at 0x7f07b42a8890>
2025-11-04 12:12:35,222 - DEBUG - botocore.endpoint - _do_get_response: Sending http request: <AWSPreparedRequest stream_output=False, method=POST, url=http://localhost:29312/, headers={'Content-Type': b'application/x-www-form-urlencoded; charset=utf-8', 'User-Agent': b'Boto3/1.34.89 md/Botocore#1.34.89 ua/2.0 os/linux#5.15.0-157-generic md/arch#x86_64 lang/python#3.12.12 md/pyimpl#CPython cfg/retry-mode#legacy Botocore/1.34.89', 'X-Amz-Date': b'20251104T121235Z', 'X-Amz-Security-Token': b'unused', 'Authorization': b'AWS4-HMAC-SHA256 Credential=TEST_ID_FOR_RETRYIES/20251104/ru-central1/sqs/aws4_request, SignedHeaders=content-type;host;x-amz-date;x-amz-security-token, Signature=c064ab0f93ff6bcf5f8dd13d228614798eb3b854c8577f7678dffd889064a748', 'amz-sdk-invocation-id': b'70dad376-4730-4e79-8d9e-0588ab94a16b', 'amz-sdk-request': b'attempt=5; max=5', 'Content-Length': '36'}>
2025-11-04 12:13:05,338 - DEBUG - urllib3.connectionpool - _make_request: http://localhost:29312 "POST / HTTP/1.1" 503 241
2025-11-04 12:13:05,339 - DEBUG - botocore.parsers - parse: Response headers: {'Content-Type': 'application/xml', 'Content-Length': '241', 'Connection': 'Keep-Alive'}
2025-11-04 12:13:05,339 - DEBUG - botocore.parsers - parse: Response body:
b'<?xml version="1.0" encoding="UTF-8"?>\n<ErrorResponse><Error><Message>IAM authorization error. Request id to report: 66ad203d-34b5b742-ede8bde3-69486b0.</Message><Code>ServiceUnavailable</Code></Error><RequestId></RequestId></ErrorResponse>\n'
2025-11-04 12:13:05,340 - DEBUG - botocore.hooks - _emit: Event needs-retry.sqs.ListQueues: calling handler <botocore.retryhandler.RetryHandler object at 0x7f07b2386680>
2025-11-04 12:13:05,340 - DEBUG - botocore.retryhandler - _check_response: retry needed: retryable HTTP status code received: 503
2025-11-04 12:13:05,340 - DEBUG - botocore.retryhandler - __call__: Reached the maximum number of retry attempts: 5
2025-11-04 12:13:05,340 - DEBUG - botocore.retryhandler - __call__: No retry needed.
2025-11-04 12:13:05,345 - INFO - ya.test - pytest_runtest_teardown: Test teardown
2025-11-04 12:13:05,346 - DEBUG - ydb.connection - _prepare_call: RpcState(ListDirectory, 447d97a9-75c0-4680-a82e-e04dd344d1b3, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,347 - DEBUG - ydb.connection - _log_request: RpcState(ListDirectory, 447d97a9-75c0-4680-a82e-e04dd344d1b3, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS" }
2025-11-04 12:13:05,351 - DEBUG - ydb.connection - _log_response: RpcState(ListDirectory, 447d97a9-75c0-4680-a82e-e04dd344d1b3, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SUCCESS result { [type.googleapis.com/Ydb.Scheme.ListDirectoryResult] { self { name: "Root/TenantSQS" owner: "root@builtin" type: DATABASE effective_permissions { subject: "USERS" permission_names: "ydb.database.connect" } effective_permissions { subject: "METADATA-READERS" permission_names: "ydb.generic.list" } effective_permissions { subject: "DATA-READERS" permission_names: "ydb.granular.select_row" } effective_permissions { subject: "DATA-WRITERS" permission_names: "ydb.tables.modify" } effective_permissions { subject: "DDL-ADMINS" permission_names: "ydb.granular.create_directory" permission_names: "ydb.granular.write_attributes" permission_names: "ydb.granular.create_table" permission_names: "ydb.granular.remove_schema" permission_names: "ydb.granular.create_queue" permission_names: "ydb.granular.alter_schema" } effective_permissions { subject: "ACCESS-ADMINS" permission_names: "ydb.access.grant" } effective_permissions { subject: "DATABASE-ADMINS" permission_names: "ydb.generic.manage" } size_bytes: 315 created_at { tx_id: 1 } } children { name: ".AtomicCounter" owner: "root@builtin" type: TABLE created_at { plan_step: 1762258070660 tx_id: 281474976720659 } } children { name: ".Events" owner: "root@builtin" type: TABLE created_at { plan_step: 1762258070870 tx_id: 281474976720662 } } children { name: ".FIFO" owner: "root@builtin" type: DIRECTORY created_at { plan_step: 1762258071290 tx_id: 281474976720669 } } children { name: ".Queues" owner: "root@builtin" type: TABLE created_at { plan_step: 1762258070770 tx_id: 281474976720661 } } children { name: ".RemovedQueues" owner: "root@builtin" type: TABLE created_at { plan_step: 1762258070960 tx_id: 281474976720664 } } children { name: ".STD" owner: "root@builtin" type: DIRECTORY created_at { plan_step: 1762258071040 tx_id: 281474976720665 } } children { name: ".Settings" owner: "root@builtin" type: TABLE created_at { plan_step: 1762258070930 tx_id: 281474976720663 } } children { name: ".metadata" owner: "metadata@system" type: DIRECTORY created_at { plan_step: 1762258069360 tx_id: 281474976720657 } } children { name: ".sys" type: DIRECTORY created_at { } } } } } }
2025-11-04 12:13:05,357 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 007e4a67-bdf6-4412-83dd-b6db676d9aeb, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,357 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 007e4a67-bdf6-4412-83dd-b6db676d9aeb, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS/.Events/Queues" }
2025-11-04 12:13:05,361 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 007e4a67-bdf6-4412-83dd-b6db676d9aeb, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SCHEME_ERROR issues { message: "Path not found" severity: 1 } } }
2025-11-04 12:13:05,362 - DEBUG - ydb.tests.library.sqs.test_base - check_no_queues_table: No queue table: message: "Path not found" severity: 1 (server_code: 400070)
2025-11-04 12:13:05,362 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 6414d6f6-16e8-4c32-b86b-90cb9ca104c8, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,363 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 6414d6f6-16e8-4c32-b86b-90cb9ca104c8, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS/.FIFO/Queues" }
2025-11-04 12:13:05,366 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 6414d6f6-16e8-4c32-b86b-90cb9ca104c8, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SCHEME_ERROR issues { message: "Path not found" severity: 1 } } }
2025-11-04 12:13:05,366 - DEBUG - ydb.tests.library.sqs.test_base - check_no_queues_table: No queue table: message: "Path not found" severity: 1 (server_code: 400070)
2025-11-04 12:13:05,367 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 93a6d915-6e02-4780-9a16-a9fc84a26b64, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,367 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 93a6d915-6e02-4780-9a16-a9fc84a26b64, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS/.RemovedQueues/Queues" }
2025-11-04 12:13:05,370 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 93a6d915-6e02-4780-9a16-a9fc84a26b64, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SCHEME_ERROR issues { message: "Path not found" severity: 1 } } }
2025-11-04 12:13:05,370 - DEBUG - ydb.tests.library.sqs.test_base - check_no_queues_table: No queue table: message: "Path not found" severity: 1 (server_code: 400070)
2025-11-04 12:13:05,373 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, b8f4acf8-c1e1-47ec-95a2-8ff5ecb32f73, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,373 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, b8f4acf8-c1e1-47ec-95a2-8ff5ecb32f73, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS/.STD/Queues" }
2025-11-04 12:13:05,376 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, b8f4acf8-c1e1-47ec-95a2-8ff5ecb32f73, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SCHEME_ERROR issues { message: "Path not found" severity: 1 } } }
2025-11-04 12:13:05,378 - DEBUG - ydb.tests.library.sqs.test_base - check_no_queues_table: No queue table: message: "Path not found" severity: 1 (server_code: 400070)
2025-11-04 12:13:05,380 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 2abef10a-abdb-4ef1-a867-61c2ade7d118, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,381 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 2abef10a-abdb-4ef1-a867-61c2ade7d118, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS/.metadata/Queues" }
2025-11-04 12:13:05,383 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 2abef10a-abdb-4ef1-a867-61c2ade7d118, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SCHEME_ERROR issues { message: "Path not found" severity: 1 } } }
2025-11-04 12:13:05,384 - DEBUG - ydb.tests.library.sqs.test_base - check_no_queues_table: No queue table: message: "Path not found" severity: 1 (server_code: 400070)
2025-11-04 12:13:05,385 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 8531296e-f221-4f74-bfd1-a3494c83b4b8, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,386 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 8531296e-f221-4f74-bfd1-a3494c83b4b8, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS/.sys/Queues" }
2025-11-04 12:13:05,388 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 8531296e-f221-4f74-bfd1-a3494c83b4b8, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SCHEME_ERROR issues { message: "Path not found" severity: 1 } } }
2025-11-04 12:13:05,388 - DEBUG - ydb.tests.library.sqs.test_base - check_no_queues_table: No queue table: message: "Path not found" severity: 1 (server_code: 400070)
2025-11-04 12:13:05,388 - DEBUG - ydb.connection - _prepare_call: RpcState(DescribePath, 1688d502-ccd9-480a-be69-b70d90812f40, ghrun-txp46ju72i.auto.internal:4121): creating call state
2025-11-04 12:13:05,389 - DEBUG - ydb.connection - _log_request: RpcState(DescribePath, 1688d502-ccd9-480a-be69-b70d90812f40, ghrun-txp46ju72i.auto.internal:4121): request = { operation_params { operation_timeout { seconds: 600 } cancel_after { seconds: 600 } } path: "/Root/TenantSQS/CLOUD_FOR_folder_acc_406b88e2-b977-11f0-8331-d00dc3df7f25/Queues" }
2025-11-04 12:13:05,391 - DEBUG - ydb.connection - _log_response: RpcState(DescribePath, 1688d502-ccd9-480a-be69-b70d90812f40, ghrun-txp46ju72i.auto.internal:4121): response = { operation { ready: true status: SCHEME_ERROR issues { message: "Path not found" severity: 1 } } }
2025-11-04 12:13:05,392 - DEBUG - ydb.tests.library.sqs.test_base - check_no_queues_table: No queue table: message: "Path not found" severity: 1 (server_code: 400070)
2025-11-04 12:13:05,392 - DEBUG - ydb.topic - close: Close topic client
2025-11-04 12:13:05,392 - DEBUG - ydb.topic - close: Topic client was closed
2025-11-04 12:13:05,392 - DEBUG - ydb.connection - close: Closing channel for endpoint localhost:4121
2025-11-04 12:13:05,393 - DEBUG - ydb.connection - close: Closing channel for endpoint ghrun-txp46ju72i.auto.internal:4121
2025-11-04 12:13:05,394 - INFO - ydb.pool.Discovery - run: Successfully terminated discovery process
2025-11-04 12:13:05,394 - DEBUG - root - teardown_method: Test finished: test_retryable_iam_error
2025-11-04 12:13:08,396 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:6384/1
2025-11-04 12:13:17,396 - INFO - ydb.tests.library.harness.kikimr_runner - stop: Stopped node localhost:4121/1
2025-11-04 12:13:17,404 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/29312
2025-11-04 12:13:17,406 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/29764
2025-11-04 12:13:17,406 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/9912
2025-11-04 12:13:17,410 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/17014
2025-11-04 12:13:17,410 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/24072
2025-11-04 12:13:17,413 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/4121
2025-11-04 12:13:17,413 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/29296
2025-11-04 12:13:17,413 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/19643
2025-11-04 12:13:17,413 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/26146
2025-11-04 12:13:17,413 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/10155
2025-11-04 12:13:17,414 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/6384
2025-11-04 12:13:17,414 - DEBUG - library.python.filelock - release: Ensuring FileLock released: /home/runner/.ya/build/port_sync_dir/21661
