AddDaprSecretStore Extension always throws unhandled exception at container start #779

bgelens · 2021-11-11T11:35:14Z

Expected Behavior

Using AddDaprSecretStore extension will not throw an exception when the side car is not ready yet

Actual Behavior

It throws an unhandled exception crashing my pod. On restart, it goes through fine

Unhandled exception. Dapr.DaprException: Bulk secret operation failed: the Dapr endpoint indicated a failure. See InnerException for details.
 ---> Grpc.Core.RpcException: Status(StatusCode="Internal", Detail="Error starting gRPC call. HttpRequestException: Connection refused (127.0.0.1:50001) SocketException: Connection refused", DebugException="System.Net.Http.HttpRequestException: Connection refused (127.0.0.1:50001)
 ---> System.Net.Sockets.SocketException (111): Connection refused
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|283_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.DefaultConnectAsync(SocketsHttpConnectionContext context, CancellationToken cancellationToken)
   at System.Net.Http.ConnectHelper.ConnectAsync(Func`3 callback, DnsEndPoint endPoint, HttpRequestMessage requestMessage, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.ConnectHelper.ConnectAsync(Func`3 callback, DnsEndPoint endPoint, HttpRequestMessage requestMessage, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.GetHttp2ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout)")
   at Dapr.Client.DaprClientGrpc.GetBulkSecretAsync(String storeName, IReadOnlyDictionary`2 metadata, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at Dapr.Client.DaprClientGrpc.GetBulkSecretAsync(String storeName, IReadOnlyDictionary`2 metadata, CancellationToken cancellationToken)
   at Dapr.Extensions.Configuration.DaprSecretStore.DaprSecretStoreConfigurationProvider.LoadAsync()
   at Dapr.Extensions.Configuration.DaprSecretStore.DaprSecretStoreConfigurationProvider.Load()
   at Microsoft.Extensions.Configuration.ConfigurationRoot..ctor(IList`1 providers)
   at Microsoft.Extensions.Configuration.ConfigurationBuilder.Build()
   at Microsoft.AspNetCore.Hosting.WebHostBuilder.BuildCommonServices(AggregateException& hostingStartupErrors)
   at Microsoft.AspNetCore.Hosting.WebHostBuilder.Build()
   at MyApp.Program.Main(String[] args) in /MyApp/Program.cs:line 18

Steps to Reproduce the Problem

Dapr 1.4 running in Kubernetes with a dotnet 5 webapi app.

public static IWebHostBuilder CreateWebHostBuilder(string[] args) => WebHost.CreateDefaultBuilder(args).ConfigureAppConfiguration(config =>
{
  var daprClient = new DaprClientBuilder().Build();
  config.AddDaprSecretStore(KeyvaultStoreName, daprClient);
}).UseStartup<Startup>();

Release Note

RELEASE NOTE:

The text was updated successfully, but these errors were encountered:

halspang · 2021-11-12T19:26:13Z

We can now try and hit dapr with retries inside the configuration builder, which can stop this. I can also investigate calling the dapr healthcheck api and proceeding one it is complete. I'll only do that if I can verify that there is no potential for deadlock between the two starting systems.

harvendra2022 · 2022-01-13T19:47:19Z

We have started using Dapr in Microservices written .Net 6 and using DaprSecretStore to get the secretes from Azure Key Vault. It would be great if this issue can be fixed at the earliest? Is there any tentative timeline for the fix?

niclasrothman · 2022-02-10T16:57:44Z

Hi there, any updates about this issue, will it make to the next 1.7 milestone?
This issue are really troublesome for our team.

halspang · 2022-02-10T17:02:39Z

Hi there, any updates about this issue, will it make to the next 1.7 milestone? This issue are really troublesome for our team.

Yes, it is in 1.7. I'm planning on getting it done sometime before the release.

niclasrothman · 2022-02-10T17:06:45Z

That's just fantastic news!!! Any recommendation to overcome this problem meanwhile?
We are trying to wait on dapr to be ready by asking dapr for it's health but doesnt really seem to work;

`

public class Program
{
public static async Task Main(string[] args)
{
var host = CreateHostBuilder(args).Build();

        // Use startup logging as described here: https://docs.microsoft.com/en-us/azure/azure-monitor/app/ilogger
        var logger = host.Services.GetRequiredService<ILogger<Program>>();
        logger.LogInformation("Starting application, please hold tight");

        // Create Dapr client:
        var client = new DaprClientBuilder()
            .Build();

        int counter = 1;
        var isDaprReady = await client.CheckHealthAsync();

        while (!isDaprReady && counter < 20)
        {
            logger.LogInformation("Dapr detected not to be ready, sleeping");
            await Task.Delay(100);

            isDaprReady = await client.CheckHealthAsync();
            counter++;
        }

        host.Run();
    }

    public static IHostBuilder CreateHostBuilder(string[] args)
    {
        // Create Dapr client:
        var client = new DaprClientBuilder()
            .Build();

        return Host.CreateDefaultBuilder(args)
                .ConfigureWebHostDefaults(webBuilder => { webBuilder.UseStartup<Startup>(); })
                .ConfigureLogging((context, builder) =>
                {
                    // Providing an instrumentation key is required if you're using the
                    // standalone Microsoft.Extensions.Logging.ApplicationInsights package,
                    // or when you need to capture logs during application startup, such as
                    // in Program.cs or Startup.cs itself.
                    builder.AddApplicationInsights(context.Configuration["ApplicationInsights:Key"]);

                    // Capture all log-level entries from Program
                    builder.AddFilter<ApplicationInsightsLoggerProvider>(
                        typeof(Program).FullName, LogLevel.Trace);

                    // Capture all log-level entries from Startup
                    builder.AddFilter<ApplicationInsightsLoggerProvider>(
                        typeof(Startup).FullName, LogLevel.Trace);
                })
                .ConfigureServices((services) =>
                {
                    // Add the DaprClient to DI.
                    services.AddSingleton(client);
                })
                .ConfigureAppConfiguration(config =>
                {
                    // Add secrets via Dapr, https://docs.microsoft.com/en-us/dotnet/architecture/dapr-for-net-developers/secrets-management
                    // Example here: https://github.com/dapr/dotnet-sdk/blob/master/examples/AspNetCore/SecretStoreConfigurationProviderSample/Program.cs
                    // Issue around separators: https://github.com/dapr/dotnet-sdk/issues/627
                    config.AddDaprSecretStore("localities-service-secret-store", client, new[] { "--", ":" });
                })
            ;
    }
}

`

halspang · 2022-02-10T17:09:28Z

Are you getting an error for the client? Or is it just returning false? Do you see any logs from the dapr sidecar indicating any progress?

niclasrothman · 2022-02-10T17:15:45Z

Im starting my API project in a docker-compose file and when we are using the dapr secretstore as above I see the following in the dapr sidecar of the failing api:

time="2022-02-10T17:11:46.679314Z" level=info msg="starting Dapr Runtime -- version edge -- commit f70d69083522d56072f6af4ab230f2bddf7c9496" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6793457Z" level=info msg="log level set to: debug" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6794135Z" level=info msg="metrics server started on :9090/" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.metrics type=log ver=edge
time="2022-02-10T17:11:46.6894956Z" level=debug msg="No Access control policy specified" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.acl type=log ver=edge
time="2022-02-10T17:11:46.6895418Z" level=info msg="standalone mode configured" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6895492Z" level=info msg="app id: localities-service-api" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6896507Z" level=info msg="mTLS is disabled. Skipping certificate request and tls validation" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6901537Z" level=info msg="local service entry announced: localities-service-api -> 172.17.0.3:37681" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.contrib type=log ver=edge
time="2022-02-10T17:11:46.6902378Z" level=info msg="Initialized name resolution to mdns" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6903888Z" level=info msg="loading components" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6952537Z" level=debug msg="found component. name: localities-service-secret-store, type: secretstores.local.file/v1" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.695317Z" level=info msg="waiting for all outstanding components to be processed" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6953749Z" level=debug msg="loading component. name: localities-service-secret-store, type: secretstores.local.file/v1" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6971632Z" level=info msg="component loaded. name: localities-service-secret-store, type: secretstores.local.file/v1" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6972372Z" level=info msg="all outstanding components processed" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6973216Z" level=info msg="gRPC proxy enabled" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6975396Z" level=info msg="enabled gRPC tracing middleware" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime.grpc.api type=log ver=edge
time="2022-02-10T17:11:46.6977737Z" level=info msg="API gRPC server is running on port 50001" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6981547Z" level=info msg="enabled tracing http middleware" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime.http type=log ver=edge
time="2022-02-10T17:11:46.6983221Z" level=info msg="http server is running on port 3500" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.698453Z" level=info msg="The request body size parameter is: 4" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6984941Z" level=info msg="enabled gRPC tracing middleware" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime.grpc.internal type=log ver=edge
time="2022-02-10T17:11:46.6986316Z" level=info msg="internal gRPC server is running on port 37681" app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:11:46.6986613Z" level=info msg="application protocol: http. waiting on port 80.  This will block until the app is listening on that port." app_id=localities-service-api instance=fd7a68d03068 scope=dapr.runtime type=log ver=edge
time="2022-02-10T17:12:16.6902983Z" level=debug msg="Refreshing all mDNS addresses." app_id=localities-service-api instance=fd7a68d03068 scope=dapr.contrib type=log ver=edge
time="2022-02-10T17:12:16.6903656Z" level=debug msg="no mDNS apps to refresh." app_id=localities-service-api instance=fd7a68d03068 scope=dapr.contrib type=log ver=edge

And in the API logs I see the following:

Executing task: docker logs --tail 1000 -f 3f9499bb85c003f29b2e6630de633499256cdfa7cf0560c3a52c709243c697c4 <

Unhandled exception. Dapr.DaprException: Bulk secret operation failed: the Dapr endpoint indicated a failure. See InnerException for details.
 ---> Grpc.Core.RpcException: Status(StatusCode="Internal", Detail="Error starting gRPC call. HttpRequestException: Connection refused (127.0.0.1:50001) SocketException: Connection refused", DebugException="System.Net.Http.HttpRequestException: Connection refused (127.0.0.1:50001)
 ---> System.Net.Sockets.SocketException (111): Connection refused
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|283_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.DefaultConnectAsync(SocketsHttpConnectionContext context, CancellationToken cancellationToken)
   at System.Net.Http.ConnectHelper.ConnectAsync(Func`3 callback, DnsEndPoint endPoint, HttpRequestMessage requestMessage, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.ConnectHelper.ConnectAsync(Func`3 callback, DnsEndPoint endPoint, HttpRequestMessage requestMessage, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.GetHttp2ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at Grpc.Net.Client.Internal.GrpcCall`2.RunCall(HttpRequestMessage request, Nullable`1 timeout)")
   at Dapr.Client.DaprClientGrpc.GetBulkSecretAsync(String storeName, IReadOnlyDictionary`2 metadata, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at Dapr.Client.DaprClientGrpc.GetBulkSecretAsync(String storeName, IReadOnlyDictionary`2 metadata, CancellationToken cancellationToken)
   at Dapr.Extensions.Configuration.DaprSecretStore.DaprSecretStoreConfigurationProvider.LoadAsync()
   at Dapr.Extensions.Configuration.DaprSecretStore.DaprSecretStoreConfigurationProvider.Load()
   at Microsoft.Extensions.Configuration.ConfigurationRoot..ctor(IList`1 providers)
   at Microsoft.Extensions.Configuration.ConfigurationBuilder.Build()
   at Microsoft.Extensions.Hosting.HostBuilder.BuildAppConfiguration()
   at Microsoft.Extensions.Hosting.HostBuilder.Build()
   at X.LocalitiesService.Api.Program.Main(String[] args) in /src/Api/Program.cs:line 20
   at X.LocalitiesService.Api.Program.<Main>(String[] args)

And here the relevant part of the docker-compose file!:

  localities-elasticsearch:
    image: docker.elastic.co/elasticsearch/elasticsearch:7.10.0
    container_name: "localities-elasticsearch"     
    environment:
      - xpack.security.enabled=false
      - discovery.type=single-node
    ulimits:
      memlock:
        soft: -1
        hard: -1
      nofile:
        soft: 65536
        hard: 65536
    cap_add:
      - IPC_LOCK
    volumes:
      - ./localities-service-data/ElasticSearch:/usr/share/elasticsearch/data      
    ports:
      - 9200:9200
      - 9310:9310

  localities-api:
    #image: samfundetregistry.azurecr.io/localities-api:latest
    image: localities-service-api:local
    environment:
      - ASPNETCORE_ENVIRONMENT=Development
      - ASPNETCORE_URLS=http://+:80
      - SearchSettings__SearchServiceUri=http://localities-elasticsearch:9200
      - SearchSettings__Username=blank_in_localhost
    ports:
      - "3201:80"
      - "50002:50001"    
    depends_on:
       - localities-elasticsearch

  localities-api-dapr:    
    image: daprio/daprd:edge
    network_mode: "service:localities-api"
    command: ["./daprd",
      "-app-id", "localities-service-api",
      "-app-port", "80",
      "-log-level", "debug",
      "-components-path", "/components",
      "-config", "/configuration/dapr.config.yaml"      
      ]
    volumes:
      - "./localities-service/src/Dapr/components/:/components"
      - "./localities-service/src/Dapr/configuration/:/configuration"
    depends_on:
      - localities-api

Appreciating that you are taking time to help!!!

halspang · 2022-02-11T00:28:56Z

I see that the secret store is loaded in Dapr, so it's interesting that you're still having a problem with it given the wait. I'll try and prioritize this and see if I can't figure out what's up.

halspang · 2022-02-11T00:59:25Z

@niclasrothman - So I tried this myself and got a similar result. Before my app is ready, the health check fails. However, even with the failing health check, I was able to fetch the secrets. Looking into the Dapr runtime, here's what's happening:

Dapr runtime starts initialization
Dapr inits components
Dapr inits APIs
Dapr blocks waiting for your app
Dapr inits actors/starts subscriptions
Dapr marks API as ready

You can see, the dapr runtime isn't "ready" until your app is also ready. This is technically false, but it's how things are now. I'm going to see if the runtime is open to exposing yet another healthz endpoint. This time, it'd be for components. So like a healthz/components similar to the existing healthz/outbound.

halspang · 2022-02-11T01:03:06Z

Actually, healthz/outbound is already marked as ready before it blocks on the app. I'll just use that since it already exists :)

The secret store configuration provider was trying to access Dapr during the app startup. If the app started faster than Dapr, it would get an error trying to access the secrets. This commit lets the provider wait for the sidecar to come up before making any requests. If the sidecar does not come up at all, we will still fail. dapr#779 Signed-off-by: Hal Spang <halspang@microsoft.com>

The secret store configuration provider was trying to access Dapr during the app startup. If the app started faster than Dapr, it would get an error trying to access the secrets. This commit lets the provider wait for the sidecar to come up before making any requests. If the sidecar does not come up at all, we will still fail. #779 Signed-off-by: Hal Spang <halspang@microsoft.com>

bgelens added the kind/bug Something isn't working label Nov 11, 2021

halspang added this to the v1.6 milestone Nov 12, 2021

ajaysingh77 mentioned this issue Dec 9, 2021

docker-compose up is not working dotnet-architecture/eShopOnDapr#67

Closed

amolenk mentioned this issue Jan 12, 2022

Kubernetes Cluster setup not working properly dotnet-architecture/eShopOnDapr#75

Closed

halspang modified the milestones: v1.6, Future Jan 13, 2022

halspang modified the milestones: Future, v1.7 Jan 24, 2022

halspang mentioned this issue Feb 15, 2022

Wait for sidecar in DaprSecretStoreConfiguration #838

Merged

3 tasks

halspang closed this as completed in #838 Feb 18, 2022

juris-greitans mentioned this issue Dec 9, 2022

Dapr.Extensions.Configuration.AddDaprSecretStore() fails if the sidecar and app are started separately #993

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

AddDaprSecretStore Extension always throws unhandled exception at container start #779

AddDaprSecretStore Extension always throws unhandled exception at container start #779

bgelens commented Nov 11, 2021

halspang commented Nov 12, 2021

harvendra2022 commented Jan 13, 2022 •

edited

Loading

niclasrothman commented Feb 10, 2022

halspang commented Feb 10, 2022

niclasrothman commented Feb 10, 2022

halspang commented Feb 10, 2022

niclasrothman commented Feb 10, 2022 •

edited

Loading

halspang commented Feb 11, 2022

halspang commented Feb 11, 2022

halspang commented Feb 11, 2022

AddDaprSecretStore Extension always throws unhandled exception at container start #779

AddDaprSecretStore Extension always throws unhandled exception at container start #779

Comments

bgelens commented Nov 11, 2021

Expected Behavior

Actual Behavior

Steps to Reproduce the Problem

Release Note

halspang commented Nov 12, 2021

harvendra2022 commented Jan 13, 2022 • edited Loading

niclasrothman commented Feb 10, 2022

halspang commented Feb 10, 2022

niclasrothman commented Feb 10, 2022

halspang commented Feb 10, 2022

niclasrothman commented Feb 10, 2022 • edited Loading

halspang commented Feb 11, 2022

halspang commented Feb 11, 2022

halspang commented Feb 11, 2022

harvendra2022 commented Jan 13, 2022 •

edited

Loading

niclasrothman commented Feb 10, 2022 •

edited

Loading