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.

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

Frequent disconnections at regular intervals #1565

Closed
Tracked by #1455
agazso opened this issue Sep 12, 2023 · 10 comments · Fixed by #1647
Closed
Tracked by #1455

Frequent disconnections at regular intervals #1565

agazso opened this issue Sep 12, 2023 · 10 comments · Fixed by #1647
Assignees
Labels
bug Something isn't working

Comments

@agazso
Copy link

agazso commented Sep 12, 2023

This is a bug report

Problem

I have a Node.js application that is a long running process (think of a chat bot) connected to a single nwaku node. Sometimes it did not receive messages so I started investigating the issue by logging out disconnect and connect events. The disconnect event is when libp2p generates the event peer:disconnect and connect is peer:connect.

I cannot reliably reproduce the issue. Sometimes it happens all the time, sometimes it happens rarely. It might be a clue is that often the disconnect happen at a multiplier of 30 seconds interval. So at the 2nd second or the 32nd second of the minute. I observed from the nwaku logs that it also prints out internal metrics at 30 seconds, maybe it is related. I included a log from my application to illustrate this.

Setting different pingKeepAlive values (e.g. 3, 5, 15 etc.) does not seem to make a difference.

Proposed Solutions

It would be good if waku did not disconnect at least when the quality of the connection is otherwise good. The problem with this is that basically I have to write a safe waku wrapper around waku to detect if there were a disconnect and after reconnection query the store for messages that I was subscribed to for the interval it was disconnected.

Another problem is that if I want to show the user if they are connected to the network or not and disable certain functionality which requires connectivity I cannot rely on detecting the connectivity this way because the user experience will be not great.

Maybe connecting to multiple nodes can improve the situation.

Notes

@waku/sdk version 0.0.18 (the latest working that I tried was 0.0.16)
Node.js v18.17.1 on Linux
Connected to nwaku 0.19

Screenshot from 2023-09-12 11-27-33

@fryorcraken fryorcraken added this to Waku Sep 12, 2023
@agazso
Copy link
Author

agazso commented Sep 12, 2023

Just adding to this that I also see disconnections (about 15 per hour) when I run nwaku in a docker container on the same machine, so there are no connection issues for sure.

@agazso
Copy link
Author

agazso commented Sep 12, 2023

I changed the loglevel to DEBUG for nwaku on the local docker image to see in the logs what is going on when I see a disconnect event:

2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.890+00:00 push request                               topics="waku lightpush" tid=1 file=protocol.nim:57 peerId=12D*u9KSLq requestId=b89b6ff1-f5ab-417f-a198-693cc5f359e9 pubsubTopic=/waku/2/default-waku/proto
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.890+00:00 Dialing peer                               topics="waku node peer_manager" tid=1 file=peer_manager.nim:211 wireAddr=@[] peerId=12D*u9KSLq proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.891+00:00 Dialing peer                               topics="waku node peer_manager" tid=1 file=peer_manager.nim:211 wireAddr=@[] peerId=12D*L8HLi1 proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.892+00:00 Dialing peer                               topics="waku node peer_manager" tid=1 file=peer_manager.nim:211 wireAddr=@[] peerId=12D*DQPjYV proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.892+00:00 Dialing peer                               topics="libp2p dialer" tid=1 file=dialer.nim:134 peerId=12D*DQPjYV
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.892+00:00 Error dialing                              topics="libp2p dialer" tid=1 file=dialer.nim:327 conn=nil err="Unable to establish outgoing link"
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.892+00:00 Dialing peer failed                        topics="waku node peer_manager" tid=1 file=peer_manager.nim:225 peerId=12D*DQPjYV reason=failed proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.892+00:00 Dialing peer                               topics="waku node peer_manager" tid=1 file=peer_manager.nim:211 wireAddr=@[] peerId=12D*c5XAXV proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.892+00:00 Dialing peer                               topics="libp2p dialer" tid=1 file=dialer.nim:134 peerId=12D*c5XAXV
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.892+00:00 Error dialing                              topics="libp2p dialer" tid=1 file=dialer.nim:327 conn=nil err="Unable to establish outgoing link"
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.893+00:00 Dialing peer failed                        topics="waku node peer_manager" tid=1 file=peer_manager.nim:225 peerId=12D*c5XAXV reason=failed proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.893+00:00 Dialing peer                               topics="waku node peer_manager" tid=1 file=peer_manager.nim:211 wireAddr=@[] peerId=12D*nkxj2C proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.893+00:00 Dialing peer                               topics="libp2p dialer" tid=1 file=dialer.nim:134 peerId=12D*nkxj2C
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.893+00:00 Error dialing                              topics="libp2p dialer" tid=1 file=dialer.nim:327 conn=nil err="Unable to establish outgoing link"
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.893+00:00 Dialing peer failed                        topics="waku node peer_manager" tid=1 file=peer_manager.nim:225 peerId=12D*nkxj2C reason=failed proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.936+00:00 Error dialing                              topics="libp2p dialer" tid=1 file=dialer.nim:327 conn=12D*u9KSLq:650074d68ba7827adb401ef2 err="Stream Reset!"
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.938+00:00 unsubscribing pubsub peer                  topics="libp2p pubsub" tid=1 file=pubsub.nim:135 peerId=12D*u9KSLq
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.938+00:00 Error while reading message from secure connection, closing. topics="libp2p secure" tid=1 file=secure.nim:164 error=AsyncStreamReadError message="Read stream failed, originated from [TransportUseClosedError] Attempt to read data from closed stream" connection=12D*u9KSLq:650074d68ba7827adb401ef2
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.938+00:00 Unexpected exception in mplex read loop    topics="libp2p mplex" tid=1 file=mplex.nim:196 m=12D*u9KSLq:650074d68ba7827adb401ef2 msg="Read stream failed, originated from [TransportUseClosedError] Attempt to read data from closed stream"
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.939+00:00 Dialing peer failed                        topics="waku node peer_manager" tid=1 file=peer_manager.nim:225 peerId=12D*u9KSLq reason=failed proto=/vac/waku/filter-push/2.0.0-beta1
2023-09-12 16:32:54 waku-objects-playground-waku-1  | DBG 2023-09-12 14:32:54.953+00:00 No peers for topic, skipping publish       topics="libp2p gossipsub" tid=1 file=gossipsub.nim:538 peersOnTopic=0 connectedPeers=0 topic=/waku/2/default-waku/proto

@weboko weboko moved this to Triage in Waku Sep 13, 2023
@weboko weboko self-assigned this Sep 13, 2023
@weboko weboko moved this from Triage to In Progress in Waku Sep 13, 2023
@weboko weboko mentioned this issue Sep 14, 2023
24 tasks
@fryorcraken fryorcraken added the bug Something isn't working label Sep 21, 2023
@fryorcraken fryorcraken moved this from In Progress to Priority in Waku Sep 21, 2023
@agazso
Copy link
Author

agazso commented Oct 3, 2023

This seems like to be a problem between js-waku and nwaku, because when using go-waku so far I haven't seen this issue. The docker-compose.yaml that I used:

version: '2.4'
services:
  waku:
    image: wakuorg/go-waku:latest
    command: |
      --store=true
      --filter=true
      --lightpush=true
      --websocket-support=true
      --websocket-port=8000
      --nodekey=7b8d9a670aae6421500b7b3f933d0b5d08b51fcf0f0c2f14cba3a4737c83a228
      --min-relay-peers-to-publish=0
    ports:
      - 8000:8000/tcp

@fryorcraken
Copy link
Collaborator

I have a Node.js application that is a long running process (think of a chat bot) connected to a single nwaku node.

Hi @agazso

At this point in time, js-waku targets the browser environment and is being optimized for light client protocols.

Waku Relay in js-waku is considered highly experimental because of browser scalability reasons.

For NodeJS, we recommend running nwaku alongside your NodeJS application and consuming its JSON RPC (REST API is wip).

@agazso
Copy link
Author

agazso commented Oct 10, 2023

I have a Node.js application that is a long running process (think of a chat bot) connected to a single nwaku node.

Hi @agazso

At this point in time, js-waku targets the browser environment and is being optimized for light client protocols.

Waku Relay in js-waku is considered highly experimental because of browser scalability reasons.

For NodeJS, we recommend running nwaku alongside your NodeJS application and consuming its JSON RPC (REST API is wip).

Just to clarify the Node.js application is running the exact same code of a lightweight chat protocol that runs in the browser and it only uses ligthPush, filter and store protocols and it does not use relay protocol.

The same issue exist in browsers, but it's more difficult to experiment and reproduce testing long running processes in the browser to collect data for this issue, that's why I chose to illustrate it with a Node.js app.

BTW It is very convenient that the same code can be shared and it would be more work to create and maintain a separate version that uses a different API.

@danisharora099
Copy link
Collaborator

danisharora099 commented Oct 10, 2023

should be partially fixed with #1647

@github-project-automation github-project-automation bot moved this from Icebox to Done in Waku Oct 11, 2023
@danisharora099
Copy link
Collaborator

@agazso while #1647 is merged, I'm happy to keep this open; please feel free to close if it's resolved for you

@danisharora099 danisharora099 moved this from Done to Icebox in Waku Oct 11, 2023
@agazso
Copy link
Author

agazso commented Oct 11, 2023

@agazso while #1647 is merged, I'm happy to keep this open; please feel free to close if it's resolved for you

Thank you! I will test this in the following days and report back.

@fryorcraken
Copy link
Collaborator

BTW It is very convenient that the same code can be shared and it would be more work to create and maintain a separate version that uses a different API.

Yes we understand we are considering making js-waku officially support on NodeJS.. However, for now the focus is on delivering waku-org/pm#50 and in this context, keeping js-waku focused on the browser.

@agazso
Copy link
Author

agazso commented Dec 4, 2023

I no longer observe this, so it seems the default keepalive ping solved this issue.

@agazso agazso closed this as completed Dec 4, 2023
@github-project-automation github-project-automation bot moved this from Icebox to Done in Waku Dec 4, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

4 participants