search

espressif / esp-hosted

Hosted Solution (Linux/MCU) with ESP32 (Wi-Fi + BT + BLE)
Other
711 stars 170 forks source link

NG mode：ESP32 restart abnormaly #536

Open lwj850533527 opened 2 weeks ago

lwj850533527 commented 2 weeks ago

Checklist

How often does this bug occurs?

rarely

Expected behavior

ESP32 work normaly I want to why print regularly every hour Rx PACKET_TYPE_EAPOL!!!!. Is it related to the ap? Is there any reason that may cause ESP32 to restart.

Actual behavior (suspected bug)

esp32 restart abnormaly 1、01:53:24 start connect ap 2、01:53:30 end connect ap 3、print regularly every hour Rx PACKET_TYPE_EAPOL!!!! 4、after 2 days, 01:57:06 Command[0x8] timed out , it is CMD_ADD_KEY. This time esp32 should happen to the restart 5、after esp32 restarted, [0x4] Command failed, it is CMD_SCAN_REQUEST. It may because of slave side no init

Error logs or terminal output

Nov  9 01:53:24 kernel: [   23.671159] esp32_spi: cmd_auth_request: Authentication request: 0c:8e:29:c3:b1:ea 11 0 0 0
Nov  9 01:53:25 kernel: [   24.027593] esp32_spi: cmd_assoc_request: Association request: 0c:8e:29:c3:b1:ea 11 40
Nov  9 01:53:25 kernel: [   24.076208] esp32_spi: process_assoc_event: Connection status: 0
Nov  9 01:53:25 kernel: [   24.427329] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 01:53:25 kernel: [   24.456601] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 01:53:25 kernel: [   24.456694] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 01:53:25 udhcpc[335]: started, v1.34.1
Nov  9 01:53:25 udhcpc[335]: broadcasting discover
Nov  9 01:53:28 udhcpc[335]: broadcasting discover
Nov  9 01:53:29 udhcpc[335]: broadcasting select for 192.168.2.201, server 192.168.2.1
Nov  9 01:53:30 udhcpc[335]: lease of 192.168.2.201 obtained from 192.168.2.1, lease time 1814400
Nov  9 01:53:30 kernel: [   29.397809] esp32_spi: esp_inetaddr_event: NETDEV_UP interface wlan0 ip changed to  192.168.002.201
Nov  9 01:56:53 kernel: [  232.513649] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 01:56:53 kernel: [  232.513737] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 02:56:53 kernel: [ 3832.736640] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 02:56:53 kernel: [ 3832.736726] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 03:56:54 kernel: [ 7432.850740] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 03:56:54 kernel: [ 7432.850842] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 04:56:54 kernel: [11033.173934] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 04:56:54 kernel: [11033.174018] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 05:56:54 kernel: [14633.188303] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 05:56:54 kernel: [14633.188399] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 06:56:54 kernel: [18233.300732] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 07:56:54 kernel: [21833.514643] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 07:56:54 kernel: [21833.514728] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 08:56:54 kernel: [25433.637592] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 08:56:54 kernel: [25433.637677] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 09:56:55 kernel: [29033.860859] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 09:56:55 kernel: [29033.860951] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 10:56:54 kernel: [32633.974622] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 11:56:54 kernel: [36234.197373] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 11:56:54 kernel: [36234.197450] NOHZ tick-stop error: Non-RCU local softirq work is pending, handler #08!!!
Nov  9 12:56:54 kernel: [39834.310609] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 13:56:54 kernel: [43434.533568] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 14:56:54 kernel: [47034.647371] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 15:56:55 kernel: [50634.870507] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 16:56:55 kernel: [54234.993355] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 17:56:55 kernel: [57835.207071] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 18:56:54 kernel: [61435.330679] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 19:56:54 kernel: [65035.483295] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 20:56:54 kernel: [68635.667146] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 21:56:55 kernel: [72235.791061] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 22:56:55 kernel: [75836.004828] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov  9 23:56:55 kernel: [79436.128168] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 00:56:55 kernel: [83036.271798] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 01:56:54 kernel: [86636.465811] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 02:56:54 kernel: [90236.689926] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 03:56:54 kernel: [93836.803676] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 04:56:54 kernel: [97437.028159] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 05:56:54 kernel: [101037.141423] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 06:56:55 kernel: [104637.365337] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 07:56:55 kernel: [108237.489191] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 08:56:55 kernel: [111837.603499] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 09:56:55 kernel: [115437.827283] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 10:56:55 kernel: [119037.941028] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 11:56:55 kernel: [122638.164299] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 12:56:55 kernel: [126238.278009] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 13:56:56 kernel: [129838.501986] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 14:56:56 kernel: [133438.625655] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 15:56:56 kernel: [137038.849391] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 16:56:56 kernel: [140638.963056] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 17:56:56 kernel: [144239.186320] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 18:56:55 kernel: [147839.300581] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 19:56:56 kernel: [151439.424637] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 20:56:56 kernel: [155039.768063] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 21:56:56 kernel: [158639.861781] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 22:56:56 kernel: [162239.985405] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 10 23:56:56 kernel: [165840.098843] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 11 00:56:57 kernel: [169440.322874] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 11 01:57:01 kernel: [173046.767331] esp32_spi: process_rx_packet: Rx PACKET_TYPE_EAPOL!!!!
Nov 11 01:57:06 kernel: [173051.876817] esp32_spi: wait_and_decode_cmd_resp: Command[0x8] timed out
Nov 11 01:57:06 kernel: [173051.882224] esp32_spi: cmd_add_key: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -22
Nov 11 01:57:06 kernel: [173052.049548] esp32_spi: decode_common_resp: [0x4] Command failed
Nov 11 01:57:06 kernel: [173052.049612] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -1
Nov 11 01:57:06 kernel: [173052.089074] esp32_spi: esp_inetaddr_event: Interface Down: 0
Nov 11 01:57:08 kernel: [173053.129150] esp32_spi: decode_common_resp: [0x4] Command failed
Nov 11 01:57:08 kernel: [173053.129215] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -1
Nov 11 01:57:09 kernel: [173054.169658] esp32_spi: decode_common_resp: [0x4] Command failed
Nov 11 01:57:09 kernel: [173054.169777] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -1
Nov 11 01:57:10 kernel: [173055.210073] esp32_spi: decode_common_resp: [0x4] Command failed
Nov 11 01:57:10 kernel: [173055.210137] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -1
Nov 11 01:57:11 kernel: [173056.259391] esp32_spi: decode_common_resp: [0x4] Command failed
Nov 11 01:57:11 kernel: [173056.259459] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -1
Nov 11 01:57:12 kernel: [173057.299657] esp32_spi: decode_common_resp: [0x4] Command failed
Nov 11 01:57:12 kernel: [173057.299797] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -1
Nov 11 01:57:13 kernel: [173058.339451] esp32_spi: decode_common_resp: [0x4] Command failed
Nov 11 01:57:13 kernel: [173058.339505] esp32_spi: cmd_scan_request: wait_and_decode_cmd_resp(priv, cmd_node) failure, ret: -1
Nov 11 01:57:14 kernel: [173059.379823] esp32_spi: decode_common_resp: [0x4] Command failed

Steps to reproduce the behavior

1、sta connect to ap 2、there are no other operations available

Project release version

1.0.3.0.0

System architecture

other (details in Additional context)

Operating system

Linux

Operating system version

linux

Shell

ZSH

Additional context

No response

mantriyogesh commented 2 weeks ago

@kapilkedawat ++

kapilkedawat commented 2 weeks ago

Hi @lwj850533527, AP may be doing periodic GTK rekeying for which you are getting a EAPOL in regular interval. Please share the logs for ESP32 when it is rebooting.

lwj850533527 commented 2 weeks ago

This is a problem that takes a long time to occur and rarely. I am unable to directly get the logs of ESP32, is there any way to send the logs for ESP32 when it is rebooting to host

kapilkedawat commented 6 days ago

is there any way to send the logs for ESP32 when it is rebooting to host

Unfortunately that is not possible. Is there a way for you to connect uart to chip?