lbcd rejects other lbcd peers's getdata network message. #36

Closed
opened 2022-05-12 23:10:16 +02:00 by roylee17 · 1 comment
roylee17 commented 2022-05-12 23:10:16 +02:00 (Migrated from github.com)

This can be reproduced by having a lbcd connected to only another lbcd instance.

lbcd --datadir=~/tmp/lbcd-test/datadir --logdir=~/tmp/lbcd-test/logdir --nolisten --norpc --connect 127.0.0.1:9246

The catching up (sync from scratch) node soon lost the peer and stuck since we indicate it to connect only one lbcd node.

2022-05-12 09:17:29.334 [INF] MAIN: RPC service is disabled
2022-05-12 09:17:29.335 [INF] MAIN: Version 0.22.200-beta
...
2022-05-12 09:17:29.985 [INF] SYNC: New valid peer 127.0.0.1:9246 (outbound) (/btcwire:0.5.0/LBRY.GO:0.22.200/)
2022-05-12 09:17:29.985 [INF] SYNC: Syncing to block height 1158573 from peer 127.0.0.1:9246
2022-05-12 09:17:29.985 [INF] SYNC: Downloading headers for blocks 1 to 40000 from peer 127.0.0.1:9246
2022-05-12 09:17:30.087 [INF] SYNC: Verified downloaded block header against checkpoint at height 40000/hash 4c55584b068108b15c0066a010d11971aa92f46b0a73d479f1b7fa57df8b05f4
2022-05-12 09:17:30.087 [INF] SYNC: Received 40000 block headers: Fetching blocks
2022-05-12 09:17:40.087 [INF] SYNC: Processed 16254 blocks in the last 10s (64833 transactions, height 16254, 2016-07-22 14:47:41 -0700 PDT)
2022-05-12 09:17:49.913 [INF] LBRY: Invalid update operation: name or ID mismatch at 25468 for: cookie21, f854f24c664c81a012f3bc7eca6b693d211e6bfd
2022-05-12 09:17:49.920 [INF] LBRY: Invalid update operation: name or ID mismatch at 25477 for: cookie22, 396b783e61d0e6844d08089dc6f6775f693b20e6
2022-05-12 09:17:49.927 [INF] LBRY: Invalid update operation: name or ID mismatch at 25480 for: pug, a97a7fd002dcea85afab0a0211342c7eb8237c4b
2022-05-12 09:17:49.940 [INF] LBRY: Invalid update operation: name or ID mismatch at 25489 for: pug, f13758adbce6204aa4b941059f3ba85bc4820e4a
2022-05-12 09:17:50.090 [INF] SYNC: Processed 9364 blocks in the last 10s (114463 transactions, height 25618, 2016-08-09 00:40:16 -0700 PDT)
2022-05-12 09:18:00.090 [INF] SYNC: Processed 8156 blocks in the last 10s (113434 transactions, height 33774, 2016-08-24 03:41:00 -0700 PDT)
2022-05-12 09:18:07.737 [INF] CHAN: Verified checkpoint at height 40000/block 4c55584b068108b15c0066a010d11971aa92f46b0a73d479f1b7fa57df8b05f4
2022-05-12 09:18:07.739 [INF] SYNC: Downloading headers for blocks 40001 to 80000 from peer 127.0.0.1:9246
2022-05-12 09:18:07.843 [INF] SYNC: Verified downloaded block header against checkpoint at height 80000/hash 6e9facdfb87ba8394a46c61a7c093f7f00b1397a2dabc6a04f2911e0efdcf50a
2022-05-12 09:18:07.843 [INF] SYNC: Received 40000 block headers: Fetching blocks
2022-05-12 09:18:08.022 [INF] SYNC: Lost peer 127.0.0.1:9246 (outbound)
2022-05-12 09:18:08.026 [WRN] SYNC: No sync peer candidates available

The other lbcd instance complains and ban the catching up node.

2022-05-12 09:18:08.022 [WRN] PEER: Misbehaving peer 127.0.0.1:57637 (inbound): getdata -- ban score increased to 129
2022-05-12 09:18:08.022 [WRN] PEER: Misbehaving peer 127.0.0.1:57637 (inbound) -- banning and disconnecting
2022-05-12 09:18:08.022 [INF] SRVR: Banned peer 127.0.0.1 (inbound) for 24h0m0s
2022-05-12 09:18:08.022 [INF] SYNC: Lost peer 127.0.0.1:57637 (inbound)
2022-05-12 09:18:11.939 [INF] MAIN: RAM: using 5.7 GB with 33.6 available, DISK: using 117.4 GB with 465.0 available
2022-05-12 09:18:13.025 [WRN] SYNC: Received done peer message for unknown peer 127.0.0.1:57640 (inbound)
This can be reproduced by having a lbcd connected to only another lbcd instance. `lbcd --datadir=~/tmp/lbcd-test/datadir --logdir=~/tmp/lbcd-test/logdir --nolisten --norpc --connect 127.0.0.1:9246` The catching up (sync from scratch) node soon lost the peer and stuck since we indicate it to connect only one lbcd node. ``` 2022-05-12 09:17:29.334 [INF] MAIN: RPC service is disabled 2022-05-12 09:17:29.335 [INF] MAIN: Version 0.22.200-beta ... 2022-05-12 09:17:29.985 [INF] SYNC: New valid peer 127.0.0.1:9246 (outbound) (/btcwire:0.5.0/LBRY.GO:0.22.200/) 2022-05-12 09:17:29.985 [INF] SYNC: Syncing to block height 1158573 from peer 127.0.0.1:9246 2022-05-12 09:17:29.985 [INF] SYNC: Downloading headers for blocks 1 to 40000 from peer 127.0.0.1:9246 2022-05-12 09:17:30.087 [INF] SYNC: Verified downloaded block header against checkpoint at height 40000/hash 4c55584b068108b15c0066a010d11971aa92f46b0a73d479f1b7fa57df8b05f4 2022-05-12 09:17:30.087 [INF] SYNC: Received 40000 block headers: Fetching blocks 2022-05-12 09:17:40.087 [INF] SYNC: Processed 16254 blocks in the last 10s (64833 transactions, height 16254, 2016-07-22 14:47:41 -0700 PDT) 2022-05-12 09:17:49.913 [INF] LBRY: Invalid update operation: name or ID mismatch at 25468 for: cookie21, f854f24c664c81a012f3bc7eca6b693d211e6bfd 2022-05-12 09:17:49.920 [INF] LBRY: Invalid update operation: name or ID mismatch at 25477 for: cookie22, 396b783e61d0e6844d08089dc6f6775f693b20e6 2022-05-12 09:17:49.927 [INF] LBRY: Invalid update operation: name or ID mismatch at 25480 for: pug, a97a7fd002dcea85afab0a0211342c7eb8237c4b 2022-05-12 09:17:49.940 [INF] LBRY: Invalid update operation: name or ID mismatch at 25489 for: pug, f13758adbce6204aa4b941059f3ba85bc4820e4a 2022-05-12 09:17:50.090 [INF] SYNC: Processed 9364 blocks in the last 10s (114463 transactions, height 25618, 2016-08-09 00:40:16 -0700 PDT) 2022-05-12 09:18:00.090 [INF] SYNC: Processed 8156 blocks in the last 10s (113434 transactions, height 33774, 2016-08-24 03:41:00 -0700 PDT) 2022-05-12 09:18:07.737 [INF] CHAN: Verified checkpoint at height 40000/block 4c55584b068108b15c0066a010d11971aa92f46b0a73d479f1b7fa57df8b05f4 2022-05-12 09:18:07.739 [INF] SYNC: Downloading headers for blocks 40001 to 80000 from peer 127.0.0.1:9246 2022-05-12 09:18:07.843 [INF] SYNC: Verified downloaded block header against checkpoint at height 80000/hash 6e9facdfb87ba8394a46c61a7c093f7f00b1397a2dabc6a04f2911e0efdcf50a 2022-05-12 09:18:07.843 [INF] SYNC: Received 40000 block headers: Fetching blocks 2022-05-12 09:18:08.022 [INF] SYNC: Lost peer 127.0.0.1:9246 (outbound) 2022-05-12 09:18:08.026 [WRN] SYNC: No sync peer candidates available ``` The other lbcd instance complains and ban the catching up node. ``` 2022-05-12 09:18:08.022 [WRN] PEER: Misbehaving peer 127.0.0.1:57637 (inbound): getdata -- ban score increased to 129 2022-05-12 09:18:08.022 [WRN] PEER: Misbehaving peer 127.0.0.1:57637 (inbound) -- banning and disconnecting 2022-05-12 09:18:08.022 [INF] SRVR: Banned peer 127.0.0.1 (inbound) for 24h0m0s 2022-05-12 09:18:08.022 [INF] SYNC: Lost peer 127.0.0.1:57637 (inbound) 2022-05-12 09:18:11.939 [INF] MAIN: RAM: using 5.7 GB with 33.6 available, DISK: using 117.4 GB with 465.0 available 2022-05-12 09:18:13.025 [WRN] SYNC: Received done peer message for unknown peer 127.0.0.1:57640 (inbound) ```
roylee17 commented 2022-05-26 06:58:28 +02:00 (Migrated from github.com)

Currently, the OnGetData() handler penalizes peers requesting large number of blocks.

https://github.com/lbryio/lbcd/blob/master/server.go#L652:L652

For peers, especially those sync from scratch, trying to catch up to checkpoints, they would request as many as the wire.MaxInvPerMsg allows, and get themselves banned quickly.

The options here are either relaxing the checking heuristics/logics on the handler side, or reduce the block on the requesting side.

Currently, the `OnGetData()` handler penalizes peers requesting large number of blocks. https://github.com/lbryio/lbcd/blob/master/server.go#L652:L652 For peers, especially those sync from scratch, trying to catch up to checkpoints, they would request as many as the `wire.MaxInvPerMsg` allows, and get themselves banned quickly. The options here are either relaxing the checking heuristics/logics on the handler side, or reduce the block on the requesting side.
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: LBRYCommunity/lbcd#36
No description provided.