Node cannot be synchronized

sistemkoin-mahsum · November 25, 2019, 3:04pm

Hi all.
I have installed the Aeternity node. Node is not synchronizing. When I examine the Console output, I see the message “Dropping gossiped light micro_block”.

This is console output:

16:00:07.525 [info] TX-pool synchronization (outgoing) started towards “pp_2LnQXCm…sCQK4fN”
16:00:07.916 [info] Application aehttp started on node aeternity@localhost
16:00:07.928 [info] Application aemon started on node aeternity@localhost
16:00:07.932 [info] Application aestratum_lib started on node aeternity@localhost
16:00:07.937 [info] Application aestratum started on node aeternity@localhost
Eshell V9.3.3.12 (abort with ^G)
(aeternity@localhost)1> 16:00:08.427 [info] TX-pool sync requries getting 1 TXs
16:00:08.457 [info] TX-pool sync added 1 TXs
16:00:08.485 [info] TX-pool synchronization finished!
16:00:08.773 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.802 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.806 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.816 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.839 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.844 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.858 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.886 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}
16:00:08.953 [info] Dropping gossiped light micro_block (<<6,15,106,102,…,33,106,164,207>>): {error,prev_key_block_not_found}

This is node status output:

{ "difficulty": 17188712909039, "genesis_key_block_hash": "kh_pbtwgLrNu23k9PA6XCZnUbtsvEFeQGgavY4FS2do3QP8kcp2z", "listening": true, "network_id": "ae_mainnet", "node_revision": "02546a105843c8f9773a93666a819beee2c1de48", "node_version": "5.1.0", "peer_count": 330, "peer_pubkey": "pp_Q3Hi4h1NrGaM..............sQrS6Ys", "pending_transactions_count": 22, "protocols": [ { "effective_at_height": 161150, "version": 4 }, { "effective_at_height": 90800, "version": 3 }, { "effective_at_height": 47800, "version": 2 }, { "effective_at_height": 0, "version": 1 } ], "solutions": 0, "sync_progress": 100.0, "syncing": false, "top_block_height": 173574, "top_key_block_hash": "kh_28Qwbk24sx41ANPtVTqvMr3sbALLup9pdCNsWKNzU3tiDfQ9An" }

hanssv.chain · November 25, 2019, 6:10pm

What brings you to think that your node is not in sync? The status says sync_progress is at 100% and the height looks close to where the top was at the time you posted the message? (syncing: false means that the node is currently not syncing)

The occasional info-log message Dropping gossiped light micro_block... is nothing to worry about it just means that you got a micro-block out of order (which can happen). If it happens often it might indicate that you are not well connected to the network…

Kryztoval · May 5, 2020, 8:02am

How about me? I see a lot of the same errors, but status shows “sync_progress”: 96.74888
and a bunch of

07:59:14.930 [warning] Mnesia activity Type=transaction exit with Reason={aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,937}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,604}]},{aec_sync,has_generation,1,[{file,"/app/apps/aecore/src/aec_sync.erl"},{line,986}]}]}}, retrying
07:59:14.931 [info] worker stopped with reason: {aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,934}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,604}]},{aec_sync,has_generation,1,[{file,"/app/apps/aecore/src/aec_sync.erl"},{line,986}]}]}}
07:59:14.931 [error] CRASH REPORT Process <0.5449.0> with 0 neighbours exited with reason: {aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,934}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,...},...]}} in mnesia:wrap_trans/6 line 493
07:59:15.653 [warning] Mnesia activity Type=transaction exit with Reason={aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,937}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,604}]},{aec_sync,has_generation,1,[{file,"/app/apps/aecore/src/aec_sync.erl"},{line,986}]}]}}, retrying
07:59:15.654 [info] worker stopped with reason: {aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,934}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,604}]},{aec_sync,has_generation,1,[{file,"/app/apps/aecore/src/aec_sync.erl"},{line,986}]}]}}
07:59:15.654 [error] CRASH REPORT Process <0.5515.0> with 0 neighbours exited with reason: {aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,934}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,...},...]}} in mnesia:wrap_trans/6 line 493
07:59:17.219 [warning] Mnesia activity Type=transaction exit with Reason={aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,937}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,604}]},{aec_sync,has_generation,1,[{file,"/app/apps/aecore/src/aec_sync.erl"},{line,986}]}]}}, retrying
07:59:17.219 [info] worker stopped with reason: {aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,934}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,604}]},{aec_sync,has_generation,1,[{file,"/app/apps/aecore/src/aec_sync.erl"},{line,986}]}]}}
07:59:17.220 [info] Removing/ending sync task #Ref<0.879899077.486539265.87327> target was #{hash => <<211,136,248,248,90,134,69,154,79,77,247,89,10,72,219,152,100,76,154,45,224,141,2,131,163,53,157,44,116,28,174,114>>,height => 250776}
07:59:17.219 [error] CRASH REPORT Process <0.5622.0> with 0 neighbours exited with reason: {aborted,{{badmatch,[]},[{aec_db,'-find_block/1-fun-1-',1,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,385}]},{mnesia_tm,apply_fun,3,[{file,"mnesia_tm.erl"},{line,836}]},{mnesia_tm,execute_transaction,5,[{file,"mnesia_tm.erl"},{line,811}]},{mnesia,wrap_trans,6,[{file,"mnesia.erl"},{line,491}]},{aec_db,try_activity,4,[{file,"/app/apps/aecore/src/aec_db.erl"},{line,934}]},{aec_chain,get_generation_,2,[{file,"/app/apps/aecore/src/aec_chain.erl"},{line,589}]},{aec_chain,get_generation_by_hash,...},...]}} in mnesia:wrap_trans/6 line 493

and block has been stuck at 242622 for a while.

{
"difficulty": 7935986511283,
"genesis_key_block_hash": "kh_pbtwgLrNu23k9PA6XCZnUbtsvEFeQGgavY4FS2do3QP8kcp2z",
"listening": true,
"network_id": "ae_mainnet",
"node_revision": "dd1335c6acccd8bd61907d6dee5caa641ea97c4a",
"node_version": "5.5.3",
"peer_connections": {
"inbound": 0,
"outbound": 10
},
"peer_count": 165,
"peer_pubkey": "pp_KXZNUzZ5aS82mSLymTzLbK1eRQvds9DVLkSjzwpYHwdR9Ho4L",
"pending_transactions_count": 251,
"protocols": [
{
"effective_at_height": 161150,
"version": 4
},
{
"effective_at_height": 90800,
"version": 3
},
{
"effective_at_height": 47800,
"version": 2
},
{
"effective_at_height": 0,
"version": 1
}
],
"solutions": 0,
"sync_progress": 100,
"syncing": false,
"top_block_height": 242622,
"top_key_block_hash": "kh_xw57cYHk3At2gV99P5qYK1PWGksWkprbQPQ31mVRHKnTNBzZV"
}

I really want to avoid having to resync the whole database

P.S. I hate reviving a dead post, but this one seemed abandoned and had lots of Dropping gossiped errors too. Which would be a probably reason to land here.

hanssv.chain · May 5, 2020, 9:21am

“Dropping gossiped…” is benign and will happen from time to time (more often in the beginning and the endgame of the sync).

Hard to say what is wrong, but unfortunately it looks like a DB problem - it doesn’t find a block that it expects to have in the DB. To avoid re-syncing the whole thing you can have a look at https://downloads.aeternity.io

Kryztoval · May 5, 2020, 9:47pm

Thanks for your swift response, I am looking at the post you provided and I am not sure what I am suppossed to look at? The one running is a docker container running version 5.5.3

What you linked seems to be only the node iteself. so I don’t know what I am meant to do

hanssv.chain · May 5, 2020, 10:02pm

You wanted to avoid resyncing the whole chain so I provided a link to some DB backups that you could use to avoid that?!

Kryztoval · May 5, 2020, 10:35pm

OHHH the “backups” section. still need to download it all tho. and amazingly my node just went into the same loop just 2 hours ago… so I will try this in the server.

Ok nass, gonna try it.

Kryztoval · May 7, 2020, 8:32am

Welp, after a 32.37 GB download, and letting it show that bogus error for a few hours it is now synced, that took really long and 32.37 GB is not an easy thing to say. Are there ways to slim down the database size?

Also on the same note, why are the backups sorter chronologically from oldest to newer? shouldn’t the newer be on top?