search

ArweaveTeam / arweave

The Arweave server and App Developer Toolkit.
https://www.arweave.org
GNU General Public License v2.0
926 stars 205 forks source link

Error after finding H2 solution: Mining worker crash and fetch failure #593

Closed kslazarev closed 4 months ago

kslazarev commented 4 months ago

I've encountered a recurring error in the logs that appears after finding an H2 solution. This issue has been observed multiple times for last month. Here's an example of the error sequence:

2024-07-18T10:04:22.960522+00:00 [info] ar_mining_worker:handle_task/2:423 event: found_h2_solution, worker: ar_mining_worker_12, h2: <<"_____934HV3znVfrlXO-y9tuUBUVa2gVytnu2fHf9tg">>, difficulty: {115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141}, partial_difficulty: not_set 2024-07-18T10:04:22.969711+00:00 [error] ar_data_sync:read_chunk_with_metadata/6:1630 event: failed_to_fetch_chunk_metadata, tags: [solution_proofs], seek_offset: 46694397157623, store_id: storage_module_12_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, stored_packing: spora_2_6_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, modules_covering_seek_offset: storage_module_12_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, error: invalid_iterator 2024-07-18T10:04:23.187327+00:00 [error] gen_server:error_info/7:949 Generic server ar_mining_worker_12 terminating. Reason: {'function not exported',[{ar_mining_server,fetch_poa_from_peers,[46694397346138],[]},{ar_mining_worker,handle_task,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_worker.erl"},{line,451}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]}. Last message: {'$gen_cast',handle_task}. State: {state,ar_mining_worker_12,12,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},{143,{{{1,-46335909},#Ref<0.3905040386.2010644503.246291>,{computed_h2,{mining_candidate,{47,12,200894281720054,#Ref<0.3905040386.2016673793.152233>},not_set,<<49,155,150,39,122,149,83,76,12,72,164,...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{95,54,82,50,1984},<<37,208,255,228,25,193,34,...>>,<<226,99,97,146,103,62,...>>,<<148,234,31,48,195,...>>,<<25,90,244,10,...>>,<<97,23,114,...>>,692398,380,<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246207>,{computed_h2,{mining_candidate,{47,12,200894281720054,#Ref<0.3905040386.2016673793.152233>},not_set,<<"»yįGp¡Ëøáz"...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{95,54,82,50,1984},<<37,208,255,228,25,...>>,<<176,16,241,215,...>>,<<"ÿÿÿÿÝø"...>>,<<25,90,...>>,<<"a"...>>,692398,...}}},nil,{{{1,-46335909},#Ref<0.3905040386.2010644503.246234>,{computed_h2,{mining_candidate,{47,12,200894281720054,#Ref<0.3905040386.2016673793.152233>},not_set,<<72,167,117,184,127,226,...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{95,54,82,...},<<"%Ðÿä"...>>,<<"ö¥Æð"...>>,<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246219>,{computed_h2,{mining_candidate,{47,12,200894281720054,#Ref<0.3905040386.2016673793.152233>},not_set,<<"Ä5ÒÂfæä$\t;»Zà:ä:"...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{95,...},<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246213>,{computed_h2,{mining_candidate,{47,12,200894281720054,#Ref<0.3905040386.2016673793.152233>},not_set,<<237,16,...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,...},[],...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246210>,{computed_h2,{mining_candidate,{47,12,...},not_set,<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246209>,{computed_h2,{mining_candidate,{...},...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246208>,{computed_h2,{...}}},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246212>,{computed_h2,{mining_candidate,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246211>,{computed_h2,...}},nil,nil},nil}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246216>,{computed_h2,{mining_candidate,{47,...},not_set,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246215>,{computed_h2,{mining_candidate,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246214>,{computed_h2,...}},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246218>,{computed_h2,{...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246217>,{...}},nil,nil},nil}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246225>,{computed_h2,{mining_candidate,{47,12,200894281720054,...},not_set,<<21,...>>,{...},...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246222>,{computed_h2,{mining_candidate,{47,...},not_set,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246221>,{computed_h2,{mining_candidate,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246220>,{computed_h2,...}},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246224>,{computed_h2,{...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246223>,{...}},nil,nil},nil}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246232>,{computed_h2,{mining_candidate,{...},...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246231>,{computed_h2,{...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246226>,{...}},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246233>,{computed_h2,...}},nil,nil}}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246260>,{computed_h2,{mining_candidate,{16,12,200894281720054,#Ref<0.3905040386.2016673793.152217>},not_set,<<156,84,217,...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{...},...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246255>,{computed_h2,{mining_candidate,{47,12,200894281720054,...},not_set,<<140,...>>,{...},...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246252>,{computed_h2,{mining_candidate,{47,...},not_set,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246251>,{computed_h2,{mining_candidate,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246237>,{computed_h2,...}},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246254>,{computed_h2,{...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246253>,{...}},nil,nil},nil}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246258>,{computed_h2,{mining_candidate,{...},...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246257>,{computed_h2,{...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246256>,{...}},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246259>,{computed_h2,...}},nil,nil}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246286>,{computed_h2,{mining_candidate,{16,12,...},not_set,<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246283>,{computed_h2,{mining_candidate,{...},...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246282>,{computed_h2,{...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246281>,{...}},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246285>,{computed_h2,...}},{{{1,...},#Ref<0.3905040386.2010644503.246284>,...},nil,nil},nil}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246289>,{computed_h2,{mining_candidate,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246288>,{computed_h2,...}},{{{1,...},#Ref<0.3905040386.2010644503.246287>,...},nil,nil},nil},{{{1,-46335909},#Ref<0.3905040386.2010644503.246290>,{...}},nil,nil}}}}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246386>,{computed_h2,{mining_candidate,{16,12,200894281720054,#Ref<0.3905040386.2016673793.152217>},not_set,<<48,43,199,207,86,144,116,250,...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{95,54,82,50,1985},<<229,91,141,87,...>>,<<156,170,93,...>>,<<"\bá2©#h"...>>,<<25,...>>,<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246348>,{computed_h2,{mining_candidate,{16,12,200894281720054,#Ref<0.3905040386.2016673793.152217>},not_set,<<103,113,208,242,159,112,...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{95,54,82,...},<<"å["...>>,<<"\b7ÿ'"...>>,<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246321>,{computed_h2,{mining_candidate,{16,12,200894281720054,#Ref<0.3905040386.2016673793.152217>},not_set,<<"¹8+F"...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,115792089158000739615670140091070474477585236898197735126134722917486885663141},[],{95,...},<<...>>,...}}},{{{1,-46335909},#Ref<0.3905040386.2010644503.246315>,{computed_h2,{mining_candidate,{16,12,200894281720054,#Ref<0.3905040386.2016673793.152217>},not_set,<<219,24,...>>,{11579208923652304086549197655951173351951313718796613575... 2024-07-18T10:04:23.242948+00:00 [error] proc_lib:crash_report/4:525 crasher: initial call: ar_mining_worker:init/1, pid: <0.2932.0>, registered_name: ar_mining_worker_12, error: {undef,[{ar_mining_server,fetch_poa_from_peers,[46694397346138],[]},{ar_mining_worker,handle_task,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_worker.erl"},{line,451}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]}, ancestors: [ar_mining_sup,ar_sup,<0.827.0>], message_queue_len: 858, messages: [{'$gen_cast',handle_task},{'$gen_cast',{add_task,{computed_h2,{mining_candidate,{47,12,200894281720054,#Ref<0.3905040386.2016673793.152233>},not_set,<<"Ë7BL "...>>,{115792089236523040865491976559511733519513137187966135750324355397008867200169,...},[],...}}}},{'$gen_cast',{add_task,{computed_h2,{mining_candidate,{47,12,200894281720054,...},not_set,<<1,...>>,{...},...}}}},{'$gen_cast',{add_task,{computed_h2,{mining_candidate,{47,12,...},not_set,<<...>>,...}}}},{'$gen_cast',{add_task,{computed_h2,{mining_candidate,{47,...},not_set,...}}}},{'$gen_cast',{add_task,{computed_h2,{mining_candidate,{...},...}}}},{'$gen_cast',{add_task,{computed_h2,{mining_candidate,...}}}},{'$gen_cast',{add_task,{computed_h2,{...}}}},{'$gen_cast',{add_task,{computed_h2,...}}}|...], links: [<0.2920.0>], dictionary: [{rand_seed,{#{bits => 58,jump => #Fun,next => #Fun,type => exsss,uniform => #Fun,uniform_n => #Fun},[241525729872918020|191295039240648151]}}], trap_exit: true, status: running, heap_size: 318187, stack_size: 29, reductions: 30377399165; neighbours: [] 2024-07-18T10:04:23.253967+00:00 [error] supervisor:do_restart/3:736 Supervisor: {local,ar_mining_sup}. Context: child_terminated. Reason: {undef,[{ar_mining_server,fetch_poa_from_peers,[46694397346138],[]},{ar_mining_worker,handle_task,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_worker.erl"},{line,451}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]}. Offender: id=ar_mining_worker_12,pid=<0.2932.0>.

Questions:

Additional Information:

Arweave version: master e39b4cc8af5eb308a700a7fad6886288539b64a0 Operating System: ubuntu-22.04.3-lts Node Configuration: one address solo node with 3 coordinated mining peers

I can provide more extensive logs if needed. Thank you for your assistance in understanding and potentially resolving this issue.

JamesPiechota commented 4 months ago

see if it works now.

kslazarev commented 4 months ago

updated all nodes to master: aa0280222cf1dc4452c1c84b0d958c31339d51cd

kslazarev commented 4 months ago

Get an another error below, but looks like handle correct.

https://arweave.net/block/height/1468862

Questions:

2024-07-20T10:16:45.679073+00:00 [info] ar_mining_worker:handle_task/2:423 event: found_h2_solution, worker: ar_mining_worker_46, h2: <<"_____ZUAEPJhmucbMsBLqwCzQKHHLVKw4LI504enOUc">>, difficulty: {115792089235116515728632171927576301730633041974277216118334405166473933692766,115792089017348225929689676897527295589575715529305771927139699863993534922880}, partial_difficulty: not_set 2024-07-20T10:16:46.269897+00:00 [error] ar_data_sync:read_chunk_with_metadata/6:1658 event: failed_to_read_chunk_data_path, tags: [solution_proofs], seek_offset: 167377159102711, store_id: storage_module_46_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, stored_packing: spora_2_6_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, modules_covering_seek_offset: storage_module_46_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, chunk_data_key: <<"AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAYR37BPNSpBo6r1pxK8GCyyxnIYGMfHoWNipgUjtbTvDJNCyMa3oQ">>

2024-07-20T10:16:46.295087+00:00 [error] ar_mining_server:prepare_solution/3:575 event: failed_to_find_poa_proofs_locally, tags: [solution_proofs], recall_byte: 167377159278298, modules_covering_recall_byte: storage_module_46_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM

2024-07-20T10:16:46.296664+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 184.161.12.157:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296664+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 38.29.227.28:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296818+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 24.59.240.76:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296787+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 38.29.227.55:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296783+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 206.83.144.15:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296788+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 112.120.10.102:1985, recall_byte: 167377159278298

2024-07-20T10:16:46.296766+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 94.130.139.215:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296845+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 38.29.227.48:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296836+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 174.112.132.234:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296713+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 170.205.62.132:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296910+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 38.29.227.25:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296662+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 38.70.220.163:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296878+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 162.220.53.21:1984, recall_byte: 167377159278298

2024-07-20T10:16:46.296877+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 121.133.147.61:1984, recall_byte: 167377159278298

2024-07-20T10:16:47.008750+00:00 [info] ar_node_worker:handle_found_solution/3:2019 event: mined_block, indep_hash: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>, solution: <<"_____ZUAEPJhmucbMsBLqwCzQKHHLVKw4LI504enOUc">>, height: 1468862, step_number: 46509130, steps: 24, txs: 1, chunks: 2

2024-07-20T10:16:47.008773+00:00 [info] ar_watchdog:handle_cast/2:136 event: mined_block, block: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>, height: 1468862, previous_block: <<"YSW-gPMojoI7PFXWlZ_aXtnO4ocQJKt7ORUPSVkYxisJuKbedyEBU76w-u1-N0i0">>

2024-07-20T10:16:47.136285+00:00 [info] ar_nonce_limiter:request_validation/3:269 event: vdf_validation_start, block: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>, session_key: {<<"iqQNWh0tKIG_cFYHqAJNGhwxiFTKXRGyYz9Zx6vBIE0-RvpysOpnU_xnIOy0wqjb">>,38757,692288}, next_session_key: {<<"iqQNWh0tKIG_cFYHqAJNGhwxiFTKXRGyYz9Zx6vBIE0-RvpysOpnU_xnIOy0wqjb">>,38757,692288}, prev_step_number: 46509106, step_number: 46509130, start_step_number: 46509106, step_count: 24, steps: 24, session_steps: 24, prev_vdf_difficulty: 692288, vdf_difficulty: 692288, next_vdf_difficulty: 692288, pid: <0.7729.0>

2024-07-20T10:16:47.139304+00:00 [info] ar_node_worker:handle_info/2:461 event: vdf_validation_successful, block: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>

2024-07-20T10:16:47.354275+00:00 [info] ar_node_utils:validate/6:63 event: validating_block, hash: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>

2024-07-20T10:16:47.384765+00:00 [info] ar_node_utils:validate/6:70 event: block_validation_successful, hash: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>, time_taken_us: 30347

2024-07-20T10:16:47.407611+00:00 [info] ar_storage:store_account_tree_update/3:1256 event: storing_account_tree_update, updated_key_count: 11, height: 1468862, root_hash: <<"LbjevEy51dStzpW3Unpkza6q-_2Cq4gLDIrfOBK8NGrd5ZGVPzu4twmQgTJrhc_-">>

2024-07-20T10:16:47.414628+00:00 [info] ar_storage:store_account_tree_update/3:1290 event: stored_account_tree

2024-07-20T10:16:47.957609+00:00 [info] ar_node_worker:log_applied_block/1:1426 event: applied_block, indep_hash: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>, height: 1468862, partition1: 46, partition2: 13, num_chunks: 2

2024-07-20T10:16:47.958020+00:00 [info] ar_node_worker:log_tip/1:1434 event: new_tip_block, indep_hash: <<"uJNWyWxjXTP1tqyqcmunhR9ge22fY1pnrvqNFY8MWhWiH4xxt1EtEKqtn4gu4cKX">>, height: 1468862

2024-07-20T10:16:48.099516+00:00 [info] ar_storage:store_account_tree_update/3:1256 event: storing_account_tree_update, updated_key_count: 11, height: 1468862, root_hash: <<"LbjevEy51dStzpW3Unpkza6q-_2Cq4gLDIrfOBK8NGrd5ZGVPzu4twmQgTJrhc_-">>

2024-07-20T10:16:48.100120+00:00 [info] ar_storage:store_account_tree_update/3:1290 event: stored_account_tree

kslazarev commented 4 months ago

Also found another H2 solution without error, but in arweave.net block reward_addr is 7rh2LVdpBhr35oC8VH0Bg5xZQtYUkqDu2-JWwo5qG6M. Is it call Orphan block for me and this is correct behavior?

https://arweave.net/block/height/1468575

2024-07-19T23:51:44.921783+00:00 [info] ar_watchdog:handle_cast/2:136 event: mined_block, block: <<"O3M0-BXbW6ipChlPVPJtUgPhw1tZELkoMS5DpFYUZpPEUzNqON0HLGa87N8J6LHP">>, height: 1468575, previous_block: <<"4TOALaNHWX4qZyw1kLu7RQHPIJkGJ_m5qs9mlviz7kyYP6T6-bbzZMmtR-wr7SSS">>

2024-07-19T23:51:44.921760+00:00 [info] ar_node_worker:handle_found_solution/3:2019 event: mined_block, indep_hash: <<"O3M0-BXbW6ipChlPVPJtUgPhw1tZELkoMS5DpFYUZpPEUzNqON0HLGa87N8J6LHP">>, solution: <<"_____cfgTx217mcmiZ8DHqjzo2pjOqkLsJVCeLdU2Rw">>, height: 1468575, step_number: 46471504, steps: 414, txs: 38, chunks: 2

JamesPiechota commented 4 months ago

The failed to find proofs locally often means there's some corruption in that particular storage module. The node will try to fetch proofs from peers when that happens. You can either leave as is or resync that partition. Resyncing will be better long term, but takes time.

Orphan blocks are common. It means your block "lost the race" against another miner's block. Fetching proofs from peers does slow you down so that could be one reason, but there could be many others - including just bad luck.

kslazarev commented 4 months ago

The failed to find proofs locally often means there's some corruption in that particular storage module. The node will try to fetch proofs from peers when that happens. You can either leave as is or resync that partition. Resyncing will be better long term, but takes time.

I appreciate the explanation about the potential corruption in the storage module. Resyncing the partition is not a problem in terms of network usage; it's mainly a matter of time. However, I have a few questions about this process:

I'm willing to perform the resync as suggested, but I want to ensure I'm doing it in the most efficient and effective manner possible. Any additional guidance you can provide on these points would be greatly appreciated. Thank you for your continued support.

Orphan blocks are common. It means your block "lost the race" against another miner's block. Fetching proofs from peers does slow you down so that could be one reason, but there could be many others - including just bad luck.

Yep, thanks for confirmation

JamesPiechota commented 4 months ago

Unfortunately there aren't yet any tools to make the resyncing easier nor to validate that a storage module is valid. It's on the list of things to implement, but no ETA. The only option today is to resync the whole storage module and then monitor for errors.

kslazarev commented 4 months ago

I've encountered another error: 2024-07-21T10:31:20.822764+00:00 [error] ar_data_sync:read_chunk_with_metadata/6:1687 event: chunk_metadata_read_sync_record_race_condition, tags: [solution_proofs], seek_offset: 162071200964855, storeID: storage_module_45_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, modules_covering_seek_offset: storage_module_45_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, root_sync_records: [[{{ar_data_sync,"storage_module_45_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM"},#Ref<0.3278541479.1706688513.156698>}]], stored_packing: spora_2_6_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM

  1. Is this chunk_metadata_read_sync_record_race_condition error also indicative of corruption in the storage module, similar to the previous errors?

  2. Does this error also require resyncing the entire partition?

JamesPiechota commented 4 months ago

I haven't seen that error before. From the code it should be a rare occurrence. If it's happening a lot, then yeah it likely indicates corruption.

kslazarev commented 4 months ago

2024-07-28T12:33:22.942466+00:00 [info] ar_http_iface_middleware:handle_mining_h2/2:3250 event: h2_received, peer: 95.54.82.50:1984

2024-07-28T12:33:23.035309+00:00 [error] ar_data_sync:read_chunk_with_metadata/6:1630 event: failed_to_fetch_chunk_metadata, tags: [solution_proofs], seek_offset: 173158547366135, store_id: storage_module_48_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, stored_packing: spora_2_6_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, modules_covering_seek_offset: storage_module_48_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM, error: invalid_iterator

2024-07-28T12:33:23.038149+00:00 [error] ar_mining_server:prepare_solution/3:575 event: failed_to_find_poa_proofs_locally, tags: [solution_proofs], recall_byte: 173158547486397, modules_covering_recall_byte: storage_module_48_GVr0CkdQU9TIutkf1eTtm9Ud3Wp-X9rtdIXCHdrlNMM

2024-07-28T12:33:23.038674+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 46.122.10.233:10003, recall_byte: 173158547486397

2024-07-28T12:33:23.038678+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 107.23.245.24:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.038886+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 112.120.10.102:2186, recall_byte: 173158547486397

2024-07-28T12:33:23.038931+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 38.29.227.27:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.039070+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 54.90.226.66:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.039065+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 206.83.144.16:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.039083+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 184.161.12.157:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.039013+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 217.145.83.116:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.038658+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 24.136.34.175:1989, recall_byte: 173158547486397

2024-07-28T12:33:23.039094+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 104.244.75.216:1988, recall_byte: 173158547486397

2024-07-28T12:33:23.038893+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 162.220.53.21:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.039033+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 170.205.62.132:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.038967+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 38.70.220.167:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.038833+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 174.129.84.142:1984, recall_byte: 173158547486397

2024-07-28T12:33:23.038979+00:00 [info] ar_mining_server:fetch_poa_from_peers/1:722 event: last_moment_proof_search, peer: 121.133.147.61:1984, recall_byte: 173158547486397

2024-07-28T12:33:24.025425+00:00 [error] gen_server:error_info/7:949 Generic server ar_mining_server terminating. Reason: {badarg,[{b64fast,encode,1,[{file,"/home/kslazarev/arweave/_build/default/lib/b64fast/src/b64fast.erl"},{line,22}]},{ar_serialize,poa_to_json_struct,1,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_serialize.erl"},{line,1366}]},{ar_serialize,solution_to_json_struct,1,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_serialize.erl"},{line,1909}]},{ar_http_iface_client,cm_publish_send,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_http_iface_client.erl"},{line,602}]},{ar_mining_server,post_solution,3,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_server.erl"},{line,700}]},{ar_mining_server,handle_cast,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_server.erl"},{line,169}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]}]}. Last message: {'$gen_cast',{prepare_and_post_solution,{mining_candidate,not_set,not_set,not_set,{115792089235613661174834588371474966357101914327237576624960975875971015037502,115792089067062770549931321287393758236462950825341822589796770813701669396508},[],not_set,<<201,131,248,106,46,99,54,189,134,105,104,66,249,63,73,108,193,181,72,157,5,159,190,44,111,175,69,135,111,142,114,0>>,<<201,197,60,44,182,241,249,96,201,230,218,21,21,235,51,240,102,169,80,17,147,43,212,126,106,56,247,181,58,253,127,99>>,<<255,255,255,253,176,146,206,249,111,176,129,187,254,184,223,88,2,235,99,243,142,247,19,192,52,201,136,112,44,243,185,167>>,<<25,90,244,10,71,80,83,212,200,186,217,31,213,228,237,155,213,29,221,106,126,95,218,237,116,133,194,29,218,229,52,195>>,<<63,170,110,250,244,40,80,120,66,90,92,240,171,187,24,16,91,212,105,64,85,65,130,53,169,99,211,33,60,27,128,250,20,85,230,87,185,102,125,45,77,215,164,7,212,231,123,77>>,690189,177,<<67,14,153,172,152,59,51,181,195,224,209,217,35,203,47,28,253,8,196,129,41,71,140,130,154,128,56,234,178,42,17,65>>,48,33,204538523459830,{poa,1,<<141,127,56,203,24,249,30,10,195,68,58,92,14,12,165,62,131,75,52,122,168,167,143,26,88,189,56,251,96,189,1,3,144,49,71,9,39,181,140,156,97,41,184,78,162,160,173,53,223,192,44,224,109,243,90,251,93,167,159,198,125,58,92,204,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,48,227,71,214,186,127,60,79,4,204,36,189,186,20,144,60,254,119,14,147,87,223,88,53,138,57,198,183,219,241,68,182,0,97,2,142,174,251,100,227,48,127,10,48,77,224,29,71,123,99,220,195,101,105,223,176,237,113,182,34,160,77,254,210,16,179,193,189,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,17,60,0,0,55,187,243,89,235,88,81,1,17,240,228,114,231,141,92,4,70,106,240,167,7,187,124,114,126,166,96,131,138,17,72,192,84,97,221,234,49,...>>,<<204,132,134,68,133,17,73,2,181,53,144,47,192,213,54,56,90,49,158,17,83,222,24,238,80,2,158,111,31,85,157,171,116,213,190,104,141,44,127,163,193,102,95,18,1,66,59,237,67,47,54,46,89,44,199,27,221,225,4,121,70,157,184,115,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,0,0,0,223,95,17,152,14,184,222,178,85,41,164,215,147,45,88,97,59,194,137,143,245,209,133,64,249,190,41,130,111,222,61,137,76,127,208,39,13,68,56,107,170,124,119,32,49,135,26,170,245,83,143,190,43,34,191,152,231,0,192,19,22,111,199,40,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,1,128,0,0,161,178,246,92,80,219,91,149,237,121,164,100,156,6,114,240,21,83,181,186,36,8,105,44,5,204,11,168,50,82,254,33,140,251,226,152,...>>,<<107,169,80,120,223,51,48,36,41,146,83,46,52,124,161,83,146,0,251,38,209,102,67,59,189,166,150,190,216,149,204,135,106,162,188,213,68,117,23,111,250,234,129,210,70,222,250,125,142,157,102,128,37,113,166,212,155,174,226,226,131,219,122,164,133,158,5,236,17,217,183,148,179,148,220,36,237,185,210,79,167,214,19,175,21,222,233,179,160,196,150,91,66,115,37,0,216,125,28,168,16,133,179,47,91,30,181,209,255,78,175,126,82,111,222,108,244,162,188,108,47,191,194,121,63,247,234,248,193,101,92,216,0,126,46,252,178,107,44,161,95,109,204,224,107,188,116,40,125,230,111,25,114,15,27,88,14,163,240,60,27,219,122,110,201,246,236,138,72,213,232,11,76,3,53,49,146,235,70,176,136,33,136,41,35,162,38,126,72,185,21,223,178,32,94,78,46,89,92,241,41,232,222,225,73,10,108,19,69,90,150,175,96,254,243,22,203,192,228,230,66,254,72,86,229,126,166,...>>},<<59,187,52,138,225,47,31,149,98,132,157,24,36,97,196,69,204,118,14,36,149,22,228,122,110,72,140,150,12,152,131,206>>,<<155,114,152,242,29,75,135,42,138,74,74,84,21,188,85,207,39,96,246,3,228,17,3,183,15,74,78,11,133,127,23,142,135,126,25,45,96,251,114,123,247,35,47,53,229,77,20,56>>,{<<63,170,110,250,244,40,80,120,66,90,92,240,171,187,24,16,91,212,105,64,85,65,130,53,169,99,211,33,60,27,128,250,20,85,230,87,185,102,125,45,77,215,164,7,212,231,123,77>>,39338,690189},39338,47205733,<<"cm">>}}}. State: {state,false,#{0 => ar_mining_worker_0,3 => ar_mining_worker_3,10 => ar_mining_worker_10,11 => ar_mining_worker_11,16 => ar_mining_worker_16,25 => ar_mining_worker_25,31 => ar_mining_worker_31,35 => ar_mining_worker_35,40 => ar_mining_worker_40,42 => ar_mining_worker_42,43 => ar_mining_worker_43,48 => ar_mining_worker_48,49 => ar_mining_worker_49,52 => ar_mining_worker_52,54 => ar_mining_worker_54,55 => ar_mining_worker_55},{set,2,16,16,8,80,48,{[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]},{{[],[],[],[],[],[],[],[{<<63,170,110,250,244,40,80,120,66,90,92,240,171,187,24,16,91,212,105,64,85,65,130,53,169,99,211,33,60,27,128,250,20,85,230,87,185,102,125,45,77,215,164,7,212,231,123,77>>,39338,690189}],[],[],[{<<155,114,152,242,29,75,135,42,138,74,74,84,21,188,85,207,39,96,246,3,228,17,3,183,15,74,78,11,133,127,23,142,135,126,25,45,96,251,114,123,247,35,47,53,229,77,20,56>>,39337,690189}],[],[],[],[],[]}}},#{{<<63,170,110,250,244,40,80,120,66,90,92,240,171,187,24,16,91,212,105,64,85,65,130,53,169,99,211,33,60,27,128,250,20,85,230,87,185,102,125,45,77,215,164,7,212,231,123,77>>,39338,690189} => <<155,114,152,242,29,75,135,42,138,74,74,84,21,188,85,207,39,96,246,3,228,17,3,183,15,74,78,11,133,127,23,142,135,126,25,45,96,251,114,123,247,35,47,53,229,77,20,56>>,{<<155,114,152,242,29,75,135,42,138,74,74,84,21,188,85,207,39,96,246,3,228,17,3,183,15,74,78,11,133,127,23,142,135,126,25,45,96,251,114,123,247,35,47,53,229,77,20,56>>,39337,690189} => <<22,198,217,237,254,50,68,179,35,219,137,139,71,148,63,145,144,65,103,188,146,251,21,84,8,227,177,193,43,158,47,71,37,170,45,198,59,143,72,143,57,159,243,132,71,80,136,254>>},{115792089235613661174834588371474966357101914327237576624960975875971015037502,115792089067062770549931321287393758236462950825341822589796770813701669396508},1600,8000,#Ref<0.2914340924.2500329478.141492>,151066495197430,false}.

2024-07-28T12:33:24.113529+00:00 [error] proc_lib:crash_report/4:525 crasher: initial call: ar_mining_server:init/1, pid: <0.2308.0>, registered_name: ar_mining_server, error: {badarg,[{b64fast,encode,1,[{file,"/home/kslazarev/arweave/_build/default/lib/b64fast/src/b64fast.erl"},{line,22}]},{ar_serialize,poa_to_json_struct,1,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_serialize.erl"},{line,1366}]},{ar_serialize,solution_to_json_struct,1,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_serialize.erl"},{line,1909}]},{ar_http_iface_client,cm_publish_send,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_http_iface_client.erl"},{line,602}]},{ar_mining_server,post_solution,3,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_server.erl"},{line,700}]},{ar_mining_server,handle_cast,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_server.erl"},{line,169}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]}]}, ancestors: [ar_mining_sup,ar_sup,<0.827.0>], message_queue_len: 15, messages: [{'$gen_cast',{compute_h2_for_peer,{mining_candidate,not_set,not_set,not_set,{115792089235613661174834588371474966357101914327237576624960975875971015037502,115792089067062770549931321287393758236462950825341822589796770813701669396508},[{...}|...],{...},...}}},{'$gen_cast',{compute_h2_for_peer,{mining_candidate,not_set,not_set,not_set,{115792089235613661174834588371474966357101914327237576624960975875971015037502,...},[...],...}}},{'$gen_cast',{compute_h2_for_peer,{mining_candidate,not_set,not_set,not_set,{...},...}}},{event,nonce_limiter,{computed_output,{{<<"?ªnú"...>>,39338,...},47205743,<<...>>,...}}},{'$gen_cast',{compute_h2_for_peer,{mining_candidate,not_set,not_set,...}}},{'$gen_cast',{compute_h2_for_peer,{mining_candidate,not_set,...}}},{...}|...], links: [<0.2280.0>], dictionary: [{rand_seed,{#{bits => 58,jump => #Fun<rand.3.92093067>,next => #Fun<rand.0.92093067>,type => exsss,uniform => #Fun<rand.1.92093067>,uniform_n => #Fun<rand.2.92093067>},[268410994980058319|22208613051424125]}}], trap_exit: true, status: running, heap_size: 46422, stack_size: 29, reductions: 25927600; neighbours: []

2024-07-28T12:33:24.116595+00:00 [error] supervisor:do_restart/3:736 Supervisor: {local,ar_mining_sup}. Context: child_terminated. Reason: {badarg,[{b64fast,encode,1,[{file,"/home/kslazarev/arweave/_build/default/lib/b64fast/src/b64fast.erl"},{line,22}]},{ar_serialize,poa_to_json_struct,1,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_serialize.erl"},{line,1366}]},{ar_serialize,solution_to_json_struct,1,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_serialize.erl"},{line,1909}]},{ar_http_iface_client,cm_publish_send,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_http_iface_client.erl"},{line,602}]},{ar_mining_server,post_solution,3,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_server.erl"},{line,700}]},{ar_mining_server,handle_cast,2,[{file,"/home/kslazarev/arweave/apps/arweave/src/ar_mining_server.erl"},{line,169}]},{gen_server,try_dispatch,4,[{file,"gen_server.erl"},{line,695}]},{gen_server,handle_msg,6,[{file,"gen_server.erl"},{line,771}]}]}. Offender: id=ar_mining_server,pid=<0.2308.0>.

After error, miner still works but with "VDF Speed: undefined". Manually restart miner to fix problem.

kslazarev commented 4 months ago

Close this ticket. Last updates are huge in master. Also re-download and hash several storages. Already had defragmentation on all partitions. If errors occur, I'll open a new ticket with additional information.