search

dapr / dotnet-sdk

Dapr SDK for .NET
Apache License 2.0
1.11k stars 333 forks source link

Service Invocation not working as Expected, Error invoking method: 'XXXX' on app-id: 'uploader' #971

Closed iamsourabh-in closed 1 year ago

iamsourabh-in commented 1 year ago

Expected Behavior

I have Two Service Processor and Uploader. Processor Service can reach out to uploader for getting any service details.

The Processor Service should be able to invoke method in Uploader Service

Actual Behavior

Getting an error after trying Multiple Routes and Scenarios. Processor Service is unable to Invoke any method in Uploader Service

An exception occurred while invoking method: 'uploads' on app-id: 'uploader'

Steps to Reproduce the Problem

Enable Dapr:

dapr init

The Uploader Service has an endpoint http://<host>:<port>/uploads

 [ApiController]
 [Route("[controller]")]
 public class UploadsController : ControllerBase
 {
    [HttpGet]
    public async Task<IActionResult> GetAll()
    {
        var response = await _storageService.GetAllVideos(new Services.Models.GetAllVideosRequestModel(){
          BucketName = "*****",
          BucketFolder ="****"   
        });
        return Ok(response);
     }
  }

// output
{
    "videos": [
        {
            "lastModified": "2022-10-09T00:03:17+05:30",
            "size": 3288367,
            "key": "files/4303ckbt.cil.mp4"
        },
        {
            "lastModified": "2022-10-08T22:11:26+05:30",
            "size": 3288367,
            "key": "filesubpmk1a3.hwd.mp4"
        }
    ]
}

Also, Note, calling directly through postman the dapr endpoint do return the response. It's only the App not able to call

image

The code for Processor Service to invoke the uploader service which gives an error:

 try
 {             
   CancellationTokenSource source = new CancellationTokenSource();
   var videos = await _daprClient.InvokeMethodAsync<UploadApiVideoModel>(HttpMethod.Get,"uploader", "uploads", source.Token);
   _logger.LogInformation("Video" + videos.Videos[0].Key);

 }
 catch (System.Exception ex)
 {
    _logger.LogInformation(" Calling Error " + ex.Message);
  }

Now for running it locally:

Uploader Service

dapr run --app-port 2000 --app-id uploader --app-protocol http --dapr-http-port 2500 --components-path ../../dapr/components -- dotnet run

Processor Service

dapr run --app-port 3000 --app-id processor --app-protocol http --dapr-http-port 3500 --components-path ../../dapr/components -- dotnet run

Exception Received in Processor service

image

Other Details

I also tried using the CreateInvokeHttpClient Method in dapr.

var httpClient = DaprClient.CreateInvokeHttpClient("uploader");
await httpClient.PostAsJsonAsync("/uploads");

I also tried enabling mtls and then try with --app-ssl still no luck.

I also tried it running in K8s still no luck.

Few Version details

.Net Core: net6.0 Dapr on Docker Dapr nuget Client : 1.9.0 K8 cluster using Docker Desktop System : Windwos 11

Thanks

halspang commented 1 year ago

Do you see any indication that the uploader app is receiving a request? Or is it failing to even get there? Also, can you print the inner exception, if there is one?

How are you constructing your DaprClient? Given that you're running locally, most of that setup should just work out of the box.

I'd also takea a look at your model class. Perhaps the json deserialization is causing problems?

iamsourabh-in commented 1 year ago

No, I am not able to see any logs showing any indication for the same. Also, tried with log level=debug, uploader still shows no sign of invocation.

DaprClient Initialize in Program.cs

builder.Services.AddControllers().AddDapr();

The Model Class looks like this:

    public class UploadApiVideoModel
    {
        public List<VideoModel> Videos;
    }

    public class VideoModel
    {
        public DateTime LastModified { get; set; }
        public long Size { get; set; }
        public string Key { get; set; }

    }

// Invocation
       private readonly DaprClient _daprClient;

        public ProcessorController(
            DaprClient daprClient
        )
        {
            _daprClient = daprClient;
        }

 public async Task<IActionResult> Get([FromQuery] string key, [FromQuery] string bucketName)
        {
         var videos = await _daprClient.InvokeMethodAsync<UploadApiVideoModel>(HttpMethod.Get,"uploader", "/uploads", source.Token); 
...
halspang commented 1 year ago

@iamsourabh-in - This may be a shot in the dark here, but I wonder if you have your ports backwards for your uploader app.

I noticed in the postman call that you were hitting localhost:2500/uploads. That's the direct app endpoint, not the Dapr one. In your run command, you have --app-port 2000 --dapr-http-port 2500. Is it possible those should be reversed?

If it's not that, I may need the code to debug it more. If you can't give that, the full logs you get from Dapr when you run it would be great too.

iamsourabh-in commented 1 year ago

@halspang - I might have miss understood it, but I am under an impression, this is the port which dapr side car is running,

For Uploader Service the GET /uploads endpoint can be invoke it via two ways

http://localhost:2500/v1.0/invoke/uploader/method/uploads

#OR (below was the way i used in teh screenshot above)

curl --location --request GET 'http://localhost:2500/uploads' \
--header 'dapr-app-id: uploader'

Logs

Processor Service

== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==       3288367
== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==       08-10-2022 18:33:17
== APP == info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
== APP ==       Executing OkObjectResult, writing value of type 'Processor.Api.Services.Models.GetVideoDetailsResponseModel'.
== APP == info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
== APP ==       Executed action Processor.Api.Controllers.ProcessorController.Get (Processor.Api) in 34916.6472ms
== APP == info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
== APP ==       Executed endpoint 'Processor.Api.Controllers.ProcessorController.Get (Processor.Api)'
== APP == info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
== APP ==       Request finished HTTP/1.1 GET http://localhost:3000/Processor?key=files/4303ckbt.cil.mp4&bucketName=evolution-video-uploads application/json 32 - 200 - application/json;+charset=utf-8 34940.3050ms
time="2022-10-29T01:55:12.3504046+05:30" level=debug msg="Refreshing mDNS addresses for app id uploader timed out." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:12.3509222+05:30" level=debug msg="mDNS browse for app id uploader timed out." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:42.3602209+05:30" level=debug msg="Refreshing all mDNS addresses." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:42.3607271+05:30" level=debug msg="0 IPv4 address(es) expired for app id uploader." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:42.3607271+05:30" level=debug msg="Refreshing mDNS addresses for app id uploader." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:42.4014316+05:30" level=debug msg="mDNS response for app id uploader received." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:42.4036351+05:30" level=debug msg="Adding IPv4 address 192.168.1.11:61484 for app id uploader cache entry." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:45.3636849+05:30" level=debug msg="mDNS browse for app id uploader timed out." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:55:45.3636849+05:30" level=debug msg="Refreshing mDNS addresses for app id uploader timed out." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
== APP == info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
== APP ==       Request starting HTTP/1.1 GET http://localhost:3000/Processor?key=files/4303ckbt.cil.mp4&bucketName=evolution-video-uploads application/json 32
== APP == info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
== APP ==       Executing endpoint 'Processor.Api.Controllers.ProcessorController.Get (Processor.Api)'
== APP == info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
== APP ==       Route matched with {action = "Get", controller = "Processor"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] Get(System.String, System.String) on controller Processor.Api.Controllers.ProcessorController (Processor.Api).  
== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==       been here
time="2022-10-29T01:56:07.2360792+05:30" level=debug msg="found mDNS IPv4 address in cache: 192.168.1.11:61484" app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==       ERROR An exception occurred while invoking method: '/uploads' on app-id: 'uploader'
== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==          at Dapr.Client.DaprClientGrpc.InvokeMethodWithResponseAsync(HttpRequestMessage request, CancellationToken cancellationToken)
== APP ==          at Dapr.Client.DaprClientGrpc.InvokeMethodAsync[TResponse](HttpRequestMessage request, CancellationToken cancellationToken)
== APP ==          at Processor.Api.Controllers.ProcessorController.Get(String key, String bucketName) in D:\Work\git_space\cloud-first-approach\Evolution.Processor\src\Processor.Api\Controllers\ProcessorController.cs:line 56
== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==          at System.Net.Http.ConnectHelper.EstablishSslConnectionAsync(SslClientAuthenticationOptions sslOptions, HttpRequestMessage request, Boolean async, Stream stream, CancellationToken cancellationToken)
== APP ==          at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)   
== APP ==          at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
== APP ==          at System.Net.Http.HttpConnectionPool.AddHttp11ConnectionAsync(HttpRequestMessage request)
== APP ==          at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)      
== APP ==          at System.Net.Http.HttpConnectionPool.GetHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
== APP ==          at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
== APP ==          at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)  
== APP ==          at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
== APP ==          at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
== APP ==          at Dapr.Client.DaprClientGrpc.InvokeMethodWithResponseAsync(HttpRequestMessage request, CancellationToken cancellationToken)
== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==       3288367
== APP == info: Processor.Api.Controllers.ProcessorController[0]
== APP ==       08-10-2022 18:33:17
== APP == info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
== APP ==       Executing OkObjectResult, writing value of type 'Processor.Api.Services.Models.GetVideoDetailsResponseModel'.
== APP == info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
== APP ==       Executed action Processor.Api.Controllers.ProcessorController.Get (Processor.Api) in 310.8803ms
== APP == info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
== APP ==       Executed endpoint 'Processor.Api.Controllers.ProcessorController.Get (Processor.Api)'
== APP == info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
== APP ==       Request finished HTTP/1.1 GET http://localhost:3000/Processor?key=files/4303ckbt.cil.mp4&bucketName=evolution-video-uploads application/json 32 - 200 - application/json;+charset=utf-8 312.0882ms
time="2022-10-29T01:56:15.3683511+05:30" level=debug msg="Refreshing all mDNS addresses." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:56:15.3690387+05:30" level=debug msg="0 IPv4 address(es) expired for app id uploader." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:56:15.3690387+05:30" level=debug msg="Refreshing mDNS addresses for app id uploader." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0
time="2022-10-29T01:56:15.3948084+05:30" level=debug msg="mDNS response for app id uploader received." app_id=processor instance=DESKTOP-FIUUHBV scope=dapr.contrib type=log ver=1.9.0

I did notice the logs for processor service showing when running in log level debug mode.

Refreshing mDNS addresses for app id uploader timed out

Any idea what can cause this ?

iamsourabh-in commented 1 year ago

Also , to add

I can see the dapr dashboard showing the uploader service up.

Dapr Config

image

Processor

image

halspang commented 1 year ago

@iamsourabh-in - I actually didn't know you could access an app that way, but I just tried and it worked, so I guess I learned something new today :)

The mDNS timing out is interesting and would be a runtime problem. So, you may need to ask over there/in components-contrib.

Do you have the logs for the uploader as well?

iamsourabh-in commented 1 year ago

@halspang - I have raise the ticket in dapr runtime. 5430

Upgraded to dapr runtime 1.9.1, No luck Yet

When running AspNetCore in Debug, was able to get some insights, but still not able to invoke the method.

The dapr dashboard shows the below status

image

The logs from the Uploader Service (the service receiving the request) , seems to be a TLS Issue.

== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[1]
== APP ==       Connection id "0HMLQBQFRB300" started.
== APP == info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
== APP ==       Request starting HTTP/1.1 GET http://127.0.0.1:2000/uploads - -
== APP == dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1001]
== APP ==       1 candidate(s) found for the request path '/uploads'
== APP == dbug: Microsoft.AspNetCore.Routing.Matching.DfaMatcher[1005]
== APP ==       Endpoint 'Uploader.Api.Controllers.UploadsController.GetAll (Uploader.Api)' with route pattern 'Uploads' is valid for the request path '/uploads'
== APP == dbug: Microsoft.AspNetCore.Routing.EndpointRoutingMiddleware[1]
== APP ==       Request matched endpoint 'Uploader.Api.Controllers.UploadsController.GetAll (Uploader.Api)'
== APP == dbug: Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware[15]
== APP ==       Static files was skipped as the request already matched an endpoint.
== APP == dbug: Microsoft.AspNetCore.HttpsPolicy.HttpsRedirectionMiddleware[1]
== APP ==       Redirecting to 'https://127.0.0.1:2443/uploads'.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[9]
== APP ==       Connection id "0HMLQBQFRB300" completed keep alive response.
== APP == info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
== APP ==       Request finished HTTP/1.1 GET http://127.0.0.1:2000/uploads - - - 307 0 - 13.9515ms
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[39]
== APP ==       Connection id "0HMLQBQFRB301" accepted.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[1]
== APP ==       Connection id "0HMLQBQFRB301" started.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
== APP ==       Connection id "0HMLQBQFRB301" received FIN.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Https.Internal.HttpsConnectionMiddleware[3]
== APP ==       Connection 0HMLQBQFRB301 established using the following protocol: Tls13
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
== APP ==       Connection id "0HMLQBQFRB301" sending FIN because: "The client closed the connection."
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[10]
== APP ==       Connection id "0HMLQBQFRB301" disconnecting.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.BadRequests[20]
== APP ==       Connection id "0HMLQBQFRB301" request processing ended abnormally.
== APP ==       System.IO.IOException: The decryption operation failed, see inner exception.
== APP ==        ---> System.ComponentModel.Win32Exception (0x80090327): An unknown error occurred while processing the certificate.
== APP ==          --- End of inner exception stack trace ---
== APP ==          at System.Net.Security.SslStream.ReadAsyncInternal[TIOAdapter](TIOAdapter adapter, Memory`1 buffer)
== APP ==          at System.IO.Pipelines.StreamPipeReader.<ReadAsync>g__Core|36_0(StreamPipeReader reader, CancellationTokenSource tokenSource, CancellationToken cancellationToken)
== APP ==          at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequests[TContext](IHttpApplication`1 application)        
== APP ==          at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.Http.HttpProtocol.ProcessRequestsAsync[TContext](IHttpApplication`1 application)   
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[2]
== APP ==       Connection id "0HMLQBQFRB301" stopped.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[6]
== APP ==       Connection id "0HMLQBQFRB300" received FIN.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[10]
== APP ==       Connection id "0HMLQBQFRB300" disconnecting.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Connections[2]
== APP ==       Connection id "0HMLQBQFRB300" stopped.
== APP == dbug: Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets[7]
== APP ==       Connection id "0HMLQBQFRB300" sending FIN because: "The Socket transport's send loop completed gracefully."
iamsourabh-in commented 1 year ago

Seems to be some issue with the runtime or TLS Config.

I have raise the ticket in dapr runtime. 5430 for further discussion.

Closing this ticket.