search

microsoft / azure-container-apps

Roadmap and issues for Azure Container Apps
MIT License
365 stars 29 forks source link

"Error finding address for actor type" #708

Open onionhammer opened 1 year ago

onionhammer commented 1 year ago 
Dapr.DaprApiException: error invoke actor method: error finding address for actor type

This issue is a: (mark with an x)

Issue description

I have bicep scripts which I use to deploy my application to two environments (a QA and prod), which work fine, but creating a third environment with no code changes (just different azure resources), results in the above error.

I have 2 services in the same ACA environment, an actor 'client' and an actor 'server', the 'server' has an actor statestore and starts successfully, the client also has dapr enabled.

Client daprd output:

3-04-06T16:46:54.257078755Z time="2023-04-06T16:46:54.25672203Z" level=info msg="HTTP API Called" app_id=dev-app-client instance=dev-app-client--zlyt340-6cc7c46d4c-qfpfz method="GET /v1.0/metadata" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:50:27.057467532Z time="2023-04-06T16:50:27.057321286Z" level=info msg="HTTP API Called" app_id=dev-app-client instance=dev-app-client--zlyt340-6cc7c46d4c-qfpfz method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:50:27.057513340Z time="2023-04-06T16:50:27.057461276Z" level=info msg="Error processing operation DaprBuiltInActorNotFoundRetries. Retrying in 1s…" app_id=dev-app-client instance=dev-app-client--zlyt340-6cc7c46d4c-qfpfz scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:50:50.053413726Z time="2023-04-06T16:50:50.053310552Z" level=info msg="HTTP API Called" app_id=dev-app-client instance=dev-app-client--zlyt340-6cc7c46d4c-qfpfz method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:50:50.053456349Z time="2023-04-06T16:50:50.053384266Z" level=info msg="Error processing operation DaprBuiltInActorNotFoundRetries. Retrying in 1s…" app_id=dev-app-client instance=dev-app-client--zlyt340-6cc7c46d4c-qfpfz scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:51:51.346558669Z time="2023-04-06T16:51:51.346462718Z" level=info msg="HTTP API Called" app_id=dev-app-client instance=dev-app-client--zlyt340-6cc7c46d4c-qfpfz method="GET /v1.0/metadata" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2

Server daprd output:

2023-04-06T16:56:20.91813  Connecting to the container 'daprd'...
2023-04-06T16:56:20.93484  Successfully Connected to container: 'daprd' [Revision: 'dev-app-actorhost--jemoy1j', Replica: 'dev-app-actorhost--jemoy1j-8667577cc-4xv9w']
2023-04-06T16:46:24.309544817Z time="2023-04-06T16:46:24.309508453Z" level=info msg="HTTP server listening on TCP address: [::1]:3500" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.http type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309585274Z time="2023-04-06T16:46:24.309528071Z" level=info msg="HTTP server listening on TCP address: 127.0.0.1:3500" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.http type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309614939Z time="2023-04-06T16:46:24.309579428Z" level=info msg="enabled metrics http middleware" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.http type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309619798Z time="2023-04-06T16:46:24.309590493Z" level=info msg="enabled tracing http middleware" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.http type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309626809Z time="2023-04-06T16:46:24.309606725Z" level=info msg="http server is running on port 3500" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309640411Z time="2023-04-06T16:46:24.30961701Z" level=info msg="The request body size parameter is: 4" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309691982Z time="2023-04-06T16:46:24.309641272Z" level=info msg="gRPC server listening on TCP address: :50002" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.grpc.internal type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309695730Z time="2023-04-06T16:46:24.309666325Z" level=info msg="Enabled gRPC tracing middleware" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.grpc.internal type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309698593Z time="2023-04-06T16:46:24.309671205Z" level=info msg="Enabled gRPC metrics middleware" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.grpc.internal type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.309706302Z time="2023-04-06T16:46:24.309679756Z" level=info msg="sending workload csr request to sentry" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.grpc.internal type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.328722217Z time="2023-04-06T16:46:24.32862569Z" level=info msg="certificate signed successfully" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.grpc.internal type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.328805247Z time="2023-04-06T16:46:24.328744984Z" level=info msg="internal gRPC server is running on port 50002" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.328809982Z time="2023-04-06T16:46:24.328761834Z" level=info msg="application protocol: http. waiting on port 3000.  This will block until the app is listening on that port." app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.332582756Z time="2023-04-06T16:46:24.328864798Z" level=info msg="starting workload cert expiry watcher. current cert expires on: 2023-04-07 17:01:24 +0000 UTC" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.grpc.internal type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.332597592Z time="2023-04-06T16:46:24.329025461Z" level=info msg="application discovered on port 3000" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.336707268Z time="2023-04-06T16:46:24.336624494Z" level=info msg="application configuration loaded" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.336748089Z time="2023-04-06T16:46:24.336677977Z" level=info msg="actor runtime started. actor idle timeout: 1h0m0s. actor scan interval: 30s" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime.actor type=log ver=1.10.4-msft-2
2023-04-06T16:46:24.340883742Z time="2023-04-06T16:46:24.340758868Z" level=info msg="dapr initialized. Status: Running. Init Elapsed 586ms" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w scope=dapr.runtime type=log ver=1.10.4-msft-2
2023-04-06T16:46:54.251480295Z time="2023-04-06T16:46:54.251359127Z" level=info msg="HTTP API Called" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w method="GET /v1.0/metadata" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:51:51.345376301Z time="2023-04-06T16:51:51.345215124Z" level=info msg="HTTP API Called" app_id=dev-app-actorhost instance=dev-app-actorhost--jemoy1j-8667577cc-4xv9w method="GET /v1.0/metadata" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2

The same client app on QA works fine, deployed with same bicep scripts, same containers

2023-04-06T17:00:23.35224  Connecting to the container 'daprd'...
2023-04-06T17:00:23.36788  Successfully Connected to container: 'daprd' [Revision: 'qa-app-client--tag-13f2130', Replica: 'qa-app-client--tag-13f2130-6fc59ffc87-stjpp']
2023-04-06T16:59:33.249487508Z time="2023-04-06T16:59:33.249439925Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.249599657Z time="2023-04-06T16:59:33.249560972Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.249706522Z time="2023-04-06T16:59:33.249671037Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.249844192Z time="2023-04-06T16:59:33.249805929Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.249969563Z time="2023-04-06T16:59:33.249921081Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.250080522Z time="2023-04-06T16:59:33.250041419Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.250195781Z time="2023-04-06T16:59:33.250157371Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.250311412Z time="2023-04-06T16:59:33.250272223Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.250459901Z time="2023-04-06T16:59:33.25041942Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251045716Z time="2023-04-06T16:59:33.250998004Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251174479Z time="2023-04-06T16:59:33.251134472Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251292854Z time="2023-04-06T16:59:33.251252039Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251396852Z time="2023-04-06T16:59:33.251356573Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251512240Z time="2023-04-06T16:59:33.251468896Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251634440Z time="2023-04-06T16:59:33.251595733Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251755646Z time="2023-04-06T16:59:33.251716089Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251860865Z time="2023-04-06T16:59:33.251825165Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.251986519Z time="2023-04-06T16:59:33.251947097Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.252092869Z time="2023-04-06T16:59:33.252055691Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2
2023-04-06T16:59:33.252226674Z time="2023-04-06T16:59:33.252180297Z" level=info msg="HTTP API Called" app_id=qa-app-client instance=qa-app-client--tag-13f2130-6fc59ffc87-stjpp method="PUT /v1.0/actors/{actorType}/{actorId}/method/{method}" scope=dapr.runtime.http-info type=log ver=1.10.4-msft-2

Expected behavior The daprd sidecar for the client should find the daprd sidecar of the server, and invoke actor methods

Actual behavior Daprd sidecar for client shows error indicating it cannot find the actor type

ItalyPaleAle commented 1 year ago

Would you be able to enable debug logs for Dapr and post the full from when the sidecars start? I would like to see if there are issues connecting to placement.

onionhammer commented 1 year ago

(Connected via Discord & sent details)

WolfspiritM commented 1 year ago

I have the same problem, however it starts working randomly after about 10-20 minutes until I deploy again.

onionhammer commented 1 year ago

@WolfspiritM this was an infrastructure issue that @ItalyPaleAle helped me to resolve. You should enable debug logs in your dapr & send the debug logs to acasupport at microsoft.com.. reference this issue and the name of your aca environment

faheemgani commented 10 months ago

@ItalyPaleAle @onionhammer Do you know what the issue was with the infrastructure?

We had an identical issue on our Production Environment today, the version of services we're running and the Dapr runtime haven't been updated for weeks now, so it was very concerning to see this happening randomly.

Deleting and recreating the container app environment fixed the issue but obviously this is not a viable solution on our Production systems!

onionhammer commented 10 months ago

@faheemgani no, it was an internal issue and they said they resolved it on the backend.