[Ovmsdev] Branch for-v3.3 network issues

Fri Mar 12 22:32:04 HKT 2021

I just tried switching to for-v3.3 in my car module after tests on my 
desk module were OK, and I've run into the very same problem with 
for-v3.3. So the issue isn't related to esp-idf.

The network only occasionally starts normally, but even then all 
connectivity is lost after a couple of minutes.

The stale connection watchdog in server-v2 triggers a network restart, 
but that also doesn't seem to succeed:

2021-03-12 14:53:01.802 CET W (981652) ovms-server-v2: Detected stale 
connection (issue #241), restarting network
2021-03-12 14:53:01.802 CET I (981652) esp32wifi: Restart
2021-03-12 14:53:01.802 CET I (981652) esp32wifi: Stopping WIFI station
2021-03-12 14:53:01.812 CET I (981662) wifi:state: run -> init (0)
2021-03-12 14:53:01.812 CET I (981662) wifi:pm stop, total sleep time: 
831205045 us / 975329961 us

2021-03-12 14:53:01.812 CET I (981662) wifi:new:<1,0>, old:<1,1>, 
ap:<1,1>, sta:<1,1>, prof:1
2021-03-12 14:53:01.832 CET I (981682) wifi:flush txq
2021-03-12 14:53:01.842 CET I (981692) wifi:stop sw txq
2021-03-12 14:53:01.842 CET I (981692) wifi:lmac stop hw txq
2021-03-12 14:53:01.852 CET I (981702) esp32wifi: Powering down WIFI driver
2021-03-12 14:53:01.852 CET I (981702) wifi:Deinit lldesc rx mblock:16
2021-03-12 14:53:01.862 CET I (981712) esp32wifi: Powering up WIFI driver
2021-03-12 14:53:01.862 CET I (981712) wifi:nvs_log_init, erase log key 
successfully, reinit nvs log
2021-03-12 14:53:01.882 CET I (981732) wifi:wifi driver task: 3ffd4d84, 
prio:23, stack:3584, core=0
2021-03-12 14:53:01.882 CET I (981732) system_api: Base MAC address is 
not set, read default base MAC address from BLK0 of EFUSE
2021-03-12 14:53:01.882 CET I (981732) system_api: Base MAC address is 
not set, read default base MAC address from BLK0 of EFUSE
2021-03-12 14:53:01.902 CET I (981752) wifi:wifi firmware version: 30f9e79
2021-03-12 14:53:01.912 CET I (981762) wifi:config NVS flash: enabled
2021-03-12 14:53:01.912 CET I (981762) wifi:config nano formating: disabled
2021-03-12 14:53:01.912 CET I (981762) wifi:Init data frame dynamic rx 
buffer num: 16
2021-03-12 14:53:01.912 CET I (981762) wifi:Init management frame 
dynamic rx buffer num: 16
2021-03-12 14:53:01.922 CET I (981772) wifi:Init management short buffer 
num: 32
2021-03-12 14:53:01.922 CET I (981772) wifi:Init dynamic tx buffer num: 16
2021-03-12 14:53:01.922 CET I (981772) wifi:Init static rx buffer size: 2212
2021-03-12 14:53:01.922 CET I (981772) wifi:Init static rx buffer num: 16
2021-03-12 14:53:01.922 CET I (981772) wifi:Init dynamic rx buffer num: 16
2021-03-12 14:53:02.642 CET I (982492) wifi:mode : sta 
(30:ae:a4:5f:e7:ec) + softAP (30:ae:a4:5f:e7:ed)
2021-03-12 14:53:02.652 CET I (982502) wifi:Total power save buffer 
number: 8
2021-03-12 14:53:02.652 CET I (982502) cellular-modem-auto: Restart
2021-03-12 14:53:02.662 CET I (982512) cellular: State: Enter PowerOffOn 
state
2021-03-12 14:53:02.662 CET I (982512) gsm-ppp: Shutting down (hard)...
2021-03-12 14:53:02.662 CET I (982512) gsm-ppp: StatusCallBack: User 
Interrupt
2021-03-12 14:53:02.662 CET I (982512) gsm-ppp: PPP connection has been 
closed
2021-03-12 14:53:02.662 CET I (982512) gsm-ppp: PPP is shutdown
2021-03-12 14:53:02.662 CET I (982512) gsm-ppp: Shutting down (hard)...
2021-03-12 14:53:02.672 CET I (982522) gsm-ppp: StatusCallBack: User 
Interrupt
2021-03-12 14:53:02.672 CET I (982522) gsm-ppp: PPP connection has been 
closed
2021-03-12 14:53:02.672 CET I (982522) gsm-ppp: PPP is shutdown
2021-03-12 14:53:02.672 CET I (982522) gsm-nmea: Shutdown (direct)
2021-03-12 14:53:02.672 CET I (982522) cellular-modem-auto: Power Cycle
2021-03-12 14:53:04.682 CET D (984532) events: Signal(system.wifi.down)
2021-03-12 14:53:04.682 CET I (984532) netmanager: WIFI client stop
2021-03-12 14:53:04.682 CET E (984532) netmanager: Inconsistent state: 
no interface of type 'pp' found
2021-03-12 14:53:04.682 CET I (984532) netmanager: WIFI client down 
(with MODEM up): reconfigured for MODEM priority
2021-03-12 14:53:04.692 CET D (984542) events: Signal(system.event)
2021-03-12 14:53:04.692 CET D (984542) events: 
Signal(system.wifi.sta.disconnected)
2021-03-12 14:53:04.692 CET E (984542) netmanager: Inconsistent state: 
no interface of type 'pp' found
2021-03-12 14:53:04.692 CET I (984542) esp32wifi: STA disconnected with 
reason 8 = ASSOC_LEAVE
2021-03-12 14:53:04.702 CET D (984552) events: Signal(system.event)
2021-03-12 14:53:04.702 CET D (984552) events: Signal(system.wifi.sta.stop)
2021-03-12 14:53:04.702 CET E (984552) netmanager: Inconsistent state: 
no interface of type 'pp' found
2021-03-12 14:53:04.712 CET D (984562) events: Signal(system.event)
2021-03-12 14:53:04.712 CET D (984562) events: Signal(system.wifi.ap.stop)
2021-03-12 14:53:04.712 CET E (984562) netmanager: Inconsistent state: 
no interface of type 'pp' found
2021-03-12 14:53:04.712 CET I (984562) netmanager: WIFI access point is down
2021-03-12 14:53:04.712 CET I (984562) esp32wifi: AP stopped
2021-03-12 14:53:04.722 CET D (984572) events: Signal(network.wifi.sta.bad)
2021-03-12 14:53:04.722 CET D (984572) events: Signal(system.event)
2021-03-12 14:53:04.722 CET D (984572) events: Signal(system.wifi.sta.start)
2021-03-12 14:53:04.732 CET D (984582) events: Signal(system.modem.down)
2021-03-12 14:53:04.742 CET I (984592) netmanager: MODEM down (with WIFI 
client down): network connectivity has been lost
2021-03-12 14:53:04.742 CET D (984592) events: Signal(system.modem.down)
2021-03-12 14:53:04.752 CET D (984602) events: Signal(system.event)
2021-03-12 14:53:04.752 CET D (984602) events: Signal(system.wifi.ap.start)
2021-03-12 14:53:04.752 CET I (984602) netmanager: WIFI access point is up
2021-03-12 14:53:26.802 CET E (1006652) events: SignalEvent: queue 
overflow (running system.wifi.ap.start->netmanager for 23 sec), event 
'ticker.1' dropped
2021-03-12 14:53:27.802 CET E (1007652) events: SignalEvent: queue 
overflow (running system.wifi.ap.start->netmanager for 24 sec), event 
'ticker.1' dropped
2021-03-12 14:53:28.802 CET E (1008652) events: SignalEvent: queue 
overflow (running system.wifi.ap.start->netmanager for 25 sec), event 
'ticker.1' dropped
…and so on until
2021-03-12 14:54:01.802 CET E (1041652) events: SignalEvent: lost 
important event => aborting

I need my car now, so will switch back to master for now.

Mark, if you've got specific debug logs I should fetch on the next try, 
tell me.

Regards,
Michael

Am 12.03.21 um 05:47 schrieb Craig Leres:
> I just updated to 3.2.016-68-g8e10c6b7 and still get the network hang 
> immediately after booting and logging into the web gui.
>
> But I see now my problem is likely that I'm not using the right 
> esp-idf (duh). Is there a way I can have master build using 
> ~/esp/esp-idf and have for-v3.3 use a different path?)
>
>         Craig
> _______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.openvehicles.com
> http://lists.openvehicles.com/mailman/listinfo/ovmsdev

-- 
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26

-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature
Type: application/pgp-signature
Size: 203 bytes
Desc: OpenPGP digital signature
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20210312/d640088d/attachment.sig>