search

eclipse-velocitas / vehicle-app-python-sdk

vehicle-app-python-sdk
Apache License 2.0
7 stars 18 forks source link

[Bug]: Dapr health check fails at wait_for_sidecar #34

Closed AkhilTThomas closed 1 year ago

AkhilTThomas commented 1 year ago

What happened?

When launching an app with sidecar the wait_for_sidecar API fails as the dapr healthz returns 500. However if a delay is added before calling health check it succeeds. Detailed log is attached.

Operating System

Linux

What release version or branch did you use?

0.4.6

Relevant log output

#######################################################
### Running Vehicle Light Application               ###
#######################################################
ℹ️  Starting Dapr with id mylightapp. HTTP Port: 3500. gRPC Port: 33693
INFO[0000] starting Dapr Runtime -- version 1.9.1 -- commit 8aaa4e6f3a5333c7b2d6d4a68b89413b2b0078c2  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] log level set to: debug                       app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] metrics server started on :39405/             app_id=mylightapp instance=codespaces-d83eeb scope=dapr.metrics type=log ver=1.9.1
WARN[0000] App health checks are a preview feature and require the AppHealthCheck feature flag to be enabled. See https://docs.dapr.io/operations/configuration/preview-features/ on how to enable preview features.  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
DEBU[0000] Resiliency is not enabled.                    app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] standalone mode configured                    app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] app id: mylightapp                            app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] mTLS is disabled. Skipping certificate request and tls validation  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] local service entry announced: mylightapp -> 172.16.5.4:42751  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.contrib type=log ver=1.9.1
INFO[0000] Initialized name resolution to mdns           app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] loading components                            app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
DEBU[0000] found component. name: mqtt-pubsub, type: pubsub.mqtt/v1  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] waiting for all outstanding components to be processed  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
DEBU[0000] loading component. name: mqtt-pubsub, type: pubsub.mqtt/v1  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
DEBU[0000] mqtt message bus initialization complete      app_id=mylightapp instance=codespaces-d83eeb scope=dapr.contrib type=log ver=1.9.1
INFO[0000] component loaded. name: mqtt-pubsub, type: pubsub.mqtt/v1  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] all outstanding components processed          app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] gRPC proxy enabled                            app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] enabled gRPC tracing middleware               app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime.grpc.api type=log ver=1.9.1
INFO[0000] enabled gRPC metrics middleware               app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime.grpc.api type=log ver=1.9.1
INFO[0000] API gRPC server is running on port 33693      app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] enabled metrics http middleware               app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime.http type=log ver=1.9.1
INFO[0000] enabled tracing http middleware               app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime.http type=log ver=1.9.1
INFO[0000] http server is running on port 3500           app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] The request body size parameter is: 4         app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] enabled gRPC tracing middleware               app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime.grpc.internal type=log ver=1.9.1
INFO[0000] enabled gRPC metrics middleware               app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime.grpc.internal type=log ver=1.9.1
INFO[0000] internal gRPC server is running on port 42751  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] application protocol: grpc. waiting on port 50008.  This will block until the app is listening on that port.  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
== APP == /workspaces/geely-poc/src/vehicle_app/light_application.py:99: DeprecationWarning: There is no current event loop
== APP ==   LOOP = asyncio.get_event_loop()
== APP == INFO:Light_Application:Starting my VehicleApp...
== APP == DEBUG:sdv.vehicle_app:Talent instantiation successfully done
== APP == DEBUG:sdv.dapr._servicier:Registering topic 'ambientLight1/brightness/command'
== APP == DEBUG:sdv.dapr.client:entering wait state
DEBU[0000] {ERR_HEALTH_NOT_READY dapr is not ready}      app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime.http type=log ver=1.9.1
== APP == DEBUG:sdv.dapr.client:HTTP Error 500: Internal Server Error
INFO[0000] application discovered on port 50008          app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1
INFO[0000] actors: state store is not configured - this is okay for clients but services with hosted actors will fail to initialize!  app_id=mylightapp instance=codespaces-d83eeb scope=dapr.runtime type=log ver=1.9.1

Code of Conduct

gkreyssing commented 1 year ago

Thanks for reporting this issue, we will have a look.

doosuu commented 1 year ago

Hi @AkhilTThomas, thanks for the report.

The dapr sidecar is a separate process which takes some time to start up, hence why you are seeing the 500 in the logs. If we add a delay, it will degrade some systems with faster startup of the dapr sidecar. I would suggest we change the logs to report Waiting for dapr sidecar in case of ERR_HEALTH_NOT_READY instead of the internal server error.