helium / miner

Miner for the helium blockchain
Apache License 2.0
609 stars 265 forks source link

failed to dial challenger : not_found #1407

Closed wolasss closed 2 years ago

wolasss commented 2 years ago

Recently, I have noticed again an increased number of errors "not_found" while connecting to the challengers:

https://pastebin.com/daDTBu9P

This is a log from one miner, but I can provide many more examples if needed - recently it happens much more often than before

Ay0hCrypto commented 2 years ago

same. 2022-02-01 23:12:00.665 29040 [error] <0.2610.0>@miner_onion_server:send_witness:207 failed to send witness, max retry ... 2022-02-01 23:04:43.450 29040 [error] <0.2352.0>@miner_onion_server:send_witness:207 failed to send witness, max retry

missing 2+ witnesses an hour due to this.

Have you found them across all miners or a specific brand? Above is an SB.

wolasss commented 2 years ago

@Ay0hCrypto please provide more log file cause it does not show the exact error, it could be timeout as well.

Ay0hCrypto commented 2 years ago

1 in 10 are relayed/timed-out the other 9 are not found. and it was a beacon sent by another miner i own ~920km away. when i can get back into the log files I will try and copy some, i can only see about 100 minutes of the log at a time. I am having successful witnesses as well. here is one series of not found: 2022-02-02 01:14:39.564 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:14:39.318 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:14:37.721 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 122 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:37.596 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 115 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:37.481 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 135 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:37.346 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 225 ms to absorb blockchain_txn_state_channel_close_v1 2022-02-02 01:14:37.146 534 [info] <0.2763.0>@blockchain_txn_state_channel_close_v1:absorb:347 Closing with conflict false 2022-02-02 01:14:36.147 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 226 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:35.909 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 277 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:35.631 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 119 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:35.510 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 136 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:35.374 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 114 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:35.261 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 117 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:35.143 534 [info] <0.2763.0>@blockchain_txn:absorb:562 took 1683 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:33.043 534 [info] <0.2763.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:14:31.755 534 [info] <0.2740.0>@blockchain_sync_handler:handle_data:142 Eagerly re-gossiping 1208264 2022-02-02 01:14:31.218 534 [info] <0.2740.0>@blockchain_sync_handler:handle_data:132 adding sync blocks [1208264] 2022-02-02 01:14:29.940 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=313,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:14:29 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:14:29.940 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:14:29 GMT">>,<<"txnb">> => 0} 2022-02-02 01:14:27.586 534 [info] <0.1562.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:14:27.432 534 [info] <0.1581.0>@miner:handle_info:474 non-consensus block 1208263 2022-02-02 01:14:27.426 534 [info] <0.2744.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 1683 post took 2305 ms height 1208263 2022-02-02 01:14:26.161 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 144 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:26.016 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 158 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:25.844 534 [info] <0.2744.0>@blockchain_txn_state_channel_close_v1:absorb:347 Closing with conflict false 2022-02-02 01:14:25.838 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 26 ms to absorb blockchain_txn_price_oracle_v1 2022-02-02 01:14:24.620 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 131 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:24.489 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 244 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:24.246 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 129 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:24.116 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 136 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:23.978 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 127 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:23.847 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 27 ms to absorb blockchain_txn_state_channel_close_v1 2022-02-02 01:14:23.835 534 [info] <0.2744.0>@blockchain_txn_state_channel_close_v1:absorb:347 Closing with conflict false 2022-02-02 01:14:23.438 534 [info] <0.2744.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:14:22.312 534 [info] <0.1562.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:14:22.179 534 [info] <0.1581.0>@miner:handle_info:474 non-consensus block 1208262 2022-02-02 01:14:22.173 534 [info] <0.2744.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 1411 post took 1673 ms height 1208262 2022-02-02 01:14:21.819 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 171 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:21.641 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 136 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:21.502 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 146 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:21.355 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 202 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:20.969 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 34 ms to absorb blockchain_txn_poc_request_v1 2022-02-02 01:14:20.682 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 34 ms to absorb blockchain_txn_poc_request_v1 2022-02-02 01:14:19.919 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 166 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:19.751 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 180 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:19.089 534 [info] <0.2744.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:14:17.933 534 [info] <0.1562.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:14:17.816 534 [info] <0.1581.0>@miner:handle_info:474 non-consensus block 1208261 2022-02-02 01:14:17.811 534 [info] <0.2744.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 1 absorb took 1144 post took 3027 ms height 1208261 2022-02-02 01:14:16.048 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 134 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:15.909 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 429 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:15.200 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 46 ms to absorb blockchain_txn_poc_request_v1 2022-02-02 01:14:14.266 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 177 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:14:14.006 534 [info] <0.2744.0>@blockchain_txn:absorb:562 took 30 ms to absorb blockchain_txn_poc_receipts_v1 2022-02-02 01:14:13.640 534 [info] <0.2744.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:14:12.248 534 [info] <0.2740.0>@blockchain_sync_handler:handle_data:142 Eagerly re-gossiping 1208263 2022-02-02 01:14:10.533 534 [info] <0.2740.0>@blockchain_sync_handler:handle_data:132 adding sync blocks [1208261,1208262,1208263] 2022-02-02 01:14:09.317 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:14:09.227 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:14:06.244 534 [info] <0.1521.0>@blockchain_worker:start_sync:855 new block sync starting with Pid: <0.2729.0>, Ref: #Ref<0.3844480711.3215720450.47359>, Peer: "/p2p/112KoedcUYZAGFTEWUJvi6KwuQcGLgpJcCpMoNMyG58GofkaiXqZ" 2022-02-02 01:13:59.929 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=309,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:13:59 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:13:59.929 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:13:59 GMT">>,<<"txnb">> => 0} 2022-02-02 01:13:39.226 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:13:38.983 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:13:29.938 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=305,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:13:29 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:13:29.938 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:13:29 GMT">>,<<"txnb">> => 0} 2022-02-02 01:13:08.982 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:13:08.886 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:12:59.929 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=301,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:12:59 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:12:59.929 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:12:59 GMT">>,<<"txnb">> => 0} 2022-02-02 01:12:38.885 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:12:38.778 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:12:29.925 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=297,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:12:29 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:12:29.925 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:12:29 GMT">>,<<"txnb">> => 0} 2022-02-02 01:12:08.777 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:12:08.688 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:11:59.929 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=293,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 1,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:11:59 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:11:59.929 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 1,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:11:59 GMT">>,<<"txnb">> => 0} 2022-02-02 01:11:49.971 534 [info] <0.1562.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:11:49.859 534 [info] <0.1581.0>@miner:handle_info:474 non-consensus block 1208260 2022-02-02 01:11:49.854 534 [info] <0.2693.0>@blockchain_txn:unvalidated_absorb_and_commit:502 validation took 0 absorb took 2034 post took 846 ms height 1208260 2022-02-02 01:11:49.748 534 [info] <0.2693.0>@blockchain_ledger_v1:maybe_gc_scs:2121 gcing old state_channels... 2022-02-02 01:11:49.730 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 154 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:48.886 534 [info] <0.2693.0>@blockchain_ledger_v1:maybe_gc_scs:2121 gcing old state_channels... 2022-02-02 01:11:48.562 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 101 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:48.461 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 100 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:48.360 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 108 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:48.247 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 109 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:48.136 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 106 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:48.029 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 101 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:47.927 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 109 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:47.818 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 112 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:47.702 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 111 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:47.592 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 115 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:47.476 534 [info] <0.2693.0>@blockchain_txn:absorb:562 took 128 ms to absorb blockchain_txn_assert_location_v2 2022-02-02 01:11:46.974 534 [info] <0.2693.0>@blockchain_txn:validate:294 valid: [], invalid: [] 2022-02-02 01:11:45.635 534 [info] <0.2684.0>@blockchain_sync_handler:handle_data:142 Eagerly re-gossiping 1208260 2022-02-02 01:11:45.095 534 [info] <0.2684.0>@blockchain_sync_handler:handle_data:132 adding sync blocks [1208260] 2022-02-02 01:11:38.687 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:11:38.443 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:11:29.926 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=289,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:11:29 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:11:29.925 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 0,<<"rxnb">> => 0,<<"rxok">> => 0,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:11:29 GMT">>,<<"txnb">> => 0} 2022-02-02 01:11:28.881 534 [info] <0.1521.0>@blockchain_worker:start_sync:855 new block sync starting with Pid: <0.2673.0>, Ref: #Ref<0.3844480711.3215720449.236430>, Peer: "/p2p/112UA7o9AtpaGYUPRRDQ5CZNhvEmQEJMzkuWHNdXR1iCkbtHLGnt" 2022-02-02 01:11:23.813 534 [info] <0.1521.0>@blockchain_worker:start_sync:855 new block sync starting with Pid: <0.2672.0>, Ref: #Ref<0.3844480711.3215720449.236400>, Peer: "/p2p/112H7aEw3dQcjDHRgo9Ti5FFeG5H1Z84PCQpLY9oLsuQmRCzNgQX" 2022-02-02 01:11:08.442 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found 2022-02-02 01:11:08.355 534 [info] <0.2664.0>@miner_onion_server:send_witness:246 re-sending witness at RSSI: -129, Frequency: 905.3, SNR: -11.2 2022-02-02 01:10:59.933 534 [info] <0.1608.0>@miner_lora:handle_json_data:564 Gateway #gateway{mac=12273815315514654720,ip={127,0,0,1},port=42357,sent=0,received=285,dropped=0,status=#{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 1,<<"rxnb">> => 1,<<"rxok">> => 1,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:10:59 GMT">>,<<"txnb">> => 0},rtt_samples=[],rtt=5000000} 2022-02-02 01:10:59.932 534 [info] <0.1608.0>@miner_lora:handle_json_data:563 got status #{<<"ackr">> => 100.0,<<"dwnb">> => 0,<<"rxfw">> => 1,<<"rxnb">> => 1,<<"rxok">> => 1,<<"temp">> => 30.0,<<"time">> => <<"2022-02-02 01:10:59 GMT">>,<<"txnb">> => 0} 2022-02-02 01:10:38.354 534 [warning] <0.2664.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112WqNBZLCYfDYDvdYeFNnT6cuFE2pMVcPmqXutrHAakLCXZEVJV": not_found

Ay0hCrypto commented 2 years ago

2022-02-02 01:16:06.001 534 [warning] <0.2828.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112FRjxxPdszy9AXN9YvxEyHT8Mun19QaRMPzF1bkxu8V1C9d8Gx": not_found

same here 2022-02-02 01:19:31.138 534 [warning] <0.2927.0>@miner_onion_server:send_witness:243 failed to dial challenger "/p2p/112umt7i5pPLE7ub8djXyNQ42zYLwrA2NVvWxdYE8D1cqdGofjGY": not_found

I have successful witnesses as well, but have not successfully been challeneged to beacon or challenged someone to beacon since 7am UTC Jan. 29th.

Ay0hCrypto commented 2 years ago

excerpts from older logs.pdf also had these two next to each other with these errors as well. not sure if related or not. don't have the whole log of this as i was chatting about the issue is a syncrobit sub thread on a discord about the same issue.

inigoflores commented 2 years ago

I have manually tried to contact those challengers involved in transactions which end up in "failed to send witness, max retry" (transaction log) up to several hours after the failure, and I still get the not_found error.

Miner 1: Not working

/opt/miner # miner peer connect /p2p/112mGu9ir5uE1nVrS18Mnpt1U22jVu22pMesrJq87ZcZ5CpFJBDB
Failed to connect to "/p2p/112mGu9ir5uE1nVrS18Mnpt1U22jVu22pMesrJq87ZcZ5CpFJBDB": not_found

I have refreshed the peerbook for the offending peer from its gossip peers, but the result is the same:

/opt/miner # miner peer refresh /p2p/112mGu9ir5uE1nVrS18Mnpt1U22jVu22pMesrJq87ZcZ5CpFJBDB
ok
/opt/miner # miner peer connect /p2p/112mGu9ir5uE1nVrS18Mnpt1U22jVu22pMesrJq87ZcZ5CpFJBDB
Failed to connect to "/p2p/112mGu9ir5uE1nVrS18Mnpt1U22jVu22pMesrJq87ZcZ5CpFJBDB": not_found

This is the gossip peer list:

/opt/miner # miner peer gossip_peers
["/p2p/11Po3SHpVL8smiHmGitRpSJXGnTXjpDf7nHonLimfzhE4PsJX7d",
 "/p2p/11JN5ajmiTjiGkZvezf8bA1zpTLXG7p8uYkZ1SqAD8nZfBrZ4HN",
 "/ip4/35.162.25.187/tcp/2154","/ip4/13.125.4.140/tcp/443",
 "/p2p/112CJg4HCYU91FmPyGBfed7bEajgjhmjp5QnU33XFwQH6PM7Yb1V",
 "/p2p/112RQaTU4ZA7c5PfS5uA8cgavvigFEZWrW4B3d2V8mLJw3Vzdg6E",
 "/p2p/11ueu3tRwd5jmJhs4TCfbTmVMDiarq7x4WG8FF7HUtRyTfc7UwT"]

I understand none of these gossip peers know about the offending peer.

When I run the same command from another test miner in the same LAN, the connection is successful.

Miner 2: Working

/opt/miner # miner peer connect /p2p/112mGu9ir5uE1nVrS18Mnpt1U22jVu22pMesrJq87ZcZ5CpFJBDB
Connected to "/p2p/112mGu9ir5uE1nVrS18Mnpt1U22jVu22pMesrJq87ZcZ5CpFJBDB" successfully

Any ideas?

Ay0hCrypto commented 2 years ago

was the working miner a different brand? If so it might mean SB hasnt addressed the issue Nebra found with newer seed nodes. if it is an SB, then @Capcom from helium discord might be correct about it being a bug, that wont be addressed until they roll out lite hotspots

inigoflores commented 2 years ago

Both are the same brand, the Pisces P100.

Please provide a Discord link to where this issue is being discussed.

wingdu commented 2 years ago

I have there the same issue with an milesight router

ghost commented 2 years ago

I have noticeably reduced the number of failed witnesses by increasing the max_inbound_connections and outbound_gossip_connections in the docker's sys.config. For example:

docker exec -it miner sh
vi config/sys.config

I changed

   {max_inbound_connections, 6},                                                                                                                                          
   {outbound_gossip_connections, 2}, 

to something like

   {max_inbound_connections, 20},                                                                                                                                          
   {outbound_gossip_connections, 10}, 

Then restarted the docker:

docker stop miner && docker start miner

I normally log the ratio of successfully sent witness entries to failed witness entries (i.e. 'max_retry') from console.log per hour. There is a noticeable jump toward 1.0 when I made this change:

Screen Shot 2022-02-10 at 12 15 32 PM

I presume that this is going to drastically increase my network traffic, but I've got an excellent internet connection, so I'm okay with that if I get more witnesses through

inigoflores commented 2 years ago

I've been testing higher values for those two sys.config parameters, and I confirm similar results, to the point where I have got completely rid of the not_found errors in all my miners.

$ ./processlogs.php -s 2022-02-09

Using logs in folder /home/pi/hnt/miner/log/

General Witnesses Overview
----------------------------------
Total witnesses                   =    77
Succesfully delivered             =    71 (92.21%)
Failed                            =     6  (7.79%)
  ├── Max retry    =    5  (6.49%)
  └── Crash/reboot =    1   (1.3%)

Max Retry Failure Reasons
----------------------------------
Timeout                           =     4    (80%)
Not Found                         =     0     (0%)
Other challenger issues           =     1    (20%)

Challengers
----------------------------------
Not Relayed                       =    74  (96.1%)
Relayed                           =     2   (2.6%)
Unknown Relay Status              =     1   (1.3%)`

Peer book size is huge:

$ sudo docker exec miner miner peer book -c
234053

I wonder if it can have a negative impact on the network if everyone implements these changes.

gitxmax commented 2 years ago

I've been testing higher values for those two sys.config parameters, and I confirm similar results, to the point where I have got completely rid of the not_found errors in all my miners.

$ ./processlogs.php -s 2022-02-09

Using logs in folder /home/pi/hnt/miner/log/

General Witnesses Overview
----------------------------------
Total witnesses                   =    77
Succesfully delivered             =    71 (92.21%)
Failed                            =     6  (7.79%)
  ├── Max retry    =    5  (6.49%)
  └── Crash/reboot =    1   (1.3%)

Max Retry Failure Reasons
----------------------------------
Timeout                           =     4    (80%)
Not Found                         =     0     (0%)
Other challenger issues           =     1    (20%)

Challengers
----------------------------------
Not Relayed                       =    74  (96.1%)
Relayed                           =     2   (2.6%)
Unknown Relay Status              =     1   (1.3%)`

Peer book size is huge:

$ sudo docker exec miner miner peer book -c
234053

I wonder if it can have a negative impact on the network if everyone implements these changes.

what values did you end up with? I changed to the recommended {max_inbound_connections, 20},{outbound_gossip_connections, 10} but still getting the invalids ..

DCYeahThatsMe commented 2 years ago

I will give this max_inbound and outbound_gossip a try and report back. Can someone share the location of the processlogs.php file? I'd like to give it a go to check my system.

For the record, I'm also having a scenario where besides the failed confirmations, some of my VALID confirmations aren't showing up in the blockchain. It's very strange, but on top of this issue - even when I do successfully send the witness confirm it won't appear in the block and thus not in my earnings as well. I am working with Milesight support to report this to Helium for investigation.

inigoflores commented 2 years ago

@gitxmax I'm currently using:

{max_inbound_connections, 200},
{outbound_gossip_connections, 50},

Probably not necessary that much. I make some adjustments and see the response.

@DCYeahThatsMe

The script can be found here: https://github.com/inigoflores/helium-miner-log-analyzer . You will have to specify the path to the logs folder with the option -p.

Let me know the full path to the logs in the Milesight miner and I will update to the script.

robgit77 commented 2 years ago

Hi guys, just configured my sensecap and below actual witness statistics with default values, I will let you know:

{max_inbound_connections, 100},
{outbound_gossip_connections, 25},

General Witnesses Overview

Total witnesses = 105 Succesfully delivered = 89 (84.76%) Failed = 16 (15.24%) ├── Max retry = 16 (15.24%) └── Crash/reboot = 0 (0%)

Max Retry Failure Reasons

Timeout = 7 (43.75%) Not Found = 9 (56.25%) Other challenger issues = 0 (0%)

I have a question, analyzing the miner logs with processlogs.php I see several operations that I can't full understand, here an example, last two rows in the -l output . The first is a witness rewarded because the challenger did a "challenged beaconer" activity, the last is a response non to a challenged beacon but to a "Constructed Challenge" . What's mean this kind of action?

2022-02-12 12:30:31.256 |   0.8687.0 | -112 | 867.1 |   1.5 | 11rtLkhrw1NrPtvmbWEt6BWUEjNLVmvjB4hojC8dDfjfhJUCGds  | no    | successfully sent |     1 |
2022-02-12 13:34:38.698 |  0.15039.0 | -115 | 867.3 |  -2.5 | 11b9km9H4aVTS5S1ZPFKRzvcb13x3Dru5LoEPeHnVRgoLhT4PHc  | no    | successfully sent |     1 |
wolasss commented 2 years ago

@robgit77 > Hi guys, just configured my sensecap and below actual witness statistics with default values, I will let you know:

Side question: How do you configure it on sensecap?

DCYeahThatsMe commented 2 years ago

Yes, how can you get ssh access on a sensecap???

DCYeahThatsMe commented 2 years ago

@robgit77 The path for the logs is: /mnt/mmcblk0p1/miner_data/log/ - console.log lives there!

robgit77 commented 2 years ago

@robgit77 > Hi guys, just configured my sensecap and below actual witness statistics with default values, I will let you know:

Side question: How do you configure it on sensecap?

Logged in via ssh adding a personal pub key into the config.json of sensecap.

DCYeahThatsMe commented 2 years ago

@robgit77 Is ssh on by default? Anything special you need to do? I've searched for whether or not ssh was possible on the M1 and I haven't found anything saying it was. Any information on enabling, default root password, etc. would be greatly appreciated! Also, how are the 100/25 values for you?

robgit77 commented 2 years ago

@robgit77 The path for the logs is: /mnt/mmcblk0p1/miner_data/log/ - console.log lives there!

In sensecap bit different if go inside the miner container logs are in /var/log/miner but you can find them also outside the container in /mnt/data/docker/volumes/xxxxxxx_miner-log/_data

Otherwise, after changing the values to 100 and 25 failed transaction passed from 20% to around 13%

General Witnesses Overview
----------------------------------
Total witnesses                   =   156
Succesfully delivered             =   136 (87.18%)
Failed                            =    20 (12.82%)
  ├── Max retry    =   20 (12.82%)
  └── Crash/reboot =    0     (0%)
robgit77 commented 2 years ago

@robgit77 Is ssh on by default? Anything special you need to do? I've searched for whether or not ssh was possible on the M1 and I haven't found anything saying it was. Any information on enabling, default root password, etc. would be greatly appreciated! Also, how are the 100/25 values for you?

M1 is based on Balena ssh is enabled but on port 22222 . You need the sensecap microsd card on your PC, then you need to create a public key and copy it in the config.json file below the support ssh-key that is already there. To generate a ssh-key you can use the command ssh-keygen and use default values when prompted.

fulda-cz commented 2 years ago

Hi @inigoflores, the full path to console.log on Milesight is /mnt/mmcblk0p1/miner_data/log/console.log The issue is there isn't php utility in the host OS (OpenWRT) so I can't start the script processlogs.php

mojomartini commented 2 years ago

Hi @inigoflores, the full path to console.log on Milesight is /mnt/mmcblk0p1/miner_data/log/console.log The issue is there isn't php utility in the host OS (OpenWRT) so I can't start the script processlogs.php

Agreed. I was unable to run it as well on a Milesight.

U1052851 commented 2 years ago

I have noticeably reduced the number of failed witnesses by increasing the max_inbound_connections and outbound_gossip_connections in the docker's sys.config. For example:

docker exec -it miner sh
vi config/sys.config

I changed

   {max_inbound_connections, 6},                                                                                                                                          
   {outbound_gossip_connections, 2}, 

to something like

   {max_inbound_connections, 20},                                                                                                                                          
   {outbound_gossip_connections, 10}, 

Then restarted the docker:

docker stop miner && docker start miner

I normally log the ratio of successfully sent witness entries to failed witness entries (i.e. 'max_retry') from console.log per hour. There is a noticeable jump toward 1.0 when I made this change:

Screen Shot 2022-02-10 at 12 15 32 PM

I presume that this is going to drastically increase my network traffic, but I've got an excellent internet connection, so I'm okay with that if I get more witnesses through

After updating these parameters.... where abouts on the page do you stop and restart the docker? Just enter text below the bottom of the brackets?

U1052851 commented 2 years ago

Or, is there a save and exit command after altering the sys.config file? (I'm just using Windows PowerShell)

gitxmax commented 2 years ago

Or, is there a save and exit command after altering the sys.config file? (I'm just using Windows PowerShell)

type "exit"

mojomartini commented 2 years ago

Or, is there a save and exit command after altering the sys.config file? (I'm just using Windows PowerShell)

In vi you have to switch to command mode <ESC> then :x <ENTER>

inigoflores commented 2 years ago

@fulda-cz @mojomartini have you tried installing it?

opkg update && opkg install php7-cli

@robgit77

Is /mnt/data/docker/volumes/xxxxxxx_miner-log/_data the right path or xxxxxxx_miner is some kind of placeholder?

A Constructed Challenge is what triggers the challengee to send a beacon. When witnesses are received by the chellanger, it gathers them all and includes them in a PoC transaction. For some reason, the challenger sometimes fails to close this transaction. I'm currently investigating one of my hotspots that is severely affected by this:

image

It's probably the same issue that is causing a large number of timeouts.

Date                    | Session    | RSSI | Freq  | SNR   | Challenger                                           | Relay | Status            | Fails | Reason 
-------------------------------------------------------------------------------------------------------------------------------------------------------------- 
2022-02-12 23:22:49.224 |   0.2407.0 | -118 | 867.5 | -12.2 | 112MZQeoupC6QSjxBBRJDtcnSwgrKRzW9tt3zhLDX8xn5JELaEQJ | yes   | failed max retry  |    10 | timeout 
2022-02-12 23:34:39.571 |   0.3657.0 |  -97 | 867.3 |   1.8 | 1124Uu2MPvQYBJeUoHqJdiXHt6BLRv38vx4A6PSJM2MHySFUrUYr | yes   | failed max retry  |    10 | timeout 
2022-02-13 01:03:02.474 |  0.11655.0 | -117 | 867.3 | -13.2 | 112W3ux2yMdJZdFyxq9vnqQ6Xarx3ufZqBsSfDrUHgKhtkYVZJZv | yes   | failed max retry  |    10 | timeout 
2022-02-13 02:48:04.719 |  0.22280.0 |  -95 | 867.5 |   4.2 | 112jJb9Er8TLGYJDGbVEGRAYhX8Q86BjNQTUSMQXdQ1cbuyhRGtE | no    | failed max retry  |    10 | timeout 
2022-02-13 03:34:48.322 |  0.26792.0 |  -50 | 868.3 |   7.2 | 11rU3itVwmsgj7wcVF5CLL74hKabfSZ6NMjPGz6M3VtmpGYfTLT  | no    | successfully sent |     0 |  
2022-02-13 04:33:18.109 |  0.31065.0 |  -96 | 867.3 |   2.0 | 11rndNskguCFJw4dKVUCSHvLWasmJkhWzchioMcgnq8DDVH56HN  | yes   | failed max retry  |    10 | timeout 
2022-02-13 06:12:55.123 |   0.6608.1 | -108 | 867.7 |  -3.2 | 112XCpVKw2jZoBgJRrKHk78qmM7CeKYjimsLSJ9tVziZTxgdDw4i | no    | failed max retry  |    10 | timeout 
2022-02-13 09:35:11.562 |  0.24819.1 | -118 | 868.3 | -10.5 | 112V5pWAj8ipQRxzoyeFnafPXwD2JWrmmknrRYm3HpCPgGgn4h8g | yes   | failed max retry  |    10 | timeout 
2022-02-13 10:46:47.591 |  0.32652.1 |  -50 | 868.1 |   8.2 | 112GeXVDnmxNmRruvQPEHT33wMhXNmdwL9Fixat2uQQf3P6iX8pe | no    | successfully sent |     0 |  
2022-02-13 15:29:56.772 |  0.24637.2 | -127 | 868.3 | -12.0 | 112p8ox2wXBJYUvRQ3HEAaMxtoCSvUJE31Z9fF9a4ezbDKY8Sakc | no    | successfully sent |     0 |  
2022-02-13 15:49:09.057 |  0.26084.2 |  -50 | 868.1 |   8.2 | 117MVygbRriU2uKzWPeNFycz4zCGmLMimyqgaP4EXHdv3pb2NS5  | no    | successfully sent |     0 |  
2022-02-13 17:35:28.018 |   0.2084.3 | -115 | 868.3 |  -9.8 | 112epQrt9vEUd6VdPGQnR6vsge8U3iyaAvFkAHjF9PhubqiobmQn | yes   | failed max retry  |    10 | timeout 
2022-02-13 18:02:06.128 |   0.4976.3 | -112 | 868.3 |  -6.5 | 112qBZz1VDWo9irjFP4CDmQaG2sZ5VmHPrpSSnzrUyey1oDJh1oK | yes   | failed max retry  |    10 | timeout 
2022-02-13 19:51:07.394 |  0.14509.3 | -117 | 867.1 | -14.2 | 112FwuLe2zWzXdfb531ui2WKpqumYMEgPG2w7j1FYLD7VgoprT1o | yes   | failed max retry  |    10 | timeout 
2022-02-13 22:23:09.050 |  0.29029.3 | -128 | 868.3 | -12.8 | 11YTFumtc4bixS7vvdJLpepNTP1QQ3UZpcPQhBUsg9X131bEEJv  | no    | successfully sent |     0 |  
2022-02-14 06:01:23.127 |  0.31445.0 | -109 | 868.5 |  -3.8 | 112biDHLE3gyy4QZPYRDhTx6QXiPRGGeMPcLPYLLDkmZCS4ftTaF | no    | successfully sent |     1 |  
2022-02-14 07:24:36.132 |   0.7554.1 | -114 | 867.7 |  -9.0 | 11jKLouCsEHbmgThCiPKa7zKptTqoTGXhUAWGm6rRZrGsSwgsBv  | no    | failed max retry  |    10 | timeout 
2022-02-14 09:14:51.685 |  0.18770.1 | -109 | 868.3 |  -2.2 |                                                      |       | incomplete        |     0 |  
2022-02-14 11:17:52.392 |  0.12727.0 | -110 | 868.3 |  -2.2 | 11MMiyv1jqtiNoN6bcB54cV4j8nBq99UqDukVbNnDRmPRPiuQGx  | yes   | failed max retry  |    10 | timeout 
2022-02-14 13:44:20.132 |   0.4514.0 |  -98 | 867.1 |   2.0 | 112bJHZbxiapuWsThyyP1hXfXiWkHd9Wyu8hEbJVXT9rh3YTadkU | yes   | failed max retry  |    10 | timeout 
DCYeahThatsMe commented 2 years ago

I know this probably doesn't help many people :) But I winSCP'ed the log files out of my Milesight UG65 and onto my ubuntu box, and php analyzed it using the amazing script from @inigoflores (THANK YOU!!!) I now see the data... that I probably didn't want to see.

Total witnesses = 51 Succesfully delivered = 43 (84.31%) Failed = 8 (15.69%)

I'm using 100/25 as my values... Is there anything else we can do to help solve this issue and convert more failed witness confirmations to successes??

fulda-cz commented 2 years ago

@fulda-cz @mojomartini have you tried installing it?

@inigoflores yes, I tried but even the opkg utility is not present in the Milesight host system :-o So I did the same trick as @DCYeahThatsMe (many thanks to both of you) and transferred all miner logs to my ubuntu server and successfully started the script processlogs.php Here is my data when I tuned the miner to 20/10

General Witnesses Overview
----------------------------------
Total witnesses                   =    15
Succesfully delivered             =    14 (93.33%)
Failed                            =     1  (6.67%)
  ├── Max retry    =    1  (6.67%)
  └── Crash/reboot =    0     (0%)

It's much better than in the past. As you can see, I count every single witness ;-)

bfonseca commented 2 years ago

Hi @inigoflores , can you please help me, according to the logs today i was able to send successfully 17 witness but there is not transactions of them:

Miner animal name:Young Aegean Aardvark

`admin@raspberrypi:~ $ ./processlogs.php -a -s 2022-02-17 -e 2022-02-18

Using logs in folder /home/pi/hnt/miner/log/

General Witnesses Overview

Total witnesses = 22 Succesfully delivered = 17 (77.27%) Failed = 5 (22.73%) ├── Max retry = 5 (22.73%) └── Crash/reboot = 0 (0%)

Max Retry Failure Reasons

Timeout = 5 (100%) Not Found = 0 (0%) Other challenger issues = 0 (0%)

Challengers

Not Relayed = 18 (81.82%) Relayed = 4 (18.18%) Unknown Relay Status = 0 (0%) admin@raspberrypi:~ $

##############################

admin@raspberrypi:~ $ ./processlogs.php -l -s 2022-02-17 -e 2022-02-18

Using logs in folder /home/pi/hnt/miner/log/

Date | Session | RSSI | Freq | SNR | Challenger | Relay | Status | Fails | Reason

2022-02-17 00:08:17.532 | 0.4463.0 | -121 | 867.5 | -22.0 | 112oQhYiBRo86CheEkqS5evMCwkDgs9EhRcfcMr3RwNsee2zTh5R | no | successfully sent | 1 | 2022-02-17 00:52:08.637 | 0.6799.0 | -102 | 868.5 | -4.5 | 11jHvQr5GYBkyJhkUsJqFfy2EBFNF9g89FLG5LRAJSgKYVhqyNc | no | successfully sent | 1 | 2022-02-17 02:40:38.926 | 0.12380.0 | -121 | 867.3 | -20.0 | 11cyYjM6n9VichzqymY8FZ1GRf5kG3NVm2o4oxZ7s3hU63mp4Rj | no | successfully sent | 1 | 2022-02-17 02:49:48.366 | 0.12714.0 | -121 | 867.1 | -20.8 | 112Las8XgkGsxo7UQRHVteSB4quabgy5kUdS8hk6Z4RgDjiNDp87 | no | successfully sent | 1 | 2022-02-17 03:28:58.076 | 0.2057.0 | -104 | 867.1 | -4.5 | 112iMuWtVhdsywXBtW8qscthMsH3DBLiujj95KFtQeVsRHcbE118 | no | successfully sent | 1 | 2022-02-17 03:44:54.217 | 0.2663.0 | -99 | 867.7 | 1.0 | 11EboebRrmaki9VBKn4b1T3dQ8WMvohHDdyme3CszdTR97rAL55 | no | failed max retry | 10 | timeout 2022-02-17 04:09:53.128 | 0.4373.0 | -111 | 867.3 | -11.0 | 11uTZAAfW1Bv9phzVzrtppRVsWnPeaRjTphtAMbLmdqgxVtLpCX | no | successfully sent | 1 | 2022-02-17 04:30:18.273 | 0.5466.0 | -122 | 868.3 | -21.0 | 112dGvVsJkwAp2LJBmF6L371qcB8mTxq8pmgAxZQc8fyHUcapKTq | no | successfully sent | 1 | 2022-02-17 04:44:14.012 | 0.6629.0 | -110 | 868.3 | -11.0 | 1126iZABDCz3ki46qv8G1nSigg2dHbk15HXYva4GrayZsZwBpRhp | no | successfully sent | 0 | 2022-02-17 04:45:29.995 | 0.6217.0 | -121 | 867.9 | -20.0 | 112LPyAG3XepdYXpNJQ3HZfBJ41tm7ta94MzLXgjXNNMB5ZKjG2n | yes | failed max retry | 10 | timeout 2022-02-17 04:46:34.829 | 0.6705.0 | -116 | 868.5 | -16.8 | 11bLoQ68BFpfRnwcTYXKwtGqxePNQWzhQ1MtsEGmTiX9MjUmfpS | no | successfully sent | 1 | 2022-02-17 05:04:17.979 | 0.7569.0 | -74 | 867.9 | 7.2 | 112TnYFGntyXEq5khRVmkADg4UQ4YNEKZBYFwpqFp5bwqzj99yqw | no | successfully sent | 8 | 2022-02-17 05:29:44.206 | 0.9323.0 | -119 | 867.7 | -18.5 | 11MgjcmaaAmczcyEv8JPoSphvSFZLRvvusRGkfLQLrmHyTWH7ND | no | successfully sent | 1 | 2022-02-17 06:22:37.793 | 0.11507.0 | -113 | 867.9 | -12.2 | 11Pz7BGSyoc2PDeabBg8dy15oC9TEbkd5eBeSJLtevyVNg2XN11 | yes | failed max retry | 10 | timeout 2022-02-17 06:54:22.873 | 0.13586.0 | -106 | 867.1 | -6.0 | 11w1RbjrDDSabwVCLxnnk2r6NiSSKkCyRiB96xPEBL6bK7espm2 | no | successfully sent | 1 | 2022-02-17 06:56:55.890 | 0.13720.0 | -119 | 867.9 | -18.8 | 11A7x1iuKCdBzggeyvJKHx37QnbfgehHgPJdmx2HL9HzCGG63je | no | successfully sent | 1 | 2022-02-17 07:23:07.690 | 0.14674.0 | -122 | 868.5 | -24.0 | 112qdFv1Xxw9TUhyxCJCMS345oQtNmtXjdJxHVBLsvkddWTWydvZ | yes | failed max retry | 10 | timeout 2022-02-17 08:37:46.559 | 0.18375.0 | -119 | 867.9 | -19.2 | 11BM7fTBpa6VnfyJvasTxYpcJEiBqZCwLpRP3QGvyZQn6bF1cHE | no | successfully sent | 1 | 2022-02-17 09:02:47.282 | 0.19039.0 | -119 | 867.7 | -20.2 | 112MWPeLuNJte7ZQKHpo5MSNUNXx5Z9Zaf5JxCTFHwyzDc2tYsbR | yes | failed max retry | 10 | timeout 2022-02-17 09:10:58.340 | 0.19731.0 | -97 | 868.5 | 0.0 | 11YodE4vcWp9QZUafCwxhauTTDUSSsX1LSwKRKydgsP5Smh2EgR | no | successfully sent | 1 | 2022-02-17 09:35:24.624 | 0.20773.0 | -92 | 867.1 | 3.0 | 115v5TAuVMFKnuwWfeiCTMHZFD64PSU7ssebGbjZywjrKdEDUYV | no | successfully sent | 1 | 2022-02-17 10:30:31.025 | 0.23060.0 | -98 | 867.9 | 1.0 | 1124U1aZkMryYqZvR7AgnzWJQFDMvYtkZrZCUnDbb34bjGqJfYyt | no | successfully sent | 1 | admin@raspberrypi:~ $ `

snip commented 2 years ago

This is not because your hotspot is able to send witness information to challanger that you will be selected to be part of the 14 witness for this beacon. This should be random. But for 18 witness you should have at least few selected and visible in explorer. There is maybe something else preventing these witness to be taken into account in the PoC.

bfonseca commented 2 years ago

Hi, thanks for your quick replay. With 17 successful witness sent only have 3 reported in the explorer, that's a lot of work for nothing. Does this tool takes in consideration the error logs too? because i'm full of them.

2022-02-17 09:02:47.282 [error] <0.19039.0>@miner_onion_server:send_witness:{207,5} failed to send witness, max retry 2022-02-17 07:48:48.435 [error] <0.16211.0>@libp2p_stream_relay:handle_server_data:{193,13} fail to pass request {libp2p_relay_bridge_cr_pb,"/p2p/112fhziXFE4gU1aYrkwQ87asTQAbKWzGiw4i3XkC3EgxbEFFHnq8","/ip4/172.88.242.5/tcp/44158"} Server not found 2022-02-17 07:23:07.690 [error] <0.14674.0>@miner_onion_server:send_witness:{207,5} failed to send witness, max retry 2022-02-17 07:13:29.041 [error] <0.14450.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/135pzA3pJxfz6Wr2y9PRP6XrTZdvJKBS4GivcFynojiCBSX3716", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 07:13:29.037 [error] <0.14447.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/11DQJE3MwEtdE8tpURvrV8vMZ7XW2nRrjzDXBwq3ENrmJn4vVYs", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 07:12:38.210 [error] <0.14399.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/119sJJguKYjZ4ZoBaMCr5iBcY8bQrDQNCUYVyXFmynUmpLcbpm9", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 07:12:38.201 [error] <0.14395.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/112fiD5UzzqcBSDkpy3a9JmtXMhgnXUVSuXdj7Ks8DAn24vpbfrh", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 07:12:38.198 [error] <0.14397.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/14FqiBUwVngt6YXsF6dsfK7Na5VKWqPjPXTezboS2wxrNrgnZja", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 07:12:38.196 [error] <0.14396.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/142MJh9h9xVj3xyMQo99zXCd85fJr9GckzhyTAdtbU5wkLLjGp4", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 07:12:38.191 [error] <0.14393.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/14cMTZB4dj7vVDDMqhQ4t2nTRrzm8Tgb1jvNvdLxUPQasXUU4Yd", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 07:12:38.186 [error] <0.14392.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/13tgMTCdJ9UmRSGyFCajX1Jf5y9MLqcNPv4Lhh6EU5BUZ6stCfo", TxnHash: <<110,134,103,251,199,91,71,24,58,206,85,253,61,177,251,172,149,43,87,99,96,89,113,151,248,165,77,157,251,239,110,137>> 2022-02-17 06:55:55.505 [error] <0.1661.0>@miner_poc_statem:send_onion:{1015,13} poc_id=qhppZdum5_D9hM0cDk1LZE6W4gCaUZ-qhngvGeEX954 failed to dial 1st hotspot ("/p2p/112kAVt3oN24wHWR7X8DohJyLBBmeuibAoDe7aJ1nKuAxD7WRwGS"): not_found 2022-02-17 06:50:10.849 [error] <0.13375.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/137JtBvPgQyWzuDgPoB1VX2psEJHLRpG5YGzSsycv8KAvnU1XSx", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:50:10.849 [error] <0.13374.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/1128M31hkL9fW6qhZYNWhLpHguqH9Ezh7VyCA5rbG5XCpPBdt3UU", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:50:10.849 [error] <0.13373.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/11uBjfLFoFkLKAHD5D1WFDTLfSej6DzrcMkAudhRPg6QRPXahLk", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:50:10.843 [error] <0.13370.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/112a7MBGikdRd6bu81965b8o8qR2wjyH6AWDL51jj6tZ9itvjc91", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:49:21.738 [error] <0.13273.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/135pzA3pJxfz6Wr2y9PRP6XrTZdvJKBS4GivcFynojiCBSX3716", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:49:21.733 [error] <0.13270.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/1123RVFSzFg9J4YWS6264VQCV2w6GSpdcfUfpc1CKK5SVMh96Hcn", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:49:21.733 [error] <0.13271.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/11RhwxFboGQWGMwagxHn2fygRmt4cfektBa8noztKCK1cXJsxXy", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:49:21.732 [error] <0.13268.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/11Z297hHNPhFm6prifXbLYTMg4Mju8AUmazUiM1itbkvjZNYFVm", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:48:21.072 [error] <0.13218.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/11tKzhdgt2QQedrQc2C5cMcYYwKGG5PGvT6thZy2Y6UpQmHRpB2", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:48:21.071 [error] <0.13217.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/11Xin4S8AnHf29harxwQSuyk8y2xsRPQK1XGFmKpwLnrSh5bzS1", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:48:21.070 [error] <0.13216.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/117WVDSXnqrxMF2xD2qhF2zHucGrHBkgsca78wnsDkaC1vuhoZf", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:48:21.065 [error] <0.13214.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/14MbB3xo8w5j1i7mhvg85rwifGfBmqsxpnYStn8HuwM5eW45vT8", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:48:21.065 [error] <0.13213.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/14G9sgkVsuCaJ9jsVEm8gqbftBnis4YRMmFtxZdceLZDBw6dnmQ", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:48:21.063 [error] <0.13212.0>@blockchain_txndialer:dial:{142,21} libp2p_framed_stream dial failed. Reason: not_found, To: "/p2p/13cqwZJPYnVD9eeiFnZXH15xxLebUZBCGRNcdGsDc5pioZAWb6N", TxnHash: <<246,68,186,166,158,206,251,162,182,217,102,0,164,152,195,15,234,147,123,76,183,232,169,0,61,201,177,161,194,177,173,107>> 2022-02-17 06:28:11.760 [error] <0.12229.0>@libp2p_stream_relay:handle_server_data:{193,13} fail to pass request {libp2p_relay_bridge_cr_pb,"/p2p/112RBt3uHibiv5xxW1H1wcdeLb6PBx1fZK4sSspYYr3xEEaQArD6","/ip4/172.88.231.113/tcp/44158"} Server not found 2022-02-17 06:22:37.793 [error] <0.11507.0>@miner_onion_server:send_witness:{207,5} failed to send witness, max retry 2022-02-17 06:16:02.588 [error] <0.11507.0>@libp2p_transport_relay:connect_rcv:{127,13} stream <0.11527.0> went down normal 2022-02-17 05:25:04.462 [error] <0.9178.0>@libp2p_stream_relay:handle_server_data:{193,13} fail to pass request {libp2p_relay_bridge_cr_pb,"/p2p/112fhziXFE4gU1aYrkwQ87asTQAbKWzGiw4i3XkC3EgxbEFFHnq8","/ip4/86.128.1.51/tcp/44158"} Server not found 2022-02-17 04:45:29.995 [error] <0.6217.0>@miner_onion_server:send_witness:{207,5} failed to send witness, max retry 2022-02-17 04:35:19.287 [error] <0.5893.0>@libp2p_stream_relay:handle_server_data:{193,13} fail to pass request {libp2p_relay_bridge_cr_pb,"/p2p/112ujt1EdXVJ93qNne3xNAemiRNdDfHWjACfzGhyjUAd6Y4wCHuu","/ip4/172.115.210.16/tcp/44159"} Server not found 2022-02-17 04:32:44.745 [error] <0.5732.0>@libp2p_stream_relay:handle_server_data:{193,13} fail to pass request {libp2p_relay_bridge_cr_pb,"/p2p/112fhziXFE4gU1aYrkwQ87asTQAbKWzGiw4i3XkC3EgxbEFFHnq8","/ip4/92.27.108.224/tcp/44158"} Server not found 2022-02-17 03:44:54.217 [error] <0.2663.0>@miner_onion_server:send_witness:{207,5} failed to send witness, max retry 2022-02-17 03:22:45.861 [error] <0.1712.0>@libp2p_transport_proxy:connect_to:{69,13} failed to dial proxy server "/p2p/11FarxDue18H4kij2TaiYA75Ar7EZGuEZZpJ2ZDtxV8Q8evWpvz" not_found

orhanhs commented 2 years ago

@gitxmax I'm currently using:

{max_inbound_connections, 200},
{outbound_gossip_connections, 50},

Probably not necessary that much. I make some adjustments and see the response.

@DCYeahThatsMe

The script can be found here: https://github.com/inigoflores/helium-miner-log-analyzer . You will have to specify the path to the logs folder with the option -p.

Let me know the full path to the logs in the Milesight miner and I will update to the script.

@inigoflores full path to the logs in the Milesight: /mnt/mmcblk0p1/miner_data/log/console.log

rickyrickuk commented 2 years ago

The sys.config changes seem to be lost on a reboot, any way of getting them to stick?

inigoflores commented 2 years ago

@rickyrickuk Are you making the changes in an "overlay" sys.config? If you are making them in the docker file, it's normal that they are lost. Every miner is different. You will have to find a custom solution for yours.

I've added the provided paths to the script. Thanks for this. As for Milesight, I don't have access to one, so I can't help sort out the PHP issue.

@bfonseca there are many reasons why the witnesses don't make it to the blockchain. You can find a quick explanation in https://github.com/inigoflores/helium-miner-log-analyzer

@DCYeahThatsMe Check the peerbook list. Ideally you want it to be at around 200.000. If it's lower, you may want to increase max_inbound_connections and outbound_gossip_connections.

rickyrickuk commented 2 years ago

@rickyrickuk Are you making the changes in an "overlay" sys.config? If you are making them in the docker file, it's normal that they are lost. Every miner is different. You will have to find a custom solution for yours.

Thanks @inigoflores , edited the correct file now :-)

ghost commented 2 years ago

@inigoflores on Milesight it is more convenient to enter the miner container and apk add php and operate there directly, since they are using Alpine distribution. While Milesight itself uses trimmed down Openwrt (with package manager removed).

THplusplus commented 2 years ago

The new miner release removed most of the sys.config contents. max_inbound_connections and outbound_gossip_connections settings no longer exist in there.

ghost commented 2 years ago

The new miner release removed most of the sys.config contents. max_inbound_connections and outbound_gossip_connections settings no longer exist in there.

I still see it on "2022.02.22.0" Release.

THplusplus commented 2 years ago

Weird!! A few minutes ago, all that config/sys.config contained was

%% -*- erlang -*-
[
  "config/sys.config",
  {lager,
    [
      {log_root, "/var/data/log"}
    ]},
  {blockchain,
    [
      {snapshot_memory_limit, 1000}
    ]},
  {miner,
    [
      {jsonrpc_ip, {0,0,0,0}},
      {radio_device, { {127,0,0,1}, 1680,
        {0,0,0,0}, 31341} }
    ]}
].

Now it's back to what it's supposed to be... No clue what happened there.

inigoflores commented 2 years ago

@beinbliss Thanks for the tip. I've added instructions for this in the Repo.

@THplusplus It's probably just your miner maker performing OTA updates. You will have to keep an eye on that file in case the settings are regularly overwritten.

masterconqueror commented 2 years ago

would changing these numbers get us into the denylist?

THplusplus commented 2 years ago

I doubt it. It solves a problem that's not intended - hotspots are supposed to be able to communicate optimally. Also, libp2p will no longer be used once Light Hotspots are rolled out, and replaced with gRPC and direct Light Hotspot<->Validator communication. This will (should) remove the current problems anyway, as Validators are much more static, easy to reach directly, endpoints. So: the developers are seeing that this problem exists and working on fixing it. In the meantime, changing the variables does not harm anyone, neither does it give us any unfair rewards, it only ensures that the proof of coverage, that we totally legitimately have and should be able to claim, reaches the blockchain.

masterconqueror commented 2 years ago

I doubt it. It solves a problem that's not intended - hotspots are supposed to be able to communicate optimally. Also, libp2p will no longer be used once Light Hotspots are rolled out, and replaced with gRPC and direct Light Hotspot<->Validator communication. This will (should) remove the current problems anyway, as Validators are much more static, easy to reach directly, endpoints. So: the developers are seeing that this problem exists and working on fixing it. In the meantime, changing the variables does not harm anyone, neither does it give us any unfair rewards, it only ensures that the proof of coverage, that we totally legitimately have and should be able to claim, reaches the blockchain.

i am not sure about fairness. not all devices have ssh access or all users knows about this. i think someone have to ask about this to developers.

inigoflores commented 2 years ago

@masterconqueror I agree with @THplusplus. If anything, those hotspots that can handle a larger peer book are doing a service to the network, benefiting other direct peers that have smaller peer books. The "not found" errors are also reduced for these.

In any case, you can't build a fairness case based on a network operation which is clearly dysfunctional. The default parameters were probably calculated and tested for a network size of say 20,000 hotsptos. We are at almost 600,000 and it's obvious that those parameters don't work any more. The devs are not concerned with spending time addressing these issues (just take a look at the amount of Github issues piling up), they are focused on making the transition to light hotspots a reality ASAP.

Some miner owners may not have access to SSH, but all makers can push OTA updates if they want.

microtransactions commented 2 years ago

Changing the value max_inbound_connections and outbound_gossip_connections on miner-arm64_2022.02.28.0_GAdoesn't seem to work anymore, it crashes my miner. The only reliable settings I can make it work is 96 and 16 respectively. That doesn't help much as my peer book count is around 80K. Anybody else confirm this? any ideas how to properly fix this?

DCYeahThatsMe commented 2 years ago

I haven't had this issue... I'm on 02.28 and it hasn't crashed my miner. What's your logs look like? Can you post them or describe what's happening with more detail?

marcijel1 commented 2 years ago

Yesterday I had a really unbeliveable day with peerbook near 200,000 and 02.28.

General Witnesses Overview
----------------------------------
Total witnesses                   =    77
Succesfully delivered             =    72 (93.51%)
Failed                            =     5  (6.49%)
  ├── Max retry    =    5  (6.49%)
  └── Crash/reboot =    0     (0%)

Max Retry Failure Reasons
----------------------------------
Timeout                           =     4    (80%)
Not Found                         =     0     (0%)
Other challenger issues           =     1    (20%)

Challengers
----------------------------------
Not Relayed                       =    73 (94.81%)
Relayed                           =     4  (5.19%)
Unknown Relay Status              =     0     (0%)