Could not publish message error:insufficientPeers

[avenbreaks]

Description

I am running 2 EL Geth, 2 CL Lighthouse, but experiencing insufficientPeers. I have added --subscribe-all-subnets and --target-peers 1.

Config:

lighthouse bn \
--datadir "/mnt/volume_sgp1_04/testnet/beacon-2" \
--testnet-dir "/root/testnet/output/custom_config_data" \
--http \
--eth1 \
--staking \
--http-address=127.0.0.1 \
--http-allow-sync-stalled \
--subscribe-all-subnets \
--http-allow-origin='*' \
--eth1-endpoints "http://127.0.0.1:8547" \
--execution-endpoints "http://127.0.0.1:8552" \
--import-all-attestations \
--genesis-backfill \
--target-peers 1 \
--listen-address '0.0.0.0' \
--http-port=5053 \
--enr-address 159.65.143.195 \
--enr-udp-port=9001 \
--enr-tcp-port=9001 \
--enr-match \
--discovery-port=9001 \
--port=9001 \
--metrics-allow-origin='*' \
--metrics \
--metrics-address "127.0.0.1" \
--metrics-port=5055 \
--logfile-debug-level info \
--logfile-max-number 5 \
--logfile-max-size 200 \
--logfile-compress \
--jwt-secrets="/root/testnet/output/el/jwtsecret" \
--suggested-fee-recipient "0xffffcC6961f8725D09FF09d99560f12F6a8a74a5" \
--graffiti "Cybria-2T" \
--boot-nodes="enr:-Ly4QIJy75hHCCAt68R-37348iQipyVaXtj1PvMqx9x_9eXUDdVd_t6mygwjNqOJGP3TH1hcfu_0Ijrol2OES_3VjmpGh2F0dG5ldHOIAAAAAAAAAACEZXRoMpDenD0nQAARIv__________gmlkgnY0gmlwhJ9Bj8OJc2VjcDI1NmsxoQKEoOJdoWU5aVl4jonrO3f_44l-lk51rZVj6X5_ZhE9oYhzeW5jbmV0cwCDdGNwgiMog3VkcIIjKA"

Logs Geth:

Aug 31 13:47:04 cybria-1 geth[145339]: INFO [08-31|13:47:04.014|miner/payload_building.go:198]                 Stopping work on payload                 id=0x793ca1e572139cda reason=delive
ry 
Aug 31 13:47:04 cybria-1 geth[145339]: INFO [08-31|13:47:04.045|core/blockchain_insert.go:77]                  Imported new potential chain segment     number=566 hash=f3906c..b5c86e bloc
ks=1 txs=0 mgas=0.000 elapsed=2.758ms     mgasps=0.000 dirty=0.00B 
Aug 31 13:47:04 cybria-1 geth[145339]: INFO [08-31|13:47:04.094|core/blockchain.go:2276]                       Chain head was updated                   number=566 hash=f3906c..b5c86e root
=8bff4e..b32ccf elapsed=2.841402ms 

Logs Beacon:

Aug 31 13:37:45 cybria-1 lighthouse[147150]: Aug 31 05:37:45.586 WARN Could not publish message               error: InsufficientPeers, service: libp2p 
Aug 31 13:37:45 cybria-1 lighthouse[147150]: Aug 31 05:37:45.592 INFO Sync committee message                  validator: 58, src: api, slot: 4065, epoch: 127, delay_ms: 163, head: 0x25f5
~@2aba, service: val_mon 

Logs Validator:

Aug 31 13:45:40 cybria-1 lighthouse[149709]: Aug 31 05:45:40.010 INFO Requesting unsigned block               slot: 4105, service: block 
Aug 31 13:45:40 cybria-1 lighthouse[149709]: Aug 31 05:45:40.055 INFO Received unsigned block                 slot: 4105, service: block 
Aug 31 13:45:40 cybria-1 lighthouse[149709]: Aug 31 05:45:40.075 INFO Publishing signed block                 signing_time_ms: 19, slot: 4105, service: block 
Aug 31 13:45:40 cybria-1 lighthouse[149709]: Aug 31 05:45:40.181 INFO Successfully published block            slot: 4105, graffiti: Some("Cybria-1T"), attestations: 1, deposits: 0, block_
type: Full, service: block 
Aug 31 13:45:44 cybria-1 lighthouse[149709]: Aug 31 05:45:44.061 INFO Successfully published attestations     type: unaggregated, slot: 4105, committee_index: 0, head_block: 0x3124ececcfb
57461f595fa1aba4f01292ea4bbaaa60d15d00c346499622a28fb, validator_indices: [21, 12], count: 2, service: attestation 
Aug 31 13:45:44 cybria-1 lighthouse[149709]: Aug 31 05:45:44.939 INFO Successfully published sync committee messages, slot: 4105, head_block: 0x3124ececcfb57461f595fa1aba4f01292ea4bbaaa60
d15d00c346499622a28fb, count: 64, service: sync_committee 
Aug 31 13:45:46 cybria-1 lighthouse[149709]: Aug 31 05:45:46.000 INFO Connected to beacon node(s)             synced: 1, available: 1, total: 1, service: notifier 
Aug 31 13:45:46 cybria-1 lighthouse[149709]: Aug 31 05:45:46.000 INFO All validators active                   slot: 4105, epoch: 128, total_validators: 64, active_validators: 64, current_
epoch_proposers: 32, service: notifier 

Local time: Thu 2023-08-31 13:34:58 +08
Universal time: Thu 2023-08-31 05:34:58 UTC
RTC time: Thu 2023-08-31 05:34:59    
Time zone: Asia/Singapore (+08, +0800)
System clock synchronized: yes                        
NTP service: active                     
RTC in local TZ: no   

Version

Lighthouse v4.3.0-dfcb336
BLS library: blst-portable
SHA256 hardware acceleration: false
Allocator: jemalloc
Profile: maxperf
Specs: mainnet (true), minimal (false), gnosis (true)

Present Behaviour

Describe the present behaviour of the application, with regards to this
issue.

Expected Behaviour

How should the application behave?

Steps to resolve

Please describe the steps required to resolve this issue, if known.

[jimmygchen]

You'd want to increase your target-peer to a much higher number, 1 is not enough. The default is 80 and is a good starting point unless you're resource constrained, and in general higher peer count is better. If you're only connected to 1 peer and the peer is not subscribed to the subnet you're publishing to (for attestations, there are 64 subnets) , then you'd have no one to publish it to, hence the InsufficientPeers error.

[avenbreaks]

So in other beacon nodes must have --subscribe-all-subnets sir?

[jimmygchen]

Yes if you’re running on a small testnet with very limited number of peers.

[avenbreaks]

it works! after I changed to 80 target peers and subnet all, but why is the block production getting slower? I set it to 12 seconds but what I see is more than 12 seconds. but getting error on beacon : No valid eth1_data votes

Sep 01 02:28:29.490 ERRO Error updating deposit contract cache   error: Failed to get remote head and new block ranges: EndpointError(FarBehind), retry_millis: 60000, service: deposit_contract_rpc
Sep 01 02:28:36.000 WARN Low peer count                          peer_count: 1, service: slot_notifier
Sep 01 02:28:36.000 INFO Synced                                  slot: 3266, block:    …  empty, epoch: 102, finalized_epoch: 0, finalized_root: 0xe87d…bb1e, exec_hash: 0x61a0…cbb3 (verified), peers: 1, service: slot_notifier
Sep 01 02:28:42.102 INFO New block received                      root: 0x694853e01b19909bfe1bc99abea9fc992a1afe39c62a2723bb1a5032464b2d76, slot: 3267
Sep 01 02:28:48.001 WARN Low peer count                          peer_count: 1, service: slot_notifier
Sep 01 02:30:18.049 ERRO No valid eth1_data votes, `votes_to_consider` empty, outcome: casting `state.eth1_data` as eth1 vote, genesis_time: 1693496118, earliest_block_timestamp: 1693496058, lowest_block_number: 0, service: deposit_contract_rpc
Sep 01 02:30:18.072 INFO Signed block published to network via HTTP API, publish_delay: 2.30069ms, slot: 3275
Sep 01 02:30:18.119 INFO Valid block from HTTP API               slot: 3275, proposer_index: 45, root: 0x2de3…66e0, block_delay: 69.922441ms

[avenbreaks]

I have a small testnet but why is my blockchain producing blocks very slowly? ETH1 produces blocks in 12s but I feel this is very long.. is it like this? in CL and EL there are no errors or insufficient peers, everything is normal, I have 2 CL (Lighthouse) 2 VN (Lighthouse) 2 EL (Geth)

is there an error in my EL (Geth)?

config:

nohup geth \
	  --http \
	  --http.port 8545 \
	  --http.api=eth,net,web3,admin,engine,txpool,debug,personal\
	  --http.addr=0.0.0.0 \
	  --http.vhosts=*\
	  --http.corsdomain=* \
	  --ws\
	  --ws.api=eth,net,web3,admin,engine,txpool,debug,personal \
	  --ws.port 8546 \
	  --ws.addr=0.0.0.0 \
	  --ws.origins=* \
	  --rpc.allow-unprotected-txs \
	  --rpc.batch-request-limit 1000 \
	  --rpc.batch-response-max-size 25000000 \
	  --txlookuplimit 0 \
	  --light.maxpeers 5\
	  --maxpeers 5 \
	  --bloomfilter.size 2048 \
	  --gcmode=archive\
	  --cache 1024 \
	  --crypto.kzg "gokzg" \
	  --pprof\
	  --pprof.addr "127.0.0.1" \
	  --pprof.port "6060" \
	  --networkid 1122 \
	  --datadir "/mnt/testnet/database/geth/1" \
	  --authrpc.port 8551 \
	  --authrpc.addr="localhost" \
	  --authrpc.vhosts="localhost" \
	  --authrpc.jwtsecret=/mnt/testnet/testnet/output/el/jwtsecret \
	  --port 30303\
	  --discovery.port 30303\
	  --verbosity 3 \
	  --syncmode full \
	  --log.rotate \
	  --log.compress \
	  --log.debug \
	  --log.maxsize 100 \
	  --log.maxage 5 \
	  --log.maxbackups 10 \
	  > /mnt/testnet/testnet/logs/geth-1.log &

[avenbreaks]

CRIT Error whilst producing block info: proposal did not use a builder, block_slot: Slot(2051), message: Irrecoverable("Some endpoints failed, num_failed: 1 http://127.0.0.1:5052/ => RequestFailed(Irrecoverable("Error from beacon node when publishing block: ServerMessage(ErrorMessage { code: 400, message: \"BAD_REQUEST: Unsupported endpoint version: v1\", stacktraces: [] })"))"), service: block

Sep 02 10:36:21.002 INFO Requesting unsigned block               slot: 2051, service: block
Sep 02 10:36:22.147 INFO Received unsigned block                 slot: 2051, service: block
Sep 02 10:36:22.151 INFO Publishing signed block                 signing_time_ms: 3, slot: 2051, service: block
Sep 02 10:36:24.779 CRIT Error whilst producing block            info: proposal did not use a builder, block_slot: Slot(2051), message: Irrecoverable("Some endpoints failed, num_failed: 1 http://127.0.0.1:5052/ => RequestFailed(Irrecoverable(\"Error from beacon node when publishing block: ServerMessage(ErrorMessage { code: 400, message: \\\"BAD_REQUEST: Unsupported endpoint version: v1\\\", stacktraces: [] })\"))"), service: block
Sep 02 10:36:25.001 INFO Connected to beacon node                endpoint: http://127.0.0.1:5052/, version: Lighthouse/v4.3.0-dfcb336/x86_64-linux
Sep 02 10:36:25.001 INFO Connected to beacon node                endpoint: http://127.0.0.1:5052/, version: Lighthouse/v4.3.0-dfcb336/x86_64-linux
Sep 02 10:36:25.002 WARN Beacon node is not synced               el_offline: true, endpoint: http://127.0.0.1:5052/, head_slot: 0, sync_distance: 2051
Sep 02 10:36:25.002 WARN Beacon node is not synced               el_offline: true, endpoint: http://127.0.0.1:5052/, head_slot: 0, sync_distance: 2051
Sep 02 10:36:25.029 INFO Successfully published attestations     type: unaggregated, slot: 2051, committee_index: 0, head_block: 0xbf890d3524df5202368e377454053c965e9f7b533f047554f12b26d6e8d31c8d, validator_indices: [101, 12, 65, 87, 138, 94], count: 6, service: attestation
Sep 02 10:36:25.236 INFO Successfully published sync committee messages, slot: 2051, head_block: 0xbf890d3524df5202368e377454053c965e9f7b533f047554f12b26d6e8d31c8d, count: 150, service: sync_committee
Sep 02 10:36:27.000 ERRO No synced beacon nodes                  synced: 0, available: 1, total: 1, service: notifier

[jimmygchen]

it works! after I changed to 80 target peers and subnet all, but why is the block production getting slower? I set it to 12 seconds but what I see is more than 12 seconds. but getting error on beacon : No valid eth1_data votes

This node received a block from its peer for slot 3267 at 02:28:42, and published a block for slot 3275 at 02:30:18. Based on the slot count and timing, it looks like the chain has 12 second slots (8 slots over 96 seconds). Maybe the validators aren't
proposing blocks?

Sep 02 10:36:25.002 WARN Beacon node is not synced el_offline: true, endpoint: http://127.0.0.1:5052/, head_slot: 0, sync_distance: 2051

Looks like there's something wrong with your EL node, the above logs indicates your EL isn't available.