[Solved] vNode sync errors since version 20210313_3

[fredlee]

Hey @Support @consensus,

I first noticed problems syncing Shard 2 as I am pending for committee on it. @Josh_Hamon was experiencing similar issues on the exact same block and wrote about it in his thread Shard 2 Stalling at 433077 on Multiple vNodes

I got a reply back from @support about a week ago that I should change GETHPORT from “” to 80, but that made no difference.

I’ve been running some vNode tests over the past weeks and narrowed it down to a change in 20210313_3 that either broke syncing or just implemented better error control that prevents it from completing. If I roll back to 20210302_1 I can get past the block with error and then switch back to a newer release. This can happen multiple times so I found it best to stick to the old release until it caught up to a higher block height.

I have reinstalled and restarted syncing from scratch numerous times, but I end up with the same errors. I finally decided to run a full node and sync all shards to see if I noticed problems in other shards as well. Please note that there are no problems with beacon syncing, this only happens when syncing specific shard blocks. I am just cutting out small parts of the logs because there is a lot of information that does not need to be repeated.

In my latest test, I am running with infura using the script from this post: How to setup your own node in a blink of an eye

docker run --restart=always --net inc_net -p $node_port:$node_port -p $rpc_port:$rpc_port \
  	-e NODE_PORT=$node_port -e RPC_PORT=$rpc_port -e BOOTNODE_IP=$bootnode \
	-e GETH_NAME=$geth_name -e GETH_PROTOCOL=$geth_proto -e GETH_PORT=$geth_port \
	-e FULLNODE=$fullnode -e MININGKEY=${validator_key} -e TESTNET=false -e LIMIT_FEE=1 \
	-v ${data_dir}:/data -d --name inc_mainnet incognitochain/incognito-mainnet:${latest_tag}

SHARD 0 Stalls at 169583

shardprocess.go:141 [INF] BlockChain log: SHARD 0 | InsertShardBlock 169584 with hash b976c1a5d978b11fced6f8ed0d70334df46b1b3e6904869b4f3c41f31dac5705 Prev hash: de7de9fad3221af8bc58103f5f550405a1823b7b8ee8dddc0beab5b48342362f
shardprocess.go:189 [INF] BlockChain log: SHARD 0 | Verify Pre Processing, block height 169584 with hash b976c1a5d978b11fced6f8ed0d70334df46b1b3e6904869b4f3c41f31dac5705
shardproducer.go:891 [INF] BlockChain log: Build Request Action Pairs [], metadata value &{BlockHash:[142 13 153 40 150 220 8 7 149 224 36 49 34 199 221 51 56 251 39 217 10 55 40 11 37 173 125 132 95 252 194 137] TxIndex:11 ProofStrs:[+HGgriIXyY7hq43IhXghy/UHRSP215RKF3B6ZEHbOmZM9QSg1KIeTPTCjoNzTKFSNKjwBhdVngW5mLupz5QAh2AsA1OAgICAgICg5YIVvoSMEpPdOBIQNZ2ESFVTAAqCtnQQQG0YO0Ktu92AgICAgICAgA== +QHxgKDZZz0tn8BRzQwTfrbo5vp5LKAkZRiMNAjIZiXXb2OWoKB8CQ1hHYwFhNgt76JvMRe0Eq3ueZvHNNCPyXu/60Tb0KBf8GGSBhHAEje2HSpkPCj5QDqS3kkAXywx5BXtR1I9UKAvZP1lleGQUeClGw135ACGl5n8qbdixB0UhrV7J9havKAmpaXMS7ai74868HrvQ+Hq+NXXTOwXy++z+7Tck95R46D6T7TvHP2QXHD7IjuDyLPj8M9C967yjTvxubUV3r+XaaB86H7oA1htaYXXp9fDCv+G34Sh0xIua5IiKZQqHblVraA6M88yowqriuXyrCTWlpuuqd7J3typSqLcpAkzQxNOGqCd8r4mBVmmcn3R1bpJnnjqUKbtGQjtwfIZ57RyBbYMRaBK9AS9BQjrkLaIyBZXj++LyhgTU3TB05kNDkfvrMJU2KDXDcXzrGlYX1ZHcI3kJOpMy6GvwhYzNN+CVxAilmkOnqAaBKghV2vQK9H/mk3jjilD23rHtC4H70DIcnscltwAPqBwzV5SO8HSe+73XMrV2+XlX4zV3w5edjRUor1sU2lKl6DK8XAIcAKzhynG+oWKikD/x9om9oUE4el298Yizl124aDBoUFSH9+3StGgOdv1auCKDMYahm31c+LcDvmsXrZCPIA= +QLsILkC6PkC5QGDCYiEuQEAAAAAgAAAAAAAAAAAAAAAAEAAAAAAAAAAAAAAAAAAAAAAQAAAAAAAAAAACAAAAABAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAACAAAAAAAAAAAAgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAEAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAACACAAAAAAAAAAAAAAAAEAIAAAAAAAAQAAAAAAAAAAAAAAQAAggAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABPkB2viblAAAAAAACF1HgLcxGbZErl7NIrN2+GOg3fJSrRviyJtpwrBo/DeNqpUrp/FjxKEWKPVaTfUjs++gAAAAAAAAAAAAAAAAxq+DllPuZW94P7DXlcMwwXtnUpqgAAAAAAAAAAAAAAAAAmHbWv+OXsmfvI+7pdS5+OzUTsegAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAmH1J+RTjQAD5ATqUAmHbWv+OXsmfvI+7pdS5+OzUTsfhoC1LWXk1881n+y7r8dtN68k0zuXHuqcVP5gP2+sudAhOuQEAAAAAAAAAAAAAAAAAAAAAAAAIXUeAtzEZtkSuXs0is3YAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAYAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAKO7+EgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAGcxMlJxa0JaSFlpMThqNVZINUpiY204bzZIUmpxYkRTV2JWd0FUc054R2oxVkpweU1lM3BkTnBNWHl1TVg0N1NnbWVtVkJEMWN6clJYckdDc3RZRjRScGNVZFJFSFdIb1B5NzY4enRIAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==] IncTokenID:8c3a61e77061265aaefa1e7160abfe343c2189278dd224bb7da6e7edc6a1d4db MetadataBase:{Type:80}}
shardproducer.go:895 [ERR] BlockChain log: Build Request Action Error -1006: Build request action error%!!(MISSING)(EXTRA []interface {}=[]) -1007: Verify proof and parse receipt%!!(MISSING)(EXTRA []interface {}=[]) invalid character 'i' looking for beginning of value
Verify proof and parse receipt
github.com/incognitochain/incognito-chain/metadata.NewMetadataTxError
	/Users/autonomous/projects/incognito-chain/metadata/error.go:158
github.com/incognitochain/incognito-chain/metadata.(*IssuingETHRequest).verifyProofAndParseReceipt
	/Users/autonomous/projects/incognito-chain/metadata/issuingethrequest.go:198
github.com/incognitochain/incognito-chain/metadata.(*IssuingETHRequest).BuildReqActions
	/Users/autonomous/projects/incognito-chain/metadata/issuingethrequest.go:164
github.com/incognitochain/incognito-chain/blockchain.CreateShardInstructionsFromTransactionAndInstruction
	/Users/autonomous/projects/incognito-chain/blockchain/shardproducer.go:890
github.com/incognitochain/incognito-chain/blockchain.(*BlockChain).verifyPreProcessingShardBlock
	/Users/autonomous/projects/incognito-chain/blockchain/shardprocess.go:369
github.com/incognitochain/incognito-chain/blockchain.(*BlockChain).InsertShardBlock
	/Users/autonomous/projects/incognito-chain/blockchain/shardprocess.go:190
github.com/incognitochain/incognito-chain/blockchain.(*ShardChain).InsertBlock
	/Users/autonomous/projects/incognito-chain/blockchain/shardchain.go:258
github.com/incognitochain/incognito-chain/syncker.InsertBatchBlock
	/Users/autonomous/projects/incognito-chain/syncker/utils.go:105
github.com/incognitochain/incognito-chain/syncker.(*ShardSyncProcess).streamFromPeer
	/Users/autonomous/projects/incognito-chain/syncker/shardsyncprocess.go:300
github.com/incognitochain/incognito-chain/syncker.(*ShardSyncProcess).syncShardProcess
	/Users/autonomous/projects/incognito-chain/syncker/shardsyncprocess.go:204
runtime.goexit
	/usr/local/go/src/runtime/asm_amd64.s:1357
Build request action error

SHARD 1 Completes syncing, no issues

SHARD 2 Stalls at 433077

shardproducer.go:891 [INF] BlockChain log: Build Request Action Pairs [], metadata value &{BlockHash:[189 54 99 126 80 108 3 122 169 149 17 159 24 209 186 83 16 89 202 15 226 110 248 233 216 110 172 254 21 193 185 54] TxIndex:55 ProofStrs:[+PGgRjW5sVVsj3zhrJifC9hL3TiCcbjYQXIOmkwHePs0096gzizV7dgVW79wKhF75Y59GF6X11GKCYA4QP4RUlkLT/SgdNcuRxQBg5N78BtHHkdb+0QFEZKvhBq1aJpbMPTxfoCgccaSM3p+sEhUI/lCqtB5KMrErRegRPU1MxOV/FTqWSugpgVukM9HfLcyLyYcjNDER7E92xwSxQuPD+zQdY0ZjGCgwNiYsto99so4qxXhbJS52SE9EetkqT3WfsfKwb513EeAgKDA2daKmG6DRwyIKfQhIepjZG5honFHqCAkAZM81Khlo4CAgICAgICA +QIRoKpwX0ILdcePK9sogJO+sDJ5PlO6T0ovW2hAeB5vptv6oMtkdkgLCtIRixTgHjOv2ajBt1GqbiAZq2B+m5Jv7AJsoDO17WMsrMKfkG4cCRvPnZ0CZSAUVs/o5xdBNghDSQ8joDzwa62XBkqQCH0zncfppYa10U7WRCYS5lHDySPMThqjoOUATo3n5H8QffwslriV9nrRaRSW5FN2d1mTGUiulHctoN5PAx3HMv2VZ7C4/W9oDXF4bi9yR6ZgjEzoxMsbq4SBoLaKqS4q7jCUsCJKaYX/6eYI55JRHTuNzU4q45UMQVFLoBeyiGRYcwF+LepJ4LlIYmKdxifP1btUFMtTISJF8NIXoHtiqJ2cwL0uJ31rR27ztcac62z+xUeBVXNQXvQz+mmFoGvuvyMl9XI77PMuxjy9qt5pOfZDh+oDtWw15WhwolokoPUSkZ4n/QEpOO4txIqtmwElFukhcIPa3ZRrUm/Vt5YKoDImAdNPrPcJ4Wqu50fs4d5BXzOM0XS2TShaofXijQmcoG77usbWWB66J4nrz7YdNXc3WBTc0LbGpBf0Ly3YpQCBoNoc8ipFoHiZ2MNpbjr1owgh7cPPc895GTr2QZ7VPEi9oN7slonN27tJk1ZoTn5vaoi+5VN2TEebpX1PBy72teIhoIoAqdDZtg/MuTc5UHfospC+ihIEJvMSDfVdlRPoepswgA== +QOJILkDhfkDggGDUXOEuQEAAAAAAAAABAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABAAAAAAACAAAAAAAAAAAAAAAAAAAAAAAACAAAAAAAAAAAAAAAAAAKAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAgAEAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAACICAAAAAAAAAAAAAAAAAAIAAAAAAAAQAAAAAAAAAAAAAAQAAggAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAEAAABAAEAAAAAAAAAAAAAAAAAAAAAAAAAgAAAAAABPkCd/iblJmP/h5D+s/7lB3DN90EaNUrpbSK+GOgjFvh5evsfVvRT3FCfR6E890DFMD3sikeWyAKyMfDuSWgAAAAAAAAAAAAAAAApvVDIL0fvBmPoiSfT6Th7pJ0kWegAAAAAAAAAAAAAAAAAmHbWv+OXsmfvI+7pdS5+OzUTsegAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAD4m5SZj/4eQ/rP+5QdwzfdBGjVK6W0ivhjoN3yUq0b4sibacKwaPw3jaqVK6fxY8ShFij1Wk31I7PvoAAAAAAAAAAAAAAAAKb1QyC9H7wZj6Ikn0+k4e6SdJFnoAAAAAAAAAAAAAAAAAJh21r/jl7Jn7yPu6XUufjs1E7HoAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAmJaA+QE6lAJh21r/jl7Jn7yPu6XUufjs1E7H4aAtS1l5NfPNZ/su6/HbTevJNM7lx7qnFT+YD9vrLnQITrkBAAAAAAAAAAAAAAAAAJmP/h5D+s/7lB3DN90EaNUrpbSKAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAGAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAJiWgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABnMTJSczdOM0RRNXp1bTE5bm5hVWhOcmNOTWdtY0Q5ZVJRcmdQeUxvdzl4Y3o2NER6VEg5d0RGQnEyVEN6TWtVSFc3VmNSOHc1YkJucDVxVkV2cW9VTnhlMk1GRkdVTExNRnhSMnRnVAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA=] IncTokenID:98be8fc9144f3f217eefbde2cad9a2e30516e9628947d8aa96b08f08375c5e20 MetadataBase:{Type:80}}
shardproducer.go:895 [ERR] BlockChain log: Build Request Action Error -1006: Build request action error%!!(MISSING)(EXTRA []interface {}=[]) -1007: Verify proof and parse receipt%!!(MISSING)(EXTRA []interface {}=[]) invalid character 'i' looking for beginning of value
...

SHARD 3 Completes syncing, no issues

SHARD 4 Completes syncing, no issues

SHARD 5 Completes syncing, no issues

SHARD 6 Stalls at 909062

shardprocess.go:189 [INF] BlockChain log: SHARD 6 | Verify Pre Processing, block height 909063 with hash 128819200c8c56557aaa1fc13d6af3111871ef9a6e044f01db27734233a009c8
shardproducer.go:891 [INF] BlockChain log: Build Request Action Pairs [], metadata value &{BlockHash:[228 62 42 72 157 225 175 225 47 60 111 144 196 19 246 141 116 234 21 47 161 209 27 177 176 76 37 43 182 79 108 113] TxIndex:208 ProofStrs:[+QExoFZ5+YxfKNNQWlGwOnMI4dufCrhbsCTRUJRvKy6XEf8UoOvPufChJpv6qnNQ9erYHIOIjfdLdmZ/eEyCCbhgqW5SoDY7AGFhkiDgrT6NYqEwhLLYxjj7zxOYRq3xFQPXOcCgoLmHPcaMYZbdXLVkpyRaGW+Wks9ffsjPKvfifi1MjpZSoJVxq5FJ3ChHvMinO6ZzGXI9f08bgN2yngQt27DVPPHnoM8iFqS0eAO1TF2ZhvVNO+1+m6txN6q18lN0uuDUg9zxoHw4GOm3VWS1hw36HuPezo1iCvcTvl9VYnkt4O/kdQfnoKjl+vqPEQ+Qg6yoGJ0NpcdSzRcImXoRva99QeQEEw0koPofdJzljq6bwzjjycayWL9gQqqiglnWuP73XUjXL9qXgICAgICAgIA= +FGg7WisvKwk3D6sijWdUCED52oG4O2g+zVQGi2PkkrGeo+glw7ID/W35JIvBNrOXZ5ivYmsrVWB6+d+u4mOcoHSC4qAgICAgICAgICAgICAgIA= +PGAgICAgICAgKCu3BQyMa2+Nqw7kZW6Paz7reDqYvsBU6MqRz5ekSPVpqBf5fG/6+2zT2lVMdRz498UxH06tbXdYFoks+Lfe57Om6AIozoNIJHCg8nC4Wgkwg9HmaH34V6j4ywqn2+J/l5C1qAPsUWSUxtoneSIkl8nbFwIw4ZnGCoQ6UZR7DMEMs0606APo0AMsJrcNK3z8gmjxBOGc8jNLO8KoRbKhMnYSpHrCaDVf7tQUiYRhp4xcfrHHj+gVuU5T5g3YXGESggdkBJ4iaCkl9OM6i6LCofaEn6ZYriHJPPCQO3h8j3uqyqSKo3N24CA +QIRoLRGRP+ix+rYaeY/Bt4BE6u0aqW8WVE0x2XND48aF+UNoI3z0PS7B67cvhpwwfCntDHzyKXwRni5qh2451HsyZrIoHsJCQy0bEmjy3bk5IyXiE+I6FpumNTEuKOyoN7BuMQ+oPnQJ005kbGsLTq6vitgNZCycykuaVCN/0ss5G6g0Ov6oJ6hcDA/dPbmtGdogX7ojDUySVAcWsxDbMs9KltBLY0coAp1Wzl8XCO04MKTJUvaVLYSdqgfJqHtAsqf+bxZCOKToKtMBqWhK/x4Gv/iX28b/vdDibNEHFkfXYFNEaC95OCKoCA+zsYNL3h0+T2LTvEBdmx2kutkujrkXc16hkfJ6TI2oE/erx3SdueqKqHeQkOeu9s4xg6rCSuoDC8qAqZX9nd/oNwG+bI5UoGn3qus6d1V7Xn7gM3SqD2MsfwbSR5VuPxpoNUiQppdHZq2ZIXTF0VQm2N/BhP5F6/LbIPFPdkeXqi4oFNqPnxiqcBC/8zURmaK45XmaNHglpdZWSbXHthYCeVtoBKg6Z6rVXpROJvStG8tETXKIIa7h2HEs1PnzRE2sqYQoA9plFZWBMEQvhRbMSAlwDxgxzrsi48G6Se1IvnxZV7UoCvjDzN6vU8dnNxLFCN1eOxM/Mj4Ipuc1RExWunh8RsxoBjvSxU8qG97ASGRtcoUIxY41kB6mZj0H8Zynzeky8FAgA== +QLsILkC6PkC5QGDsiTYuQEAAAAAAAAAAACAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAIAAAAAAAAAAAAAAAAAAEAAAAAAAAAAAAAAAAAAAAAACAAACAAAAAAAAAAAAAAAAAAAAAAAAAAgAAAAAAAAAAAAAAAACAAAAAAAAAAAAAAAAAAAEAAAAAAAAAAAAAAAAAAAAAAAAAQAAAAAAAEAAAAAAAAAAAABAAAgAAAAACAAAAAAAAAAAAAAAAAAAAAQAAAAAAAAAAAAAAQAAgAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAABAAAAAAAIAAAAAAAAAAAAAAAAAAAAAAAAAAAAPkB2viblKC4aZHGIYs2wdGdSi6esM42ButI+GOg3fJSrRviyJtpwrBo/DeNqpUrp/FjxKEWKPVaTfUjs++gAAAAAAAAAAAAAAAAsF/Jqjefio3Uq3pjUU7hvNvoPHmgAAAAAAAAAAAAAAAAl4dTVe9VrjVhMCnfixyM+PickGagAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAeQUMa75ATqUl4dTVe9VrjVhMCnfixyM+PickGbhoC1LWXk1881n+y7r8dtN68k0zuXHuqcVP5gP2+sudAhOuQEAAAAAAAAAAAAAAAAAoLhpkcYhizbB0Z1KLp6wzjYG60gAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAYAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAHkFDGuAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAGcxMlMzeG5HaWlqOTZadlZ5d0RSUHdLYnlmZ1ZweWIyMnpwNDhzY0tZRVV5VHhNcThjazVkb0pjd25IckZUamRMRUxzTjlEZUp6QVVxV2QxS2dKS1ZnemJxeFFHV3JBQjVLODRTWDkxAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==] IncTokenID:1ff2da446abfebea3ba30385e2ca99b0f0bbeda5c6371f4c23c939672b429a42 MetadataBase:{Type:80}}
shardproducer.go:895 [ERR] BlockChain log: Build Request Action Error -1006: Build request action error%!!(MISSING)(EXTRA []interface {}=[]) -1007: Verify proof and parse receipt%!!(MISSING)(EXTRA []interface {}=[]) invalid character 'i' looking for beginning of value

SHARD 7 Completes syncing, no issues

When I search for these block numbers on this forum, I find other people experiencing the same problems. Some saying they managed to solve it or it solved itself. Can someone please explain why these particular blocks raise errors? Did you break the syncing months ago and never bothered to fix it, because it only affects new nodes? Are you not able to replicate this on a fresh install?

[Mike_Wagner]

@fredlee Excellent troubleshooting and write up!! I only managed to find a few Instruction Hash Errors – however trying to search through those massive error logs using a web browser with the pNode /browser endpoint is a steep challenge.

@fredlee

When I search for these block numbers on this forum, I find other people experiencing the same problems. Some saying they managed to solve it or it solved itself.

I had a shard 2 stall fix itself. I did not resync that particular pNode having had just finished (and subsequently failed to fix) a shard stall on another pNode. The “fixed”-shard-2-stall pNode hasn’t joined one of the other problem shard chains – yet – so I’m still quite hesitant to give it a clean bill of health.

Nonetheless perhaps your excellent post will assist the team finding the root cause of the sync failures and render 3GiB error log requests moot.

@fredlee Slightly off-topic - I’m curious about the size of your fullnode sync. I seem to recall the size of the beacon chain is ~15GiB presently. If each shard is roughly the same size, that should make your fullnode ~135GiB. Is that estimate close?

[fredlee]

@Mike_Wagner

Slightly off-topic - I’m curious about the size of your fullnode sync. I seem to recall the size of the beacon chain is ~15GiB presently. If each shard is roughly the same size, that should make your fullnode ~135GiB. Is that estimate close?

At the moment I have left the node stalled on shard 0,2 and 6 in case the team needs more logs, testing or even comes up with a workaround or update. My mainnet is 74GiB right now. If I calculate my block heights for all shards combined, I’m roughly at 80%. That would give a full node ~92GiB. But that is just an estimate since the shards does seem to differ quite a lot in size.

     bytes    folder     block
18 141 863    beacon  [1240539]
   855 509    shard0  [ 169584]
10 956 895    shard1  [1242694]
 1 537 298    shard2  [ 433077]
11 827 457    shard3  [1239751]
 9 240 702    shard4  [1240383]
 7 978 078    shard5  [1240423]
 4 147 658    shard6  [ 909062]
12 331 384    shard7  [1242307]

[fredlee]

Tried the latest release 20210531_1 unfortunately no change on this issue on current data. I have once again restarted syncing from scratch to see if it makes any difference.

This time I was getting a lot of Sync too fast all the time and syncing was just abysmal.

2021-05-31 11:22:39.866 connmanager.go:398 [INF] Peerv2 log: [SyncBeacon] from 7707 to 1242967 
2021-05-31 11:22:39.866 connmanager.go:470 [INF] Peerv2 log: [stream] Request Block type BlkBc from peer  from cID 255, [7707 1242967] 
2021-05-31 11:22:39.866 blockrequester.go:235 [INF] Peerv2 log: [stream] Requesting stream block type BlkBc, spec false, height [7707..1242967] len 2, from 255 to 255, uuid = 5acadffb-cc8e-4009-a54b-6a264d72b7b7
2021-05-31 11:22:39.866 connmanager.go:490 [ERR] Peerv2 log: [stream] rpc error: code = Canceled desc = context canceled
2021-05-31 11:22:42.222 syncker.go:164 [INF] Syncker log : syncker: receive beacon block 1242969 

2021-05-31 11:22:42.264 connmanager.go:490 [ERR] Peerv2 log: [stream] rpc error: code = Unknown desc = Sync too fast, last time sync blocks of CID 255 from height 7707 is 2021-05-31 11:22:35.550777654 +0000 UTC
2021-05-31 11:22:42.264 connmanager.go:398 [INF] Peerv2 log: [SyncBeacon] from 7707 to 1242967 
2021-05-31 11:22:42.264 connmanager.go:470 [INF] Peerv2 log: [stream] Request Block type BlkBc from peer  from cID 255, [7707 1242967] 
2021-05-31 11:22:42.265 blockrequester.go:235 [INF] Peerv2 log: [stream] Requesting stream block type BlkBc, spec false, height [7707..1242967] len 2, from 255 to 255, uuid = 7d06bd33-c5f0-4916-b6c4-c93e635e56e3
2021-05-31 11:22:42.265 syncker.go:164 [INF] Syncker log : syncker: receive beacon block 1242969 
2021-05-31 11:22:42.266 syncker.go:164 [INF] Syncker log : syncker: receive beacon block 1242969 

Why does this happen?

I stopped everything, restarted, and then the problem went away. Now syncing at normal speed. I’ll update the post once shards start to sync up to the infamous blocks.

[trungtin2qn1]

Hi @fredlee ,

I see the problem you’re having is “not running Geth correctly”. So would you mind checking again for your Geth. If you’re running node in docker environment, you can try to docker inspect and send the log of it to us

Thanks

[fredlee]

Thank you for the reply. What is the geth supposed to be then? Why does this only affects a handful of blocks in 3 of the 8 shards and none in the beacon chain?

I am using the inc_node_installer.sh script and I only changed my infura api value and validator key.

Is the port supposed to be 80 even tho the protocol is https?

Taken from docker inspect:

   "GETH_NAME=mainnet.infura.io/v3/26e65277...",
   "GETH_PROTOCOL=https",
   "GETH_PORT=80",

I’ll send the full text to you as well (with the correct infura hash) =)

[fredlee]

Thanks to @trungtin2qn1 I got it to continue syncing shard 0, 2 and 6 again!!!

If I understand correctly, when syncing, there are only certain blocks that need to be looked up with GETH? If it is not configured correctly or if the call fails, then we get the error:

-1007: Verify proof and parse receipt%!!(MISSING)(EXTRA []interface {}=[]) invalid character ‘i’ looking for beginning of value

Which falls through into things like

-1051: Instruction Hash Error
Expect instruction hash to be 711455acaa89a9f8d3baa2e586dfd29b8… but get 000000000000000000000000000… at block 909063

In my original setup, I am not sure what was set wrong, but after contacting support they told me to follow the official instructions and set GETHPORT to 80.

Turns out the setup instructions are wrong? Accessing infura.io with https on port 80 seems to be a bad idea. @trungtin2qn1 told me to go back to -e GETH_PORT=, and with the latest release, it works just fine!

For anyone else troubleshooting. docker inspect inc_mainnet is a good way to make sure that the “Env” variables have been set correctly and not containing any extra characters or incorrect strings.

Mine looks like this now.

            "Env": [
                "MININGKEY=12NJX93MjCm8Z1wrKDNPLsS3zLN8...",
                "LIMIT_FEE=1",
                "NODE_PORT=9400",
                "RPC_PORT=8400",
                "BOOTNODE_IP=mainnet-bootnode.incognito.org:9330",
                "GETH_PROTOCOL=https",
                "GETH_PORT=",
                "FULLNODE=1",
                "GETH_NAME=mainnet.infura.io/v3/26e7865275720d452...",
                "TESTNET=false",
                "PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"
            ],

@consensus:
May I, first of all, suggest better error handling when GetETHHeader or GetMostRecentETHBlockHeight fails. As it is right now, there is quite a stretch to understanding that the error on just a handful of blocks in the entire chain has anything to do with the infura setup.

You may also want to update this post if port 80 is wrong. As well as the source file on github.

I’ll let it all run now and see if it syncs up to latest block on all shards.

[trungtin2qn1]

Thanks for your feedback, we will consider for updating with your advises. Your real problem is port 80 is the default port for HTTP protocol but infura is using HTTPS so it should be default port is 443. But we can by pass that by just replace port by an empty string “”. Besides you should not public mining key and your infura api key like that. it is not safety, someone can use it for bad behavior.
And one last things, would you mind close the issue which you have opened on GitHub.

[fredlee]

@trungtin2qn1

Your real problem is port 80 is the default port for HTTP protocol but infura is using HTTPS so it should be default port is 443 .

Yeah, I thought that was kinda strange. But @Rocky told me in his PM that I should set it to 80 instead of “”. That in combination with sync working in release 20210302_01 (without GETH at all apparently), threw me off the problem, and I kept on using 80 for the rest of my tests.

Oh, and that is not my real mining key and infura API key. They were just for testing, but yes, it might set a bad example for others. Do not post your keys!

@Josh_Hamon Thanks for carrying the ball over to github issues. Double-check and see if all your GETH_ parameters are correct. If this solves your issue with shard 2 as well, I think we can consider this coming down to just lack of good error messages and documentation.

[duc]

@fredlee, I suggest setting GETH env vars as follows should be working for you:

GETH_PROTOCOL=
GETH_PORT=
GETH_NAME=https://mainnet.infura.io/v3/26e7865275720d452...

By setting GETH_NAME to a full url, you would not need to care about GETH_PROTOCOL and GETH_PORT. thanks!

[fredlee]

@duc

By setting GETH_NAME to a full url, you would not need to care about GETH_PROTOCOL and GETH_PORT . thanks!

Oh! Yeah, you’re right, they’re only concated together.

func BuildRPCServerAddress(protocol string, host string, port string) string {
	url := host
	if protocol != "" {
		url = protocol + "://" + url
	}
	if port != "" {
		url = url + ":" + port
	}
	return url
}

You still have to define all three tho, because the defaults are HTTP and 8545.

[duc]

Yes, hope this could help solve your issues, I also asked @Rocky to update his post a bit to make it clearer. Sorry for the inconvenience!

[fredlee]

@duc

Yes, hope this could help solve your issues

I think it will, it’s still syncing shard 0, 2 and 6. But it looks good so far. Once it’s done, I’ll confirm and change the topic to [Solved]. I’d also like to know if this might solve the issue for:

@Josh_Hamon Shard 2 Stalling at 433077 on Multiple vNodes
@pfrp Shard6 with sync problem

Let me know guys.

[Josh_Hamon]

I’m starting fresh and syncing the beacon

[pfrp]

Hi @fredlee, I have set GETH_NAME to infure.io as instructed by duc and shard6 is syncing again. Local light ethereum node is not working anymore ? I have checked connection to parity container on port 8545 and it is working fine.

Thank you,

[Josh_Hamon]

Beacon stalled. Restarting

[fredlee]

Beacon, that’s odd, never had problems with it. Check for errors if it keeps stalling.

I’m about 200k blocks from a fully synced node. Knock on wood.

[fredlee]

Full node synced!

Resulted in around 280 requests to infura.io in total coming from shards 0,2 and 6. Still not sure how this works and why 1,3,4,5,7 and beacon requires no GETH? But I guess that’s outside of the scope of this topic.

@Mike_Wagner your guess was close. Full node is 112GiB of shard and beacon block data at this time.

Once again, thank you @trungtin2qn1 for helping me figure out what was wrong in the setup.

[Thriftinkid]

@fredlee

Resulted in around 280 requests to infura.io in total coming from shards 0,2 and 6. Still not sure how this works and why 1,3,4,5,7 and beacon requires no GETH? But I guess that’s outside of the scope of this topic.

I would like the answer to this question. Im running my nodes through jservers, and they are not running this part of the code. They said it is not necessary.

[JG20]

hey @fredlee, I am not getting any requests to infura.io even though I’ve wiped and re-synced multiple vnodes. I’ve updated the GETH vars per the info from @duc. Any ideas what I’m doing wrong? Can the same Infura API be used for all nodes?