Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Pub Sub in quickstart does not work #823

Closed
christcottrell opened this issue Apr 10, 2023 · 9 comments
Closed

Pub Sub in quickstart does not work #823

christcottrell opened this issue Apr 10, 2023 · 9 comments
Labels
area/pubsub P2 question Further information is requested

Comments

@christcottrell
Copy link

d

Expected Behavior

I expect the order-processor in the pub sub demo to subscribe and receive the message from the topic.

Actual Behavior

The message makes it to the topic correctly, but is not making it to the subscrber. Also seeing this in the logs, which I think is the problem:

level=info msg="application protocol: http. waiting on port 7102. This will block until the app is listening on that port." app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4

Steps to Reproduce the Problem

All I can give here is the environment info and the rest is directly from the quickstart. Will also include the logging when this is run below.. I also know this did work previously a couple of weeks ago.. I also looked at the troubleshooting page and below the logging, The curl that indicates the endpoint is registered correctly looks OK and returns a 200 with the following json using this curl - curl http://localhost:7005/dapr/subscribe -v returns 200 with [{"topic":"orders","pubsubName":"orderpubsub","route":"orders"}]

Dapr version is:
CLI version: 1.10.0
Runtime version: 1.10.4

C:\Users\ccottrell\pubsub\quickstarts\pub_sub\csharp\sdk\order-processor>dapr run --app-id order-processor --resources-path ../../../components --app-port 7100 -- dotnet run
Starting Dapr with id order-processor. HTTP Port: 50078. gRPC Port: 50079
time="2023-04-10T14:46:24.9706629-06:00" level=info msg="starting Dapr Runtime -- version 1.10.4 -- commit 42964736b1e99c9c03595c80c61fbe77912391c8" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:24.9763821-06:00" level=info msg="log level set to: info" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:24.9774181-06:00" level=info msg="metrics server started on :50080/" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.metrics type=log ver=1.10.4
== APP == Building...
time="2023-04-10T14:46:25.0881811-06:00" level=info msg="Resiliency configuration loaded." app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.0888129-06:00" level=info msg="standalone mode configured" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.089148-06:00" level=info msg="app id: order-processor" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.0896488-06:00" level=info msg="mTLS is disabled. Skipping certificate request and tls validation" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.0908678-06:00" level=info msg="Dapr trace sampler initialized: DaprTraceSampler(P=1.000000)" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.1944746-06:00" level=info msg="local service entry announced: order-processor -> 10.56.17.26:50081" app_id=order-processor component="mdns (nameResolution/v1)" instance=USPSCCCOTTRELL3 scope=dapr.contrib type=log ver=1.10.4
time="2023-04-10T14:46:25.1954772-06:00" level=info msg="Initialized name resolution to mdns" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.2130072-06:00" level=info msg="loading components" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.2214401-06:00" level=info msg="waiting for all outstanding components to be processed" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.2590349-06:00" level=info msg="component loaded. name: orderpubsub, type: pubsub.redis/v1" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.259428-06:00" level=info msg="all outstanding components processed" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.2624762-06:00" level=info msg="gRPC proxy enabled" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.278695-06:00" level=info msg="gRPC server listening on TCP address: :50079" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.grpc.api type=log ver=1.10.4
time="2023-04-10T14:46:25.2792538-06:00" level=info msg="Enabled gRPC tracing middleware" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.grpc.api type=log ver=1.10.4
time="2023-04-10T14:46:25.2797604-06:00" level=info msg="Enabled gRPC metrics middleware" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.grpc.api type=log ver=1.10.4
time="2023-04-10T14:46:25.2818799-06:00" level=info msg="configuring workflow engine gRPC endpoint" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.wfengine type=log ver=1.10.4
time="2023-04-10T14:46:25.2855672-06:00" level=info msg="API gRPC server is running on port 50079" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.2872641-06:00" level=info msg="enabled metrics http middleware" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.http type=log ver=1.10.4
time="2023-04-10T14:46:25.287858-06:00" level=info msg="enabled tracing http middleware" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.http type=log ver=1.10.4
time="2023-04-10T14:46:25.3058939-06:00" level=info msg="HTTP server listening on TCP address: :50078" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.http type=log ver=1.10.4
time="2023-04-10T14:46:25.3058939-06:00" level=info msg="http server is running on port 50078" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.3071088-06:00" level=info msg="The request body size parameter is: 4" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.3308835-06:00" level=info msg="gRPC server listening on TCP address: :50081" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.grpc.internal type=log ver=1.10.4
time="2023-04-10T14:46:25.3313986-06:00" level=info msg="Enabled gRPC tracing middleware" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.grpc.internal type=log ver=1.10.4
time="2023-04-10T14:46:25.3343815-06:00" level=info msg="Enabled gRPC metrics middleware" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime.grpc.internal type=log ver=1.10.4
time="2023-04-10T14:46:25.3353789-06:00" level=info msg="internal gRPC server is running on port 50081" app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
time="2023-04-10T14:46:25.3368784-06:00" level=info msg="application protocol: http. waiting on port 7100. This will block until the app is listening on that port." app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
Updating metadata for appPID: 8112
Updating metadata for app command: dotnet run
You're up and running! Both Dapr and your app logs will appear here.

== APP == info: Microsoft.Hosting.Lifetime[14]
== APP == Now listening on: http://localhost:7005
== APP == info: Microsoft.Hosting.Lifetime[0]
== APP == Application started. Press Ctrl+C to shut down.
== APP == info: Microsoft.Hosting.Lifetime[0]
== APP == Hosting environment: Development
== APP == info: Microsoft.Hosting.Lifetime[0]
== APP == Content root path: C:\Users\ccottrell\pubsub\quickstarts\pub_sub\csharp\sdk\order-processor\
@christcottrell
Copy link
Author

Is anyone else facing this.. I had a coworker try this and she ran into the same issue I had. I literally took the code as is and it is not working. It was working maybe 2-3 weeks ago. Thanks!

@ZieMcd
Copy link

ZieMcd commented May 18, 2023

Hey Chris, try running
dapr run --app-id order-processor --resources-path ../../../components --app-port 7005 -- dotnet run
I had a similar issue and changing the application port to match what is seen in the logs has resolved it for me.

@christcottrell
Copy link
Author

Thank you for the response.

That didn't seem to work.. I'll include the last couple lines from the order-processor example, but everything else looks the same. Also, I am using the .Net instructions at https://docs.dapr.io/getting-started/quickstarts/pubsub-quickstart/.

time="2023-05-18T19:53:21.0014873-05:00" level=info msg="application protocol: http. waiting on port 7005. This will block until the app is listening on that port." app_id=order-processor instance=USPSCCCOTTRELL3 scope=dapr.runtime type=log ver=1.10.4
Updating metadata for appPID: 49724
Updating metadata for app command: dotnet run
You're up and running! Both Dapr and your app logs will appear here.

== APP == info: Microsoft.Hosting.Lifetime[14]
== APP == Now listening on: http://localhost:7002
== APP == info: Microsoft.Hosting.Lifetime[0]
== APP == Application started. Press Ctrl+C to shut down.
== APP == info: Microsoft.Hosting.Lifetime[0]
== APP == Hosting environment: Development
== APP == info: Microsoft.Hosting.Lifetime[0]
== APP == Content root path: C:\projects\dapr\quickstarts\pub_sub\csharp\sdk\order-processor\

And I followed the instructions starting the order processor and then the checkout. Even tried restarting the checkout several times. Checkout seems to send the data.. Also, I was able to verify that the checkout is publishing because I switched the connection to Azure Service Bus and saw items get added there. But yea.. Fresh pull from Github with no changes and running it all from the command line and using the same port you identified and also the one in the instructions.

What is strange is that I did this back in February or March as I was doing a POC for a system I am currently building.. We're not yet at the stage where it is completely blocking, but I may have to look for work arounds. I may need to do that anyway as I haven't seen a way to add to the queue with a delay and that doesn't seem to be an option yet. It sounds like it is being discussed, but it is pretty critical for our system. Thanks

@msfussell
Copy link
Member

@christcottrell - I just tried out the C# SDK pub/sub example and it works fine. Have you checked that Docker is running on your machine since this is using Redis as the broker. If docker is not running this will fail. Also Redis is running after you have done the dapr init coommand?

@msfussell msfussell added question Further information is requested P2 area/pubsub labels May 20, 2023
@christcottrell
Copy link
Author

Docker is running.. dapr_zipkn, dapr_redis, and dapr_placement are all running containers. This is from the logs for the redis container. What I also find interesting is that the checkout is successfully sending the 10 messages.. I also had configured the send to go to Azure Service Bus and the messages successfully made it there. Memory used is really low so no issues there. The security attack message is strange.. When this is working, what versions do you have.. I have updated and at
CLI version: 1.10.0
Runtime version: 1.10.7

1:C 20 May 2023 02:39:12.729 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
1:C 20 May 2023 02:39:12.729 # Redis version=6.2.12, bits=64, commit=00000000, modified=0, pid=1, just started
1:C 20 May 2023 02:39:12.729 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
1:M 20 May 2023 02:39:12.729 * monotonic clock: POSIX clock_gettime
1:M 20 May 2023 02:39:12.730 * Running mode=standalone, port=6379.
1:M 20 May 2023 02:39:12.730 # Server initialized
1:M 20 May 2023 02:39:12.730 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can can also cause failures without low memory condition, see jemalloc/jemalloc#1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
1:M 20 May 2023 02:39:12.730 * Ready to accept connections
1:M 20 May 2023 02:49:02.405 # Possible SECURITY ATTACK detected. It looks like somebody is sending POST or Host: commands to Redis. This is likely due to an attacker attempting to use Cross Protocol Scripting to compromise your Redis instance. Connection aborted.

@GBPROB2
Copy link

GBPROB2 commented May 23, 2023 •
edited
Loading

I've got a different issue but related to pub sub. When using pub_sub/javascript/http, I get every order duplicated. On the screenshot below, order processor is on the left and checkout is on the right. Code is unchanged and as is in the repository

image

@christcottrell
Copy link
Author

@ZieMcd That answer worked..

The instructions have us running dapr run --app-id order-processor --resources-path ../../../components --app-port 7005 -- dotnet run

I changed this to 7002 and it worked.

@mikkelhm
Copy link

Just to add to this one - I just installed everything, ran the tutorials, and reached the pub-sub one. I faced the same issue. For some reason it does not listen to the topic, when started from port 7005 - Makes no sense.
Fixed it as well by changing the port to 7006, which is also what the readme in the repository says to do

@cassianodti
Copy link

cassianodti commented Aug 18, 2023 •
edited
Loading

Good morning, I have the same problem here, the quickstart app successfully sends messages, but they are not consumed.

Unfortunately so far I have not been able to reproduce the correct behavior of pubsub correctly in any application. In all it is possible to send the message, but they are never consumed.

NOTE 1: in
app.MapPost("/orders", [Topic("orderpubsub", "orders")] (Order order) => {
Console.WriteLine("Subscriber received : " + order);
return Results.Ok(order);
});
I tried changing the value of orderpubsub to orderpubsubtest and the application went up correctly. Shouldn't that fail?

NOTE 2: when accessing http://localhost:7006/dapr/subscribe the expected value is always displayed.
// 20230818073801
// http://localhost:7006/dapr/subscribe

[
{
"topic": "orders",
"pubsubName": "orderpubsub",
"route": "orders"
}
]

NOTE 3: In the sample application, actually changing the port to 7006 the expected behavior is performed successfully. Thinking about it, in the other examples that I ran I realized that I should also expose the port of the application along with the dapr run command and now my examples worked. I think this should be described somewhere

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/pubsub P2 question Further information is requested
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@mikkelhm @msfussell @christcottrell @ZieMcd @GBPROB2 @cassianodti