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

Unhandled socket connection err leads to xud crash #1773

Closed
raladev opened this issue Jul 30, 2020 · 3 comments · Fixed by #1777
Closed

Unhandled socket connection err leads to xud crash #1773

raladev opened this issue Jul 30, 2020 · 3 comments · Fixed by #1777
Assignees
@sangaman @kilrau @LePremierHomme
Labels
bug Something isn't working p2p Peer to peer networking P2 mid priority

Comments

@raladev
Copy link
Contributor

raladev commented Jul 30, 2020

Log:

30/07/2020 13:01:59.299 [P2P] verbose: received order invalidation from 03ebe60e1712fe0fe526e5cbd97770c4471ae7612ea294f7d17379fd5b80d0d5f8 (MoreLike): {"id":"d98f9650-d264-11ea-911c-f917e282fcae","pairId":"ETH/BTC","quantity":909100000}
30/07/2020 13:01:59.300 [ORDERBOOK] debug: order removed: d98f9650-d264-11ea-911c-f917e282fcae
30/07/2020 13:01:59.319 [P2P] verbose: received order from 03ef2174b6001edbc0e5b2494ce34f50550836ca540f9a082ef4c2432fcbc1bc69 (BulkSick): {"id":"da6b2940-d264-11ea-867a-4f4c948ef811","pairId":"ETH/BTC","price":0.02988751,"quantity":1110000000,"isBuy":false}
30/07/2020 13:01:59.320 [ORDERBOOK] debug: order added: {"id":"da6b2940-d264-11ea-867a-4f4c948ef811","pairId":"ETH/BTC","price":0.02988751,"quantity":1110000000,"isBuy":false,"peerPubKey":"03ef2174b6001edbc0e5b2494ce34f50550836ca540f9a082ef4c2432fcbc1bc69","createdAt":1596114119320,"initialQuantity":1110000000}
30/07/2020 13:01:59.320 [P2P] verbose: received order from 03ef2174b6001edbc0e5b2494ce34f50550836ca540f9a082ef4c2432fcbc1bc69 (BulkSick): {"id":"da6b9e70-d264-11ea-867a-4f4c948ef811","pairId":"ETH/BTC","price":0.02814649,"quantity":8588234092,"isBuy":true}
30/07/2020 13:01:59.320 [ORDERBOOK] debug: order added: {"id":"da6b9e70-d264-11ea-867a-4f4c948ef811","pairId":"ETH/BTC","price":0.02814649,"quantity":8588234092,"isBuy":true,"peerPubKey":"03ef2174b6001edbc0e5b2494ce34f50550836ca540f9a082ef4c2432fcbc1bc69","createdAt":1596114119320,"initialQuantity":8588234092}
30/07/2020 13:01:59.344 [P2P] verbose: received order from 03ebe60e1712fe0fe526e5cbd97770c4471ae7612ea294f7d17379fd5b80d0d5f8 (MoreLike): {"id":"da6ab410-d264-11ea-911c-f917e282fcae","pairId":"ETH/BTC","price":0.02988751,"quantity":909100000,"isBuy":false}
30/07/2020 13:01:59.344 [ORDERBOOK] debug: order added: {"id":"da6ab410-d264-11ea-911c-f917e282fcae","pairId":"ETH/BTC","price":0.02988751,"quantity":909100000,"isBuy":false,"peerPubKey":"03ebe60e1712fe0fe526e5cbd97770c4471ae7612ea294f7d17379fd5b80d0d5f8","createdAt":1596114119344,"initialQuantity":909100000}
30/07/2020 13:01:59.344 [P2P] verbose: received order from 03ebe60e1712fe0fe526e5cbd97770c4471ae7612ea294f7d17379fd5b80d0d5f8 (MoreLike): {"id":"da6bc580-d264-11ea-911c-f917e282fcae","pairId":"ETH/BTC","price":0.02814649,"quantity":3395009253,"isBuy":true}
30/07/2020 13:01:59.345 [ORDERBOOK] debug: order added: {"id":"da6bc580-d264-11ea-911c-f917e282fcae","pairId":"ETH/BTC","price":0.02814649,"quantity":3395009253,"isBuy":true,"peerPubKey":"03ebe60e1712fe0fe526e5cbd97770c4471ae7612ea294f7d17379fd5b80d0d5f8","createdAt":1596114119345,"initialQuantity":3395009253}
30/07/2020 13:02:01.940 [CONNEXT] error: connext server error 500: Internal Server Error
30/07/2020 13:02:01.940 [CONNEXT] error: failed to update total outbound capacity: 8.5 - connext server error 500: Internal Server Error
30/07/2020 13:02:02.937 [RPC] debug: received call /xudrpc.Xud/ListOrders
30/07/2020 13:02:04.081 [P2P] debug: Connected pre-handshake to 23.129.64.192:16435
30/07/2020 13:02:04.461 [P2P] debug: Peer 024fa9621b99d3bbdd2e15aaa271a1dfa550888b460ccc19dca83c2ab970aba0cd (WordState) session out-encryption enabled
30/07/2020 13:02:04.934 [CONNEXT] error: connext server error 500: Internal Server Error
30/07/2020 13:02:04.934 [CONNEXT] error: failed to update total outbound capacity: 8.5 - connext server error 500: Internal Server Error
30/07/2020 13:02:05.046 [P2P] debug: Peer 024fa9621b99d3bbdd2e15aaa271a1dfa550888b460ccc19dca83c2ab970aba0cd (WordState) session in-encryption enabled
30/07/2020 13:02:05.047 [P2P] verbose: opened connection to 024fa9621b99d3bbdd2e15aaa271a1dfa550888b460ccc19dca83c2ab970aba0cd (WordState) at 23.129.64.192:16435
30/07/2020 13:02:05.251 [P2P] debug: received disconnecting packet from 024fa9621b99d3bbdd2e15aaa271a1dfa550888b460ccc19dca83c2ab970aba0cd (WordState) due to Shutdown
30/07/2020 13:02:05.254 [P2P] error: Peer (024fa9621b99d3bbdd2e15aaa271a1dfa550888b460ccc19dca83c2ab970aba0cd (WordState)) error: Error: This socket has been ended by the other party
    at Socket.writeAfterFIN [as write] (net.js:454:14)
    at Peer.<anonymous> (/app/dist/p2p/Peer.js:229:37)
    at Generator.next (<anonymous>)
    at fulfilled (/app/dist/p2p/Peer.js:24:58)
events.js:292
      throw er; // Unhandled 'error' event
      ^

Error: This socket has been ended by the other party
    at Socket.writeAfterFIN [as write] (net.js:454:14)
    at Peer.<anonymous> (/app/dist/p2p/Peer.js:229:37)
    at Generator.next (<anonymous>)
    at fulfilled (/app/dist/p2p/Peer.js:24:58)
Emitted 'error' event on Socket instance at:
    at emitErrorNT (net.js:1340:8)
    at processTicksAndRejections (internal/process/task_queues.js:84:21) {
  code: 'EPIPE'
}
@raladev raladev added bug Something isn't working p2p Peer to peer networking P2 mid priority labels Jul 30, 2020
@LePremierHomme
Copy link
Contributor

Is this reproducible?
If so, can you please run it with trace log-level?

@sangaman sangaman self-assigned this Jul 31, 2020
@sangaman
Copy link
Collaborator

@raladev Important question here that I can't distinguish from the logs (and I'm thinking this should be logged going forward), did the node that wrote those logs make an outgoing connection to the peer? Or did the peer connect to it inbound?

The error looks like it's happening due to beginning a write to a socket at the exact same moment that the remote peer destroys the socket. The write call is in a try/catch statement, but then it also emits an error event on the socket and that apparently isn't being handled.

@raladev
Copy link
Contributor Author

raladev commented Jul 31, 2020

@raladev Important question here that I can't distinguish from the logs (and I'm thinking this should be logged going forward), did the node that wrote those logs make an outgoing connection to the peer? Or did the peer connect to it inbound?

it is log of our simnet-1 node. So, this node was online and just new node was installed by someone, then , if i understood correctly, it was inbound connection from remote node (if simnet-1 did not lose connection with emote node and did not try to establish it by yourself).

sangaman added a commit that referenced this issue Aug 3, 2020
@sangaman
fix(p2p): handle multiple socket errors
716f5d3 
This changes the peer socket error handling to use `on` instead of `once`
when listening for `error` events to ensure that an unexpected second
`error` event doesn't crash xud after the `once` handler stops listening.
Instead we use `on` to listen to all error events and then manually
remove all listeners from the socket after it's destroyed.

Fixes #1773
@sangaman sangaman mentioned this issue Aug 3, 2020
Merged
@ghost ghost closed this as completed in #1777 Aug 4, 2020
sangaman added a commit that referenced this issue Aug 4, 2020
@sangaman
fix(p2p): handle multiple socket errors
dfce33a 
This changes the peer socket error handling to use `on` instead of `once`
when listening for `error` events to ensure that an unexpected second
`error` event doesn't crash xud after the `once` handler stops listening.
Instead we use `on` to listen to all error events and then manually
remove all listeners from the socket after it's destroyed.

Fixes #1773
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@sangaman sangaman

@kilrau kilrau

@LePremierHomme LePremierHomme

Labels
bug Something isn't working p2p Peer to peer networking P2 mid priority
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

fix(p2p): handle multiple socket errors ExchangeUnion/xud
4 participants
@sangaman @kilrau @raladev @LePremierHomme