azure-sdk-for-cpp icon indicating copy to clipboard operation
azure-sdk-for-cpp copied to clipboard

Intermittent KeyVaultKeyClient.DoubleDeleteBeforePollComplete test failure due to 403 Reason: Forbidden

Open ahsonkhan opened this issue 7 months ago • 2 comments

From https://github.com/Azure/azure-sdk-for-cpp/pull/5814

On: ValidateLive Win2022_x86_no_rtti_with_unit_test https://dev.azure.com/azure-sdk/internal/_build/results?buildId=3971287&view=logs&j=2fc98781-9230-5004-8e4b-444d4f6ce9bd&t=3c1f81d9-4b69-5f1f-44df-3f6e046c3c5e

2024-07-17T23:17:33.0085076Z test 22
2024-07-17T23:17:33.0085916Z         Start  22: azure-security-keyvault-keys.KeyVaultKeyClient.DoubleDeleteBeforePollComplete
2024-07-17T23:17:33.0086337Z 
2024-07-17T23:17:33.0087453Z 22: Test command: D:\a\_work\1\s\build\sdk\keyvault\azure-security-keyvault-keys\test\ut\Release\azure-security-keyvault-keys-test.exe "--gtest_filter=KeyVaultKeyClient.DoubleDeleteBeforePollComplete" "--gtest_also_run_disabled_tests"
2024-07-17T23:17:33.0089537Z 22: Working Directory: D:/a/_work/1/s/build/sdk/keyvault/azure-security-keyvault-keys/test/ut
2024-07-17T23:17:33.0090340Z 22: Test timeout computed to be: 10000000
2024-07-17T23:17:33.0187022Z 22: Running main() from D:\a\_work\1\s\build\_deps\googletest-src\googletest\src\gtest_main.cc
2024-07-17T23:17:33.0187954Z 22: Note: Google Test filter = KeyVaultKeyClient.DoubleDeleteBeforePollComplete
2024-07-17T23:17:33.0188716Z 22: [==========] Running 1 test from 1 test suite.
2024-07-17T23:17:33.0189399Z 22: [----------] Global test environment set-up.
2024-07-17T23:17:33.0190066Z 22: [----------] 1 test from KeyVaultKeyClient
2024-07-17T23:17:33.0190668Z 22: [ RUN      ] KeyVaultKeyClient.DoubleDeleteBeforePollComplete
2024-07-17T23:17:33.0208133Z 22: [2024-07-17T23:17:33.0205580Z T: 1100] INFO  : Identity: AzurePipelinesCredential was created successfully.
2024-07-17T23:17:33.0209477Z 22: [2024-07-17T23:17:33.0206076Z T: 1100] DEBUG : Identity: Creating DefaultAzureCredential which combines mutiple parameterless credentials into a single one.
2024-07-17T23:17:33.0210972Z 22: DefaultAzureCredential is only recommended for the early stages of development, and not for usage in production environment.
2024-07-17T23:17:33.0212307Z 22: Once the developer focuses on the Credentials and Authentication aspects of their application, DefaultAzureCredential needs to be replaced with the credential that is the better fit for the application.
2024-07-17T23:17:33.0213360Z 22: [2024-07-17T23:17:33.0206848Z T: 1100] WARN  : Identity: EnvironmentCredential was not initialized with underlying credential.
2024-07-17T23:17:33.0214493Z 22: [2024-07-17T23:17:33.0207084Z T: 1100] DEBUG : Identity: EnvironmentCredential: Both 'AZURE_TENANT_ID' and 'AZURE_CLIENT_ID', and at least one of 'AZURE_CLIENT_SECRET', 'AZURE_CLIENT_CERTIFICATE_PATH' needs to be set. Additionally, 'AZURE_AUTHORITY_HOST' could be set to override the default authority host. Currently:
2024-07-17T23:17:33.0215369Z 22:  * 'AZURE_TENANT_ID' is set
2024-07-17T23:17:33.0216114Z 22:  * 'AZURE_CLIENT_ID' is set
2024-07-17T23:17:33.0216734Z 22:  * 'AZURE_CLIENT_SECRET' is NOT set
2024-07-17T23:17:33.0217376Z 22:  * 'AZURE_CLIENT_CERTIFICATE_PATH' is NOT set
2024-07-17T23:17:33.0218008Z 22:  * 'AZURE_AUTHORITY_HOST' is set
2024-07-17T23:17:33.0218918Z 22: [2024-07-17T23:17:33.0207431Z T: 1100] WARN  : Identity: Azure Kubernetes environment is not set up for the WorkloadIdentityCredential credential to work.
2024-07-17T23:17:33.0220109Z 22: [2024-07-17T23:17:33.0207834Z T: 1100] INFO  : Identity: AzureCliCredential created.
2024-07-17T23:17:33.0221080Z 22: Successful creation does not guarantee further successful token retrieval.
2024-07-17T23:17:33.0222175Z 22: [2024-07-17T23:17:33.0208281Z T: 1100] DEBUG : Identity: ManagedIdentityCredential: Environment is not set up for the credential to be created with App Service 2019 source.
2024-07-17T23:17:33.0223265Z 22: [2024-07-17T23:17:33.0208586Z T: 1100] DEBUG : Identity: ManagedIdentityCredential: Environment is not set up for the credential to be created with App Service 2017 source.
2024-07-17T23:17:33.0224580Z 22: [2024-07-17T23:17:33.0209195Z T: 1100] DEBUG : Identity: ManagedIdentityCredential: Environment is not set up for the credential to be created with Cloud Shell source.
2024-07-17T23:17:33.0225799Z 22: [2024-07-17T23:17:33.0209686Z T: 1100] DEBUG : Identity: ManagedIdentityCredential: Environment is not set up for the credential to be created with Azure Arc source.
2024-07-17T23:17:33.0226803Z 22: [2024-07-17T23:17:33.0209942Z T: 1100] INFO  : Identity: ManagedIdentityCredential will be created with Azure Instance Metadata Service source.
2024-07-17T23:17:33.0227629Z 22: Successful creation does not guarantee further successful token retrieval.
2024-07-17T23:17:33.0228724Z 22: [2024-07-17T23:17:33.0210593Z T: 1100] INFO  : Identity: DefaultAzureCredential: Created with the following credentials: EnvironmentCredential, WorkloadIdentityCredential, AzureCliCredential, ManagedIdentityCredential.
2024-07-17T23:17:33.0229917Z 22: [2024-07-17T23:17:33.0210914Z T: 1100] INFO  : Identity: ChainedTokenCredential: Created with the following credentials: AzurePipelinesCredential, DefaultAzureCredential.
2024-07-17T23:17:33.0230696Z 22: 
2024-07-17T23:17:33.0231828Z 22:  Keyvault and HSM areSame[2024-07-17T23:17:33.0217763Z T: 1100] INFO  : HTTP Request : POST https://dev.azure.com/azure-sdk/590cfd2a-581c-4dcb-a12e-6568ce786175/_apis/distributedtask/hubs/build/plans/5eeb7511-2951-4648-b2e2-d78e2917aba4/jobs/2fc98781-9230-5004-8e4b-444d4f6ce9bd/oidctoken?api-version=7.1&serviceConnectionId=REDACTED
2024-07-17T23:17:33.0232789Z 22: authorization : REDACTED
2024-07-17T23:17:33.0233575Z 22: content-type : application/json
2024-07-17T23:17:33.0234569Z 22: user-agent : azsdk-cpp-identity/1.9.0-beta.2 (Windows Server 2022 Datacenter 6.3 20348 20348.1.amd64fre.fe_release.210507-1500)
2024-07-17T23:17:33.0235457Z 22: x-ms-client-request-id : bba3a26d-e852-4002-a58e-fafaba095c06
2024-07-17T23:17:33.0276799Z 22: [2024-07-17T23:17:33.0275089Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:17:33.0302126Z 22: [2024-07-17T23:17:33.0300427Z T: 3176] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:17:33.0311172Z 22: [2024-07-17T23:17:33.0309620Z T: 3176] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-17T23:17:54.0884587Z 22: [2024-07-17T23:17:54.0880262Z T: 3176] INFO  : Status operation: 2097152(WINHTTP_CALLBACK_STATUS_REQUEST_ERROR )
2024-07-17T23:17:54.0886420Z 22: [2024-07-17T23:17:54.0882858Z T: 3176] ERROR : Request error:  Error Code: 12002: The operation timed out. Failing API: API_SEND_REQUEST
2024-07-17T23:17:54.0888186Z 22: [2024-07-17T23:17:54.0883693Z T: 1100] ERROR : Action completed with error:  Error Code: 12002: The operation timed out.
2024-07-17T23:17:54.0889909Z 22: [2024-07-17T23:17:54.0885594Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Closing handle synchronously.
2024-07-17T23:17:54.0890931Z 22: [2024-07-17T23:17:54.0886357Z T: 1100] INFO  : Status operation: 2048(WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING )
2024-07-17T23:17:54.0891583Z 22: [2024-07-17T23:17:54.0886641Z T: 1100] DEBUG : Closing handle; completing outstanding Close request
2024-07-17T23:17:54.0892216Z 22: [2024-07-17T23:17:54.0886901Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Handle closed.
2024-07-17T23:17:54.0892896Z 22: [2024-07-17T23:17:54.0887707Z T: 1100] WARN  : HTTP Transport error: Error while waiting for a send to complete. Error Code: 12002: The operation timed out.
2024-07-17T23:17:54.0893577Z 22: [2024-07-17T23:17:54.0888263Z T: 1100] INFO  : HTTP Retry attempt #1 will be made in 640ms.
2024-07-17T23:17:54.7427107Z 22: [2024-07-17T23:17:54.7423138Z T: 1100] INFO  : HTTP Request : POST https://dev.azure.com/azure-sdk/590cfd2a-581c-4dcb-a12e-6568ce786175/_apis/distributedtask/hubs/build/plans/5eeb7511-2951-4648-b2e2-d78e2917aba4/jobs/2fc98781-9230-5004-8e4b-444d4f6ce9bd/oidctoken?api-version=7.1&serviceConnectionId=REDACTED
2024-07-17T23:17:54.7428339Z 22: authorization : REDACTED
2024-07-17T23:17:54.7429054Z 22: content-type : application/json
2024-07-17T23:17:54.7429978Z 22: user-agent : azsdk-cpp-identity/1.9.0-beta.2 (Windows Server 2022 Datacenter 6.3 20348 20348.1.amd64fre.fe_release.210507-1500)
2024-07-17T23:17:54.7431082Z 22: x-ms-client-request-id : bba3a26d-e852-4002-a58e-fafaba095c06
2024-07-17T23:17:54.7432205Z 22: [2024-07-17T23:17:54.7429195Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:17:54.7433207Z 22: [2024-07-17T23:17:54.7429859Z T: 5740] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:17:54.7434088Z 22: [2024-07-17T23:17:54.7430180Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:17:54.7469147Z 22: [2024-07-17T23:17:54.7466951Z T: 3176] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:17:54.7470099Z 22: [2024-07-17T23:17:54.7468137Z T: 3176] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-17T23:18:15.7905541Z 22: [2024-07-17T23:18:15.7902169Z T: 3176] INFO  : Status operation: 2097152(WINHTTP_CALLBACK_STATUS_REQUEST_ERROR )
2024-07-17T23:18:15.7907086Z 22: [2024-07-17T23:18:15.7903043Z T: 3176] ERROR : Request error:  Error Code: 12002: The operation timed out. Failing API: API_SEND_REQUEST
2024-07-17T23:18:15.7908157Z 22: [2024-07-17T23:18:15.7903686Z T: 1100] ERROR : Action completed with error:  Error Code: 12002: The operation timed out.
2024-07-17T23:18:15.7909137Z 22: [2024-07-17T23:18:15.7904799Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Closing handle synchronously.
2024-07-17T23:18:15.7910227Z 22: [2024-07-17T23:18:15.7905504Z T: 1100] INFO  : Status operation: 2048(WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING )
2024-07-17T23:18:15.7910990Z 22: [2024-07-17T23:18:15.7905733Z T: 1100] DEBUG : Closing handle; completing outstanding Close request
2024-07-17T23:18:15.7911663Z 22: [2024-07-17T23:18:15.7906042Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Handle closed.
2024-07-17T23:18:15.7912373Z 22: [2024-07-17T23:18:15.7906366Z T: 1100] WARN  : HTTP Transport error: Error while waiting for a send to complete. Error Code: 12002: The operation timed out.
2024-07-17T23:18:15.7913055Z 22: [2024-07-17T23:18:15.7906644Z T: 1100] INFO  : HTTP Retry attempt #2 will be made in 1730ms.
2024-07-17T23:18:17.5300266Z 22: [2024-07-17T23:18:17.5295639Z T: 1100] INFO  : HTTP Request : POST https://dev.azure.com/azure-sdk/590cfd2a-581c-4dcb-a12e-6568ce786175/_apis/distributedtask/hubs/build/plans/5eeb7511-2951-4648-b2e2-d78e2917aba4/jobs/2fc98781-9230-5004-8e4b-444d4f6ce9bd/oidctoken?api-version=7.1&serviceConnectionId=REDACTED
2024-07-17T23:18:17.5301792Z 22: authorization : REDACTED
2024-07-17T23:18:17.5302769Z 22: content-type : application/json
2024-07-17T23:18:17.5303881Z 22: user-agent : azsdk-cpp-identity/1.9.0-beta.2 (Windows Server 2022 Datacenter 6.3 20348 20348.1.amd64fre.fe_release.210507-1500)
2024-07-17T23:18:17.5305269Z 22: x-ms-client-request-id : bba3a26d-e852-4002-a58e-fafaba095c06
2024-07-17T23:18:17.5306416Z 22: [2024-07-17T23:18:17.5301601Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:18:17.5307236Z 22: [2024-07-17T23:18:17.5302213Z T: 5740] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:18:17.5307939Z 22: [2024-07-17T23:18:17.5302524Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:18:17.5332684Z 22: [2024-07-17T23:18:17.5323946Z T: 3176] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:18:17.5333711Z 22: [2024-07-17T23:18:17.5325015Z T: 3176] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-17T23:18:38.5740196Z 22: [2024-07-17T23:18:38.5734298Z T: 3176] INFO  : Status operation: 2097152(WINHTTP_CALLBACK_STATUS_REQUEST_ERROR )
2024-07-17T23:18:39.5894836Z 22: [2024-07-17T23:18:38.5735243Z T: 3176] ERROR : Request error:  Error Code: 12002: The operation timed out. Failing API: API_SEND_REQUEST
2024-07-17T23:18:39.5896620Z 22: [2024-07-17T23:18:38.5736144Z T: 1100] ERROR : Action completed with error:  Error Code: 12002: The operation timed out.
2024-07-17T23:18:39.5897992Z 22: [2024-07-17T23:18:38.5737257Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Closing handle synchronously.
2024-07-17T23:18:39.5899283Z 22: [2024-07-17T23:18:38.5737603Z T: 1100] INFO  : Status operation: 2048(WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING )
2024-07-17T23:18:39.5900384Z 22: [2024-07-17T23:18:38.5738250Z T: 1100] DEBUG : Closing handle; completing outstanding Close request
2024-07-17T23:18:39.5901377Z 22: [2024-07-17T23:18:38.5738524Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Handle closed.
2024-07-17T23:18:39.5902677Z 22: [2024-07-17T23:18:38.5738991Z T: 1100] WARN  : HTTP Transport error: Error while waiting for a send to complete. Error Code: 12002: The operation timed out.
2024-07-17T23:18:39.5903698Z 22: [2024-07-17T23:18:38.5739379Z T: 1100] INFO  : HTTP Retry attempt #3 will be made in 2869ms.
2024-07-17T23:18:41.4567053Z 22: [2024-07-17T23:18:41.4563185Z T: 1100] INFO  : HTTP Request : POST https://dev.azure.com/azure-sdk/590cfd2a-581c-4dcb-a12e-6568ce786175/_apis/distributedtask/hubs/build/plans/5eeb7511-2951-4648-b2e2-d78e2917aba4/jobs/2fc98781-9230-5004-8e4b-444d4f6ce9bd/oidctoken?api-version=7.1&serviceConnectionId=REDACTED
2024-07-17T23:18:41.4568704Z 22: authorization : REDACTED
2024-07-17T23:18:41.4569704Z 22: content-type : application/json
2024-07-17T23:18:41.4571140Z 22: user-agent : azsdk-cpp-identity/1.9.0-beta.2 (Windows Server 2022 Datacenter 6.3 20348 20348.1.amd64fre.fe_release.210507-1500)
2024-07-17T23:18:41.4572772Z 22: x-ms-client-request-id : bba3a26d-e852-4002-a58e-fafaba095c06
2024-07-17T23:18:41.4574285Z 22: [2024-07-17T23:18:41.4569515Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:18:41.4575726Z 22: [2024-07-17T23:18:41.4570597Z T: 5740] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:18:41.4576967Z 22: [2024-07-17T23:18:41.4571233Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:18:41.4594535Z 22: [2024-07-17T23:18:41.4592903Z T: 3176] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:18:41.4596468Z 22: [2024-07-17T23:18:41.4594076Z T: 3176] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-17T23:19:02.5034945Z 22: [2024-07-17T23:19:02.5031238Z T: 5740] INFO  : Status operation: 2097152(WINHTTP_CALLBACK_STATUS_REQUEST_ERROR )
2024-07-17T23:19:02.5037468Z 22: [2024-07-17T23:19:02.5032317Z T: 5740] ERROR : Request error:  Error Code: 12002: The operation timed out. Failing API: API_SEND_REQUEST
2024-07-17T23:19:02.5039272Z 22: [2024-07-17T23:19:02.5033008Z T: 1100] ERROR : Action completed with error:  Error Code: 12002: The operation timed out.
2024-07-17T23:19:02.5040861Z 22: [2024-07-17T23:19:02.5033948Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Closing handle synchronously.
2024-07-17T23:19:02.5042183Z 22: [2024-07-17T23:19:02.5034581Z T: 1100] INFO  : Status operation: 2048(WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING )
2024-07-17T23:19:02.5043329Z 22: [2024-07-17T23:19:02.5034905Z T: 1100] DEBUG : Closing handle; completing outstanding Close request
2024-07-17T23:19:02.5044316Z 22: [2024-07-17T23:19:02.5035251Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Handle closed.
2024-07-17T23:19:02.5045359Z 22: [2024-07-17T23:19:02.5035835Z T: 1100] WARN  : HTTP Transport error: Error while waiting for a send to complete. Error Code: 12002: The operation timed out.
2024-07-17T23:19:02.5046525Z 22: [2024-07-17T23:19:02.5037374Z T: 1100] DEBUG : Identity: ChainedTokenCredential: Failed to get token from AzurePipelinesCredential: GetToken(): Error while waiting for a send to complete. Error Code: 12002: The operation timed out.
2024-07-17T23:19:02.5047660Z 22: [2024-07-17T23:19:02.5037995Z T: 1100] WARN  : Identity: EnvironmentCredential authentication unavailable. See earlier EnvironmentCredential log messages for details.
2024-07-17T23:19:02.5048797Z 22: [2024-07-17T23:19:02.5038456Z T: 1100] DEBUG : Identity: DefaultAzureCredential: Failed to get token from EnvironmentCredential: EnvironmentCredential authentication unavailable. Environment variables are not fully configured.
2024-07-17T23:19:02.5049986Z 22: [2024-07-17T23:19:02.5038765Z T: 1100] WARN  : Identity: WorkloadIdentityCredential authentication unavailable. See earlier WorkloadIdentityCredential log messages for details.
2024-07-17T23:19:02.5051144Z 22: [2024-07-17T23:19:02.5039148Z T: 1100] DEBUG : Identity: DefaultAzureCredential: Failed to get token from WorkloadIdentityCredential: WorkloadIdentityCredential authentication unavailable. Azure Kubernetes environment is not set up correctly.
2024-07-17T23:21:47.3744394Z 22: [2024-07-17T23:21:47.3739279Z T: 1100] WARN  : Identity: AzureCliCredential didn't get the token: "Azure CLI process took too long to complete."
2024-07-17T23:21:47.3746589Z 22: [2024-07-17T23:21:47.3740171Z T: 1100] DEBUG : Identity: DefaultAzureCredential: Failed to get token from AzureCliCredential: AzureCliCredential didn't get the token: "Azure CLI process took too long to complete."
2024-07-17T23:21:47.3748207Z 22: [2024-07-17T23:21:47.3741112Z T: 1100] INFO  : HTTP Request : GET http://169.254.169.254/metadata/identity/oauth2/token?api-version=2018-02-01&resource=REDACTED
2024-07-17T23:21:47.3749420Z 22: metadata : REDACTED
2024-07-17T23:21:47.3750548Z 22: user-agent : azsdk-cpp-identity/1.9.0-beta.2 (Windows Server 2022 Datacenter 6.3 20348 20348.1.amd64fre.fe_release.210507-1500)
2024-07-17T23:21:47.3751889Z 22: x-ms-client-request-id : ffc852d3-4bef-41d4-885d-9d3e5b19e160
2024-07-17T23:21:47.3753074Z 22: [2024-07-17T23:21:47.3748809Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:21:47.3754084Z 22: [2024-07-17T23:21:47.3749531Z T: 5740] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:21:47.3755048Z 22: [2024-07-17T23:21:47.3750912Z T: 5740] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-17T23:21:47.3758273Z 22: [2024-07-17T23:21:47.3756257Z T: 5740] INFO  : Status operation: 8(WINHTTP_CALLBACK_STATUS_CONNECTED_TO_SERVER )
2024-07-17T23:21:47.3759291Z 22: [2024-07-17T23:21:47.3756734Z T: 5740] INFO  : Status operation: 16(WINHTTP_CALLBACK_STATUS_SENDING_REQUEST )
2024-07-17T23:21:47.3760092Z 22: [2024-07-17T23:21:47.3757300Z T: 5740] INFO  : Status operation: 32(WINHTTP_CALLBACK_STATUS_REQUEST_SENT )
2024-07-17T23:21:47.4177610Z 22: [2024-07-17T23:21:47.4175228Z T: 5740] INFO  : Status operation: 4194304(WINHTTP_CALLBACK_STATUS_SENDREQUEST_COMPLETE )
2024-07-17T23:21:47.4179665Z 22: [2024-07-17T23:21:47.4176058Z T: 1100] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-17T23:21:47.4182461Z 22: [2024-07-17T23:21:47.4176385Z T: 1100] INFO  : Status operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED )
2024-07-17T23:21:47.4183795Z 22: [2024-07-17T23:21:47.4176693Z T: 1100] INFO  : Status operation: 131072(WINHTTP_CALLBACK_STATUS_HEADERS_AVAILABLE )
2024-07-17T23:21:47.4185036Z 22: [2024-07-17T23:21:47.4177479Z T: 1100] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-17T23:21:47.4186247Z 22: [2024-07-17T23:21:47.4177896Z T: 1100] INFO  : Status operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED )
2024-07-17T23:21:47.4187464Z 22: [2024-07-17T23:21:47.4178235Z T: 1100] INFO  : Status operation: 524288(WINHTTP_CALLBACK_STATUS_READ_COMPLETE )
2024-07-17T23:21:47.4188708Z 22: [2024-07-17T23:21:47.4178573Z T: 1100] DEBUG : Read Data read from wire. Size: 2010.
2024-07-17T23:21:47.4189863Z 22: [2024-07-17T23:21:47.4179095Z T: 1100] DEBUG : ReadData returned size: 2010.
2024-07-17T23:21:47.4190959Z 22: [2024-07-17T23:21:47.4179470Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Closing handle synchronously.
2024-07-17T23:21:47.4192091Z 22: [2024-07-17T23:21:47.4179995Z T: 1100] INFO  : Status operation: 2048(WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING )
2024-07-17T23:21:47.4192806Z 22: [2024-07-17T23:21:47.4180250Z T: 1100] DEBUG : Closing handle; completing outstanding Close request
2024-07-17T23:21:47.4193546Z 22: [2024-07-17T23:21:47.4180525Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Handle closed.
2024-07-17T23:21:47.4194161Z 22: [2024-07-17T23:21:47.4181150Z T: 1100] INFO  : HTTP/1.1 Response (43ms) : 200 OK
2024-07-17T23:21:47.4194647Z 22: content-length : 2010
2024-07-17T23:21:47.4195125Z 22: content-type : application/json; charset=utf-8
2024-07-17T23:21:47.4195557Z 22: date : Wed, 17 Jul 2024 23:21:47 GMT
2024-07-17T23:21:47.4195956Z 22: server : IMDS/150.870.65.1305
2024-07-17T23:21:47.4196588Z 22: x-ms-request-id : 6c8989ec-de56-410f-ac1f-c2a1cb86df02
2024-07-17T23:21:47.4197145Z 22: [2024-07-17T23:21:47.4181423Z T: 1100] INFO  : HTTP status code 200 won't be retried.
2024-07-17T23:21:47.4197870Z 22: [2024-07-17T23:21:47.4182523Z T: 1100] INFO  : Identity: DefaultAzureCredential: Successfully got token from ManagedIdentityCredential. This credential will be reused for subsequent calls.
2024-07-17T23:21:47.4198611Z 22: [2024-07-17T23:21:47.4182827Z T: 1100] DEBUG : Identity: DefaultAzureCredential: Saved this credential at index 3 for subsequent calls.
2024-07-17T23:21:47.4199293Z 22: [2024-07-17T23:21:47.4183081Z T: 1100] INFO  : Identity: ChainedTokenCredential: Successfully got token from DefaultAzureCredential.
2024-07-17T23:21:47.4200102Z 22: [2024-07-17T23:21:47.4183606Z T: 1100] INFO  : HTTP Request : POST ***keys/DoubleDeleteBeforePollComplete/create?api-version=7.5
2024-07-17T23:21:47.4200595Z 22: authorization : REDACTED
2024-07-17T23:21:47.4201035Z 22: content-type : application/json
2024-07-17T23:21:47.4201632Z 22: user-agent : azsdk-cpp-keyvault-keys/4.5.0-beta.3 (Windows Server 2022 Datacenter 6.3 20348 20348.1.amd64fre.fe_release.210507-1500)
2024-07-17T23:21:47.4202229Z 22: x-ms-client-request-id : 02394973-593a-4c87-a557-4ded822028ee
2024-07-17T23:21:47.4202822Z 22: [2024-07-17T23:21:47.4188057Z T: 5740] INFO  : Status operation: 1(WINHTTP_CALLBACK_STATUS_RESOLVING_NAME )
2024-07-17T23:21:47.4231123Z 22: [2024-07-17T23:21:47.4228807Z T: 2620] INFO  : Status operation: 2(WINHTTP_CALLBACK_STATUS_NAME_RESOLVED )
2024-07-17T23:21:47.4232050Z 22: [2024-07-17T23:21:47.4230035Z T: 2620] INFO  : Status operation: 4(WINHTTP_CALLBACK_STATUS_CONNECTING_TO_SERVER )
2024-07-17T23:21:47.4246476Z 22: [2024-07-17T23:21:47.4244764Z T: 2620] INFO  : Status operation: 8(WINHTTP_CALLBACK_STATUS_CONNECTED_TO_SERVER )
2024-07-17T23:21:47.4363788Z 22: [2024-07-17T23:21:47.4360953Z T: 2620] INFO  : Status operation: 16(WINHTTP_CALLBACK_STATUS_SENDING_REQUEST )
2024-07-17T23:21:47.4365203Z 22: [2024-07-17T23:21:47.4361952Z T: 2620] INFO  : Status operation: 32(WINHTTP_CALLBACK_STATUS_REQUEST_SENT )
2024-07-17T23:21:47.4366393Z 22: [2024-07-17T23:21:47.4362851Z T: 5740] INFO  : Status operation: 4194304(WINHTTP_CALLBACK_STATUS_SENDREQUEST_COMPLETE )
2024-07-17T23:21:47.4367278Z 22: [2024-07-17T23:21:47.4363566Z T: 1100] INFO  : Status operation: 16(WINHTTP_CALLBACK_STATUS_SENDING_REQUEST )
2024-07-17T23:21:47.4369261Z 22: [2024-07-17T23:21:47.4367563Z T: 2620] INFO  : Status operation: 32(WINHTTP_CALLBACK_STATUS_REQUEST_SENT )
2024-07-17T23:21:47.4370573Z 22: [2024-07-17T23:21:47.4368014Z T: 2620] INFO  : Status operation: 1048576(WINHTTP_CALLBACK_STATUS_WRITE_COMPLETE )
2024-07-17T23:21:47.4371401Z 22: [2024-07-17T23:21:47.4368596Z T: 1100] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-17T23:21:47.4500449Z 22: [2024-07-17T23:21:47.4498127Z T: 2620] INFO  : Status operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED )
2024-07-17T23:21:47.4502013Z 22: [2024-07-17T23:21:47.4498533Z T: 2620] INFO  : Status operation: 131072(WINHTTP_CALLBACK_STATUS_HEADERS_AVAILABLE )
2024-07-17T23:21:47.4503578Z 22: [2024-07-17T23:21:47.4499527Z T: 1100] INFO  : Status operation: 64(WINHTTP_CALLBACK_STATUS_RECEIVING_RESPONSE )
2024-07-17T23:21:47.4505195Z 22: [2024-07-17T23:21:47.4500148Z T: 1100] INFO  : Status operation: 128(WINHTTP_CALLBACK_STATUS_RESPONSE_RECEIVED )
2024-07-17T23:21:47.4506582Z 22: [2024-07-17T23:21:47.4500484Z T: 1100] INFO  : Status operation: 524288(WINHTTP_CALLBACK_STATUS_READ_COMPLETE )
2024-07-17T23:21:47.4507698Z 22: [2024-07-17T23:21:47.4500938Z T: 1100] DEBUG : Read Data read from wire. Size: 439.
2024-07-17T23:21:47.4508932Z 22: [2024-07-17T23:21:47.4501325Z T: 1100] DEBUG : ReadData returned size: 439.
2024-07-17T23:21:47.4509999Z 22: [2024-07-17T23:21:47.4501642Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Closing handle synchronously.
2024-07-17T23:21:47.4511150Z 22: [2024-07-17T23:21:47.4502122Z T: 1100] INFO  : Status operation: 2048(WINHTTP_CALLBACK_STATUS_HANDLE_CLOSING )
2024-07-17T23:21:47.4512382Z 22: [2024-07-17T23:21:47.4502434Z T: 1100] DEBUG : Closing handle; completing outstanding Close request
2024-07-17T23:21:47.4513408Z 22: [2024-07-17T23:21:47.4502766Z T: 1100] INFO  : WinHttpRequest::~WinHttpRequest. Handle closed.
2024-07-17T23:21:47.4514329Z 22: [2024-07-17T23:21:47.4503351Z T: 1100] INFO  : HTTP/1.1 Response (31ms) : 403 Forbidden
2024-07-17T23:21:47.4515081Z 22: cache-control : no-cache
2024-07-17T23:21:47.4515802Z 22: content-length : 439
2024-07-17T23:21:47.4516461Z 22: content-type : application/json; charset=utf-8
2024-07-17T23:21:47.4517069Z 22: date : Wed, 17 Jul 2024 23:21:47 GMT
2024-07-17T23:21:47.4518084Z 22: expires : -1
2024-07-17T23:21:47.4518860Z 22: pragma : no-cache
2024-07-17T23:21:47.4519685Z 22: strict-transport-security : REDACTED
2024-07-17T23:21:47.4520513Z 22: x-content-type-options : REDACTED
2024-07-17T23:21:47.4521398Z 22: x-ms-client-request-id : 02394973-593a-4c87-a557-4ded822028ee
2024-07-17T23:21:47.4522366Z 22: x-ms-keyvault-network-info : REDACTED
2024-07-17T23:21:47.4523144Z 22: x-ms-keyvault-region : REDACTED
2024-07-17T23:21:47.4523932Z 22: x-ms-keyvault-service-version : REDACTED
2024-07-17T23:21:47.4524777Z 22: x-ms-request-id : 8779f4db-c64e-47d4-8f78-3e88a2b0fc49
2024-07-17T23:21:47.4525693Z 22: [2024-07-17T23:21:47.4504024Z T: 1100] INFO  : HTTP status code 403 won't be retried.
2024-07-17T23:21:47.4526932Z 22: unknown file: error: C++ exception with description "Received an HTTP unsuccessful status code: 403 Reason: Forbidden" thrown in the test body.
2024-07-17T23:21:47.4528156Z 22: [  FAILED  ] KeyVaultKeyClient.DoubleDeleteBeforePollComplete (254436 ms)

ahsonkhan avatar Jul 18 '24 07:07 ahsonkhan