dapr: Dapr does not seem to call /dapr/subscribe in kubernetes mode

In what area(s)?

/area runtime /area operator

What version of Dapr?

0.5

Expected Behavior

Dapr sidecar should call the /dapr/subscribe endpoint in Kubernetes mode - from the logs it does not seem to do this. In local mode this does work. The dapr pub-sub-sample also worked on the same AKS cluster.

Actual Behavior

When calling the endpoint from another container we get the following response

curl 10.240.1.117:8080/dapr/subscribe

["topic.storage.storagetopic-response","topic.storage.storagetopic-request","topic.storage.storagetopic-a","topic.storage.storagetopic-b"]

The log from the dapr sidecar we get the following output

kubectl logs storage-6c88f67755-5tb7g  -n core -c daprd
time="2020-03-17T17:34:29.15312031Z" level=info msg="starting Dapr Runtime -- version 0.5.0 -- commit v0.3.0-rc.0-157-gb3bcd88" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:29.15317781Z" level=info msg="log level set to: info" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:29.153580613Z" level=info msg="metrics server started on :9090/" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.metrics type=log ver=0.5.0
time="2020-03-17T17:34:29.181165232Z" level=info msg="kubernetes mode configured" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:29.181189732Z" level=info msg="dapr id: storage-app" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:29.181207333Z" level=info msg="mTLS enabled. creating sidecar authenticator" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:29.181553035Z" level=info msg="trust anchors extracted successfully" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.security type=log ver=0.5.0
time="2020-03-17T17:34:29.181585536Z" level=info msg="authenticator created" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:29.193295429Z" level=info msg="application protocol: http. waiting on port 8080" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.011853431Z" level=info msg="application discovered on port 8080" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.736690088Z" level=info msg="application configuration loaded" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.736780089Z" level=warning msg="either no actor state store or multiple actor state stores are specified in the configuration, actor stores specified: 0" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.736821289Z" level=info msg="Initialized service discovery to kubernetes" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.73686519Z" level=warning msg="actors: state store must be present to initialize the actor runtime" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.actor type=log ver=0.5.0
time="2020-03-17T17:34:45.73689169Z" level=warning msg="failed to init actors: state store does not support transactions which actors require to save state - please see https://github.com/dapr/docs" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.736985291Z" level=info msg="enabled metrics grpc middleware" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.grpc type=log ver=0.5.0
time="2020-03-17T17:34:45.737009991Z" level=info msg="sending workload csr request to sentry" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.grpc type=log ver=0.5.0
time="2020-03-17T17:34:45.794322146Z" level=info msg="certificate signed successfully" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.grpc type=log ver=0.5.0
time="2020-03-17T17:34:45.795081152Z" level=info msg="gRPC server is running on port 50001" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.795770258Z" level=info msg="starting workload cert expiry watcher. current cert expires on: 2020-03-18 17:49:45 +0000 UTC" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.grpc type=log ver=0.5.0
time="2020-03-17T17:34:45.79604106Z" level=info msg="enabled cors http middleware" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.http type=log ver=0.5.0
time="2020-03-17T17:34:45.79608136Z" level=info msg="enabled proxy http middleware" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.http type=log ver=0.5.0
time="2020-03-17T17:34:45.79609726Z" level=info msg="enabled metrics http middleware" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime.http type=log ver=0.5.0
time="2020-03-17T17:34:45.79611256Z" level=info msg="http server is running on port 3500" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0
time="2020-03-17T17:34:45.796136061Z" level=info msg="dapr initialized. Status: Running. Init Elapsed 16614.970429ms" app_id=storage-app instance=storage-6c88f67755-5tb7g scope=dapr.runtime type=log ver=0.5.0

Steps to Reproduce the Problem

We implemented the rest endpoint using the DefaultObjectSerializer and from the container logs it seems that the following method does not get called.

import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

// tag::dapr-config[]
@RestController
public interface DaprPubSubExtension {

    @GetMapping("/dapr/subscribe")
    default byte[] daprConfig() throws Exception {
        String[] topics = getTopics();

        LogHolder.LOG.info("subscribing to topics: [{}]", topics);

        return SERIALIZER.serialize(topics);
    }

    String[] getTopics();
}
// end::dapr-config[]

About this issue

  • Original URL
  • State: closed
  • Created 4 years ago
  • Comments: 27 (21 by maintainers)

Most upvoted comments

Can we close this?

There seems to be something wrong with the handling of namespaces. I tried this again with the pubsub sample - if I deploy everything in default namespace it works. But when I deploy dapr into “dapr-system”, the pubsub into its own namespace “demo” and the component without any namespace then it does not work anymore.

Logs from dapr operator

kubectl logs -l app=dapr-operator -n dapr-system        

time="2020-03-18T17:41:04.163528077Z" level=info msg="service exists: react-form-dapr" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.08911396Z" level=info msg="notified about a component update" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.106697196Z" level=info msg="updating dapr pod selected by service: debian-dapr" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.114513356Z" level=info msg="updating dapr pod selected by service: node-subscriber-dapr" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.115174461Z" level=warning msg="error updating Dapr Runtime with component: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing dial tcp 10.0.5.10:50001: connect: connection refused\"" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.118535187Z" level=info msg="updating dapr pod selected by service: python-subscriber-dapr" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.119719196Z" level=warning msg="error updating Dapr Runtime with component: rpc error: code = Unavailable desc = connection closed" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.124469233Z" level=info msg="updating dapr pod selected by service: react-form-dapr" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.12535024Z" level=warning msg="error updating Dapr Runtime with component: rpc error: code = Unavailable desc = connection closed" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0
time="2020-03-18T17:46:04.140038953Z" level=warning msg="error updating Dapr Runtime with component: rpc error: code = Unavailable desc = connection closed" instance=dapr-operator-fbb7f84b5-bn9z9 scope=dapr.operator.handlers type=log ver=0.5.0

Logs from node-subscriber sidecar

 kubectl logs node-subscriber-6f8d7d6f78-bplpd -n demo daprd          
time="2020-03-18T17:48:09.635764393Z" level=info msg="starting Dapr Runtime -- version 0.5.0 -- commit v0.3.0-rc.0-157-gb3bcd88" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.635813994Z" level=info msg="log level set to: info" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.637553607Z" level=info msg="metrics server started on :9090/" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.metrics type=log ver=0.5.0
time="2020-03-18T17:48:09.638928218Z" level=info msg="kubernetes mode configured" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.638971518Z" level=info msg="dapr id: node-subscriber" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.63917472Z" level=info msg="mTLS enabled. creating sidecar authenticator" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.639504322Z" level=info msg="trust anchors extracted successfully" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.security type=log ver=0.5.0
time="2020-03-18T17:48:09.639531623Z" level=info msg="authenticator created" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.66378091Z" level=info msg="application protocol: http. waiting on port 3000" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.667013435Z" level=info msg="application discovered on port 3000" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.687650894Z" level=warning msg="either no actor state store or multiple actor state stores are specified in the configuration, actor stores specified: 0" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.687698495Z" level=info msg="Initialized service discovery to kubernetes" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.687894696Z" level=warning msg="actors: state store must be present to initialize the actor runtime" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.actor type=log ver=0.5.0
time="2020-03-18T17:48:09.687925596Z" level=warning msg="failed to init actors: state store does not support transactions which actors require to save state - please see https://github.com/dapr/docs" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.688101798Z" level=info msg="enabled metrics grpc middleware" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.grpc type=log ver=0.5.0
time="2020-03-18T17:48:09.688128898Z" level=info msg="sending workload csr request to sentry" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.grpc type=log ver=0.5.0
time="2020-03-18T17:48:09.731765535Z" level=info msg="certificate signed successfully" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.grpc type=log ver=0.5.0
time="2020-03-18T17:48:09.732169438Z" level=info msg="gRPC server is running on port 50001" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.732513241Z" level=info msg="enabled cors http middleware" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.http type=log ver=0.5.0
time="2020-03-18T17:48:09.732583641Z" level=info msg="enabled proxy http middleware" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.http type=log ver=0.5.0
time="2020-03-18T17:48:09.732595741Z" level=info msg="enabled metrics http middleware" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.http type=log ver=0.5.0
time="2020-03-18T17:48:09.732714242Z" level=info msg="http server is running on port 3500" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.732834743Z" level=info msg="dapr initialized. Status: Running. Init Elapsed 93.905325ms" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime type=log ver=0.5.0
time="2020-03-18T17:48:09.733055745Z" level=info msg="starting workload cert expiry watcher. current cert expires on: 2020-03-19 18:03:09 +0000 UTC" app_id=node-subscriber instance=node-subscriber-6f8d7d6f78-bplpd scope=dapr.runtime.grpc type=log ver=0.5.0

What you’re seeing is the expected behavior. Components are namespaced.

If you have your app deployed into the demo namespace, the pub sub component needs to be deployed into the demo namespace as well. You can only have one pub sub component in your cluster, so also make sure you delete the one in default if you deploy it to demo.