Node Canary fails despite being able to connect just fine

[jakubgs]

I was helping a user setup their own mailserver and I noticed something weird. The canary call would fail with

Error waiting for envelopes to be available to client filter package=status-go/cmd/node-canary error="timed out while waiting for event on envelopes. event: envelope.available"

But I could clearly see the connection to the node being made just fine:

Adding p2p peer                          name=node-canary/v0.27.0-... addr=100.16.172.52:48246 peers=3
Delivering mail                          peerID=d792adbf661c23e5a729007488c97a88c1325f3aa3d50e7639fd66f4b6b9a0cc
Processing request                       lower=1561390415 upper=1561476815 bloom="[0 0 0 0 0 0 128 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 32 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]" limit=1 cursor=[] batch=true
Sending historic message response        last=000000…000000 next=[]
message loop                             peer=d792adbf661c23e5 err=EOF
Removing p2p peer                        id=d792adbf661c23e5 conn=inbound duration=5.300s peers=2 req=false err=EOF

I can clearly see Adding p2p peer and then Removing p2p peer, and an attempt to send the messages in Sending historic message response.

I'm not sure but does this fail because the arguments are last=000000…000000 next=[]?

But if that's the case, why would the error say the issue was a timeout?

[dshulyak]

It looks like node-canary sends a history request for a specific chat, waits for response, and verifies that envelope that was sent last, as a part of response, was added to whisper filters.

Sending historic message response        last=000000…000000 next=[]

In log above last should be the hash of the last delivered envelope, it is all 0s so nothing was found for a specified chat. That node is definitely reachable, it just has no history for a requested chat.

[jakubgs]

Okay, and that makes sense to me, so why is the error saying:

timed out while waiting for event on envelopes. event: envelope.available

There was no timeout, it just received an empty response from the node, isn't that right? Or does it get no response if there is nothing to return?

[dshulyak]

Or does it get no response if there is nothing to return?

it gets response, but after that it waits for the last envelope to appear in filters, using that last field. it doesn't check that last is 0s, so error handling and messages definitely can be improved

[jakubgs]

Yeah, that error makes no sense in that context, even though it should fail based on what you said.

[status-github-bot[bot]]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.