Azure-sdk-for-net: [Azure Search]SearchIndexerClient.RunIndexerAsync() not robust in China cloud

[XuGuang-Yao]

We are running live Tests against other clouds like US Gov and Azure China Cloud. The goal is to check whether new azure sdk package work with other clouds or not.

Below exception will be thrown when running test CreateAzureBlobIndexer. This error happened around 5 times in 10.

Stack Trace: 
    ValueTask`1.get_Result()
    HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
    RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
    HttpClientTransport.ProcessAsync(HttpMessage message)
    RequestActivityPolicy.ProcessNextAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean isAsync)
    RequestActivityPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean isAsync)
    ResponseBodyPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
    ResponseBodyPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline)
    LoggingPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
    LoggingPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline)
    RetryPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
    RetryPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
    HttpPipelineSynchronousPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline)
    HttpPipelineSynchronousPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline)
    HttpPipelineSynchronousPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline)
    HttpPipelineSynchronousPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline)
    IndexersRestClient.GetStatusAsync(String indexerName, CancellationToken cancellationToken) line 650
    SearchIndexerClient.GetIndexerStatusAsync(String indexerName, CancellationToken cancellationToken) line 1092
    SearchTestBase.WaitForIndexingAsync(SearchIndexerClient client, String indexerName, Nullable`1 timeout) line 202
    SearchIndexerClientTests.CreateAzureBlobIndexer() line 96

Code snippet:

@jongio @danieljurek for notification.

[msftbot[bot]]

Thanks for the feedback! We are routing this to the appropriate team for follow-up. cc @brjohnstmsft, @bleroy, @tjacobhi, @markheff, @miwelsh.

[heaths]

With the connection to local host, it almost seems as if it's trying to use MSI. @schaabs what do you think?

It really shouldn't be trying, though. Environment credentials - what the test harness sets - should be used first: https://github.com/Azure/azure-sdk-for-net/blob/a0c71310257bf563f850b3ad5b982da0a1491539/sdk/identity/Azure.Identity/src/DefaultAzureCredential.cs#L168-L176. Can you share via email a link to the run and/or whole log output for further diagnostics?

[schaabs]

It's possible that the call to 127.0.0.1:9998 is coming from the ManagedIdentityCredential. The DefaultAzureCredential would have only used the ManagedIdentityCredential if the EnvironmentCredential did not have a full set of environment variables set (i.e. AZURE_CLIENT_ID, AZURE_TENANT_ID and AZURE_CLIENT_SECRET or AZURE_CLIENT_CERTIFICATE_PATH. @XuGuang-Yao can you provide the callstack for the exception to confirm it's coming from ManagedIdentityCredential?

[XuGuang-Yao]

@schaabs Updated the callstack. Here is the link of pipeline.
https://dev.azure.com/azure-sdk/internal/_build/results?buildId=476203&view=ms.vss-test-web.build-test-results-tab&runId=12285440&resultId=100536&paneView=debug

[heaths]

Thanks. From the diagnostic log, I see:

Transient error: Error processing blob 'https://t7c2f88d4ece34723stg.blob.core.chinacloudapi.cn/snaxwqtn/1': No connection could be made because the target machine actively refused it 127.0.0.1:9998
5bc751d3-2125-421d-a558-2c22d5e998d3
  method: GET
  uri: https://azs-net-t7c2f88d4ece34723.search.azure.cn/indexers('qifpqwhr')/search.status?api-version=2020-06-30
  headers: 
    Accept:application/json; odata.metadata=minimal
    api-key:REDACTED
    x-ms-client-request-id:5bc751d3-2125-421d-a558-2c22d5e998d3
    x-ms-return-client-request-id:true
    User-Agent:azsdk-net-Search.Documents/11.1.0-dev.20200728.2,(.NET Core 4.6.27514.02; Microsoft Windows 10.0.17763 )
  clientAssembly: Azure.Search.Documents

Given the stack trace, this doesn't appear to be anything related to Identity.

The full stack trace from the TRX shows this is just trying to get status, so it is indeed Search having a transient error trying to communicate with Blob Storage:

System.Threading.Tasks.ValueTask`1.get_Result()
System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean doRequestAuth, CancellationToken cancellationToken)
System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
System.Net.Http.HttpClient.FinishSendAsyncUnbuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
Azure.Core.Pipeline.HttpClientTransport.ProcessAsync(HttpMessage message)
Azure.Core.Pipeline.HttpClientTransport.Process(HttpMessage message)
Azure.Core.Pipeline.HttpPipelineTransportPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.RequestActivityPolicy.ProcessNextAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean isAsync)
Azure.Core.Pipeline.TaskExtensions.EnsureCompleted(ValueTask task)
Azure.Core.Pipeline.RequestActivityPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean isAsync)
Azure.Core.Pipeline.TaskExtensions.EnsureCompleted(ValueTask task)
Azure.Core.Pipeline.RequestActivityPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.ResponseBodyPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
Azure.Core.Pipeline.TaskExtensions.EnsureCompleted(ValueTask task)
Azure.Core.Pipeline.ResponseBodyPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.LoggingPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
Azure.Core.Pipeline.TaskExtensions.EnsureCompleted(ValueTask task)
Azure.Core.Pipeline.LoggingPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.RetryPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
Azure.Core.Pipeline.RetryPolicy.ProcessAsync(HttpMessage message, ReadOnlyMemory`1 pipeline, Boolean async)
Azure.Core.Pipeline.TaskExtensions.EnsureCompleted(ValueTask task)
Azure.Core.Pipeline.RetryPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelineSynchronousPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelineSynchronousPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelineSynchronousPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelinePolicy.ProcessNext(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipelineSynchronousPolicy.Process(HttpMessage message, ReadOnlyMemory`1 pipeline)
Azure.Core.Pipeline.HttpPipeline.Send(HttpMessage message, CancellationToken cancellationToken)
Azure.Search.Documents.IndexersRestClient.GetStatus(String indexerName, CancellationToken cancellationToken)
Azure.Search.Documents.Indexes.SearchIndexerClient.GetIndexerStatus(String indexerName, CancellationToken cancellationToken)
Azure.Search.Documents.Tests.SearchTestBase.WaitForIndexingAsync(SearchIndexerClient client, String indexerName, Nullable`1 timeout) in D:\a\1\s\sdk\search\Azure.Search.Documents\tests\Utilities\SearchTestBase.cs: line 202
Azure.Search.Documents.Tests.SearchIndexerClientTests.CreateAzureBlobIndexer() in D:\a\1\s\sdk\search\Azure.Search.Documents\tests\SearchIndexerClientTests.cs: line 96
Azure.Search.Documents.Tests.SearchIndexerClientTests.CreateAzureBlobIndexer() in D:\a\1\s\sdk\search\Azure.Search.Documents\tests\SearchIndexerClientTests.cs: line 110
NUnit.Framework.Internal.TaskAwaitAdapter.GenericAdapter`1.BlockUntilCompleted() in D:\a\1\s\src\NUnitFramework\framework\Internal\TaskAwaitAdapter.cs: line 95
NUnit.Framework.Internal.AsyncToSyncAdapter.Await(Func`1 invoke) in D:\a\1\s\src\NUnitFramework\framework\Internal\AsyncToSyncAdapter.cs: line 60
NUnit.Framework.Internal.Commands.TestMethodCommand.Execute(TestExecutionContext context) in D:\a\1\s\src\NUnitFramework\framework\Internal\Commands\TestMethodCommand.cs: line 64
NUnit.Framework.Internal.Commands.BeforeAndAfterTestCommand.<>c__DisplayClass1_0.<Execute>b__0() in D:\a\1\s\src\NUnitFramework\framework\Internal\Commands\BeforeAndAfterTestCommand.cs: line 58
NUnit.Framework.Internal.Commands.BeforeAndAfterTestCommand.RunTestMethodInThreadAbortSafeZone(TestExecutionContext context, Action action) in D:\a\1\s\src\NUnitFramework\framework\Internal\Commands\BeforeAndAfterTestCommand.cs: line 73

@brjohnstmsft is this something the service team should look at?

[brjohnstmsft]

This error is part of the indexer flow, so I defer to @bleroy on this.

It is very strange that an indexer would be trying to reach Blob storage via 127.0.0.1:9998 though.

[bleroy]

It doesn't seem to me like this has anything to do with the SDK. Looks like you;d have a better change by opening an IcM.

[brjohnstmsft]

I disagree that this merits opening a live-site incident. More likely it's a configuration issue with the live tests. @heaths @tg-msft Who wrote the test code above and might know where the value of resources.StorageAccountConnectionString comes from?

[heaths]

I did. It's hardcoded, which I did before we started actually running in other clouds: https://github.com/Azure/azure-sdk-for-net/blob/5079b87d141889e3dbe6e9f7dfb7d25900b74a91/sdk/search/Azure.Search.Documents/tests/Utilities/SearchResources.cs#L59. Odd that it only happens "around 5 times in 10", and why localhost?

I can change that in conjunction with the work @jsquire is doing now when it's ready, and if you think that could be the problem. We run in other clouds, though, too, and no mention of it failing. How sure are you this could be the problem (I mean, it seems likely - but I would think it'd fail 100% of the time). Could we check server diagnostics for request ID 5bc751d3-2125-421d-a558-2c22d5e998d3 (above; there's lots of others in the run TRX if needed).

[brjohnstmsft]

I pattern matched this to indexer status messages I've seen in the past:

Transient error: Error processing blob 'https://t7c2f88d4ece34723stg.blob.core.chinacloudapi.cn/snaxwqtn/1': No connection could be made because the target machine actively refused it 127.0.0.1:9998
5bc751d3-2125-421d-a558-2c22d5e998d3

But now I'm not sure if this was part of the response payload, or from somewhere else. I'll engage the indexer on-call to investigate.

[jsquire]

I did. It's hardcoded, which I did before we started actually running in other clouds:

I can change that in conjunction with the work @jsquire is doing now when it's ready, and if you think that could be the problem.

The changes to the Test Resources script and Azure Core were both merged this morning. I'm not sure whether the tools repository sync has been completed.

[heaths]

Using the right cloud endpoint is definitely a good idea, so I want to keep this issue open to track that work; however, @XuGuang-Yao, have you had any recent failures? We believe we identified a service configuration issue that should now be fixed.

[XuGuang-Yao]

@heaths Here is the newest result. The error still persists.
https://dev.azure.com/azure-sdk/internal/_build/results?buildId=476203&view=ms.vss-test-web.build-test-results-tab&runId=12338448&resultId=100227&paneView=debug

[XuGuang-Yao]

@heaths - The test passed in latest pipeline run.
https://dev.azure.com/azure-sdk/internal/_build/results?buildId=490107&view=results