Hi,
I purchased an OVMS module and have been working on getting it working with my 2016(US) SmartCar ED.
I can't get the Wifi Client to connect to my home Wifi or tether to my phone. The AP works perfectly, but when I try to connect the client, the best I can do is get the status page to show the SSID with an IP address of 0.0.0.0.
My home wifi is an Eero mesh network, but that shouldn't be a problem. I even tried to connect the "guest" network and had the same problem.
I did a couple of factory resets, and also flashed the latest firmware via an SD card.
In general, you need to set AP + Client mode, and then specify both the AP SSID and Client Mode SSID.
You can try to enable verbose logging to SD Card, to get more information on the error. Alternatively, use a USB serial connection and 'log monitor verbose' to see the details.
Based on this thread and what I've seen in the last week, it seems to me like there's something going on with the wifi connection management. Last week, I helped someone on TMC with a problem they were having (I believe you commented on Bunnak's thread over there). His problem was essentially the same as what was reported in this thread; he couldn't get his module to connect to his wifi. I believe he's using Orbi equipment to run his wifi. I went over to his house 3 times and we were never able to get it to connect. Since his garage was detached from the condo where the AP is, I eventually just chalked it up to poor signal quality since we were able to get it to connect it to his iphone's hotspot.
However, I received my ovms module yesterday. I was quickly able to get it connected to the wifi network at my house. However, I have since left the house twice and both times the ovms module has failed to reconnect to wifi upon returning. I'm sure if I unplug the cable to power cycle it, it will reconnect. I don't have the modem module yet as it shipped a couple of days after the base module so I don't know for sure if the module is completely unresponsive, or it's just the wifi since I don't have another way to connect to it at this point. For security reasons, I disabled the AP on the box and have it in client mode. I added my home's wifi as the primary connection and my phone's hotspot as a secondary. It won't connect to either right now.
What's worse is that whatever state the box is in seems to be affecting the vehicle as it is slow to respond to the key fob, or sometimes will not respond to the fob at all.
Once I have more time, I'll take your advice and stick an sd card in it to see if I can get some more verbose log messages from it.
I'll try to get some logs, too.
For the record, I have been trying to put it in both AP and Client mode. I tried just client mode once, which made it completely inaccessible over the network.
I have strong Wifi in my garage (it has an Eero since I use the garage as a workshop,) but also set it up on USB power in the house before trying it in the car. This isn't a signal-strength issue.
I haven't been able to SSH the device either, even while I can access it in AP mode. I was going to bring that up in another thread.
So I kicked logs into Verbose and saved them to my SD card.
1970-01-01 00:05:34 GMT D (333373) events: Signal(system.event)
1970-01-01 00:05:34 GMT D (333433) events: Signal(system.wifi.sta.disconnected)
Not very informative.
I connected a console and took a look at some wifi info. (I tried to look va the web console, but it's not possible to respond to the enable password prompt):
OVMS# wifi status
Power: on
Mode: Access-Point + Client mode
STA SSID: Goebelbecker (-84 dBm)
MAC: 00:00:00:00:00:00
IP: 0.0.0.0/0.0.0.0
GW: 0.0.0.0
AP SSID: AluminumFalcon
MAC: b4:e6:2d:d2:cc:82
IP: 192.168.4.1
AP Stations: 0
It looks like it's connected, but it doesn't have a MAC? it never pulled an IP or route from DHCP?
It's connecred (I think) to the weakest instance of my mesh network
When I do a scan:
OVMS# wifi scan
Scanning for WIFI Access Points...
AP SSID MAC ADDRESS CHAN RSSI AUTHENTICATION
================================ ================= ==== ==== ======================
<HIDDEN> 14:22:db:9c:9b:84 1 -46 WIFI_AUTH_WPA2_PSK
Goebelbecker 14:22:db:9c:9b:86 1 -47 WIFI_AUTH_WPA2_PSK
<HIDDEN> 14:22:db:9c:9b:88 1 -47 WIFI_AUTH_OPEN
Wall 14:22:db:9c:9b:8c 1 -48 WIFI_AUTH_WPA2_PSK
Goebelbecker 14:22:db:2f:8e:e6 1 -69 WIFI_AUTH_WPA2_PSK
<HIDDEN> 14:22:db:2f:8e:e8 1 -69 WIFI_AUTH_OPEN
<HIDDEN> 14:22:db:2f:8e:e4 1 -69 WIFI_AUTH_WPA2_PSK
Wall 14:22:db:2f:8e:ec 1 -71 WIFI_AUTH_WPA2_PSK
Wall 14:22:db:32:35:cc 1 -76 WIFI_AUTH_WPA2_PSK
<HIDDEN> 14:22:db:32:35:c8 1 -76 WIFI_AUTH_OPEN
<HIDDEN> 14:22:db:32:35:c4 1 -76 WIFI_AUTH_WPA2_PSK
Goebelbecker 14:22:db:32:35:c6 1 -77 WIFI_AUTH_WPA2_PSK
<HIDDEN> 14:22:db:2f:88:e8 1 -81 WIFI_AUTH_OPEN
<HIDDEN> 14:22:db:2f:88:e4 1 -81 WIFI_AUTH_WPA2_PSK
Wall 14:22:db:2f:88:ec 1 -82 WIFI_AUTH_WPA2_PSK
Goebelbecker 14:22:db:2f:88:e6 1 -82 WIFI_AUTH_WPA2_PSK
D3021A 3c:1e:04:d3:02:1e 1 -85 WIFI_AUTH_WPA_WPA2_PSK
DIRECT-16-HP M252 LaserJet da:0f:99:86:26:16 1 -87 WIFI_AUTH_WPA2_PSK
===================================================================================
Scan complete: 18 access point(s) found
There's a much stronger AP listed first in the scan. It's about one meter from the box.
I managed to get my OVMS to connect to my phone my renaming it a shorter SSID with no spaces and no punctuation.
I suspect there are two problems here:
1) The Wifi board doesn't play nice with mesh setups. Rather than picking the strongest AP with the configured name, it grabs one (random? first in scan?) and gets "stuck" if it's too weak to use.
2) Some SSIDs don't work because of length? Punctuation? Spaces?
I'm going to try to play more and maybe open some issues on Github.
I can't speak much on the mesh topic because I only have the one circumstantial experience. What I can say is that it was an Orbi-based network and it only had one AP on it (no extenders, just the main AP). I suspect that the netmanager process is not doing its job either which could be the real underlying issue you're seeing:
2019-08-31 15:33:17 PDT I (289169) webserver: HTTP GET /shell
2019-08-31 15:33:22 PDT I (293779) webserver: HTTP POST /api/execute
2019-08-31 15:33:22 PDT D (293789) webcommand: HttpCommandStream[0x3fa2bf74] init: handler=0x3fa2aaa0 command='wifi scan' verbosity=65535
2019-08-31 15:33:22 PDT I (293799) webcommand: HttpCommandStream[0x3fa2bf74]: 2043632 bytes free, executing: wifi scan
2019-08-31 15:33:22 PDT I (293819) esp32wifi: Stopping WIFI station
2019-08-31 15:33:22 PDT D (293829) events: Signal(system.wifi.down)
2019-08-31 15:33:22 PDT I (293829) wifi: state: run -> init (0)
2019-08-31 15:33:22 PDT I (293839) netmanager: WIFI client down (with MODEM down): network connectivity has been lost
2019-08-31 15:33:22 PDT I (293849) wifi: pm stop, total sleep time: 235904304 us / 289492399 us
2019-08-31 15:33:22 PDT D (293879) events: Signal(network.wifi.down)
2019-08-31 15:33:22 PDT I (293879) wifi: n:6 0, o:6 0, ap:6 2, sta:6 0, prof:6
2019-08-31 15:33:22 PDT D (293899) events: Signal(network.down)
2019-08-31 15:33:22 PDT I (293919) wifi: flush txq
2019-08-31 15:33:22 PDT D (293909) websocket: WebSocket[0x3fa1f480] handler 0x3fa21c9c closed; 0 clients active
2019-08-31 15:33:22 PDT I (293929) wifi: stop sw txq
2019-08-31 15:33:22 PDT I (293949) ovms-server-v2: Status: Disconnected
2019-08-31 15:33:22 PDT I (293959) wifi: lmac stop hw txq
2019-08-31 15:33:22 PDT I (293919) time: Stopping SNTP client
2019-08-31 15:33:22 PDT I (293989) wifi: mode : sta (30:ae:a4:60:34:b8)
2019-08-31 15:33:22 PDT D (293999) events: Signal(network.interface.change)
2019-08-31 15:33:22 PDT D (294059) events: Signal(system.event)
2019-08-31 15:33:22 PDT D (294079) events: Signal(system.wifi.sta.disconnected)
2019-08-31 15:33:22 PDT D (294089) netmanager: send cmd 3 from 0x0
2019-08-31 15:33:22 PDT D (294099) netmanager: done cmd 3 from 0x0
2019-08-31 15:33:22 PDT I (294109) esp32wifi: STA disconnected with reason 8
2019-08-31 15:33:22 PDT D (294129) events: Signal(system.event)
2019-08-31 15:33:22 PDT D (294149) events: Signal(system.wifi.sta.stop)
2019-08-31 15:33:22 PDT D (294159) netmanager: send cmd 3 from 0x0
2019-08-31 15:33:22 PDT D (294169) netmanager: done cmd 3 from 0x0
2019-08-31 15:33:22 PDT D (294189) events: Signal(server.web.socket.closed)
2019-08-31 15:33:22 PDT D (294209) events: Signal(server.v2.waitreconnect)
2019-08-31 15:33:22 PDT D (294219) netmanager: MongooseTask: got cmd 3 from 0x0
2019-08-31 15:33:22 PDT W (294239) netmanager: CleanupConnections: can't get AP station list
2019-08-31 15:33:22 PDT D (294249) netmanager: MongooseTask: done cmd 3 from 0x0
2019-08-31 15:33:22 PDT D (294259) netmanager: MongooseTask: got cmd 3 from 0x0
2019-08-31 15:33:22 PDT W (294289) netmanager: CleanupConnections: can't get AP station list
2019-08-31 15:33:22 PDT D (294299) netmanager: MongooseTask: done cmd 3 from 0x0
2019-08-31 15:33:22 PDT D (294319) events: Signal(system.event)
2019-08-31 15:33:22 PDT D (294329) events: Signal(system.wifi.ap.stop)
2019-08-31 15:33:22 PDT I (294339) netmanager: WIFI access point is down
2019-08-31 15:33:22 PDT I (294349) esp32wifi: AP stopped
2019-08-31 15:33:22 PDT D (294379) events: Signal(system.event)
2019-08-31 15:33:22 PDT D (294399) events: Signal(system.wifi.sta.start)
2019-08-31 15:33:23 PDT D (294419) events: Signal(network.interface.change)
2019-08-31 15:33:23 PDT I (294539) ovms-server-v2: Status: Server is ready to start
2019-08-31 15:33:23 PDT D (294549) events: Signal(server.v2.waitnetwork)
2019-08-31 15:33:23 PDT D (294559) netmanager: MongooseTask stopping
2019-08-31 15:33:23 PDT D (294579) events: Signal(network.mgr.stop)
2019-08-31 15:33:23 PDT I (294599) webserver: Stopping Web Server
2019-08-31 15:33:23 PDT I (294619) ssh: Stopping SSH Server
2019-08-31 15:33:25 PDT D (296439) events: Signal(system.event)
2019-08-31 15:33:25 PDT D (296459) events: Signal(system.wifi.scan.done)
2019-08-31 15:33:25 PDT I (296519) esp32wifi: Stopping WIFI station
2019-08-31 15:33:25 PDT D (296529) events: Signal(system.wifi.down)
2019-08-31 15:33:25 PDT I (296539) wifi: flush txq
2019-08-31 15:33:25 PDT D (296549) events: Signal(system.event)
2019-08-31 15:33:25 PDT I (296559) wifi: stop sw txq
2019-08-31 15:33:25 PDT D (296589) events: Signal(system.wifi.sta.stop)
2019-08-31 15:33:25 PDT I (296609) wifi: lmac stop hw txq
2019-08-31 15:33:29 PDT I (300549) housekeeping: 2019-08-31 15:33:29 PDT (RAM: 8b=113788-143184 32b=22276)
2019-08-31 15:34:22 PDT I (353889) event: station ip lost
2019-08-31 15:34:22 PDT D (353899) events: Signal(system.event)
2019-08-31 15:35:09 PDT D (7558) events: Signal(server.v2.connecting)
2019-08-31 15:35:09 PDT I (7768) ovms-server-v2: Connection successful
2019-08-31 15:35:09 PDT I (7788) ovms-server-v2: Status: Logging in...
2019-08-31 15:35:09 PDT D (7798) events: Signal(server.v2.authenticating)
In the above logs, I had the OVMS module in AP+client mode. I initiated a wifi scan with the 'wifi scan' terminal command at 15:33. Upon initialization of the scan, the client disconnects and the AP is shut down. The scan finishes but the AP is not restarted and the client never reconnects. The messages starting at 15:35 occur when I power cycled the OVMS module to re-establish communication.
I guess my first question would be if it's necessary to shut down all of the network services to perform a scan. Secondly, even if it's necessary to shut everything down, it obviously is not the intended behavior that its previous state is not resumed once the scan is complete. I have tested several times and the client never reconnects on its own upon disconnection. The client is only capable of connecting to an AP upon initial OVMS boot. This is obviously not the desired behavior of the software.
I know it's easy for me to say since I'm not a programmer and I won't be the one whose time is spent doing the work, but my opinion is that the client mode feature should be prioritized as it's a much more secure way of operating compared to constantly running an AP and broadcasting its SSID. This mode of operation is just an invitation for curious types to probe the device. A big battery on wheels that can open garage doors is a very tempting target for people with bad intentions.
On your scan question: https://github.com/openvehicles/Open-Vehicle-Monitoring-System-3/issues/186
On prioritizing client mode: it's the user's choice which mode to use. All modes normally work. "client" mode in some cases operates more reliable than "apclient" mode so is currently the recommended option. I'm using "apclient" mode all the time without any issues. You also can automate which mode & networks to use depending on the location.
To (hopefully…) be able to analyze why client mode doesn't reconnect to your networks, we need more data, i.e. "module summary" & complete debug level logs of the disconnect/reconnect situations.
Please note that the edge release has the latest Espressif wifi driver. That may make a difference to your issues.
Some mesh networks seem to have DNS issues, so you might also try setting a fixed DNS.
Having the flexibility to choose which mode to run in is definitely a good thing. But I would respectfully suggest that many (maybe even most) users of this product are not fully informed when it comes to all of the security implications at play here.
As for the client connection issues, I've been tinkering around with some scripts and trying to gather more information. I am still awaiting the arrival of my modem module. As such, the only network connectivity that my module has currently is wifi. I suspect that is influencing the behavior I'm seeing. I've noticed that when the device has no network interfaces up, it seems to shut pretty much all of its network services down:
2019-09-01 08:27:25 PDT D (2096819) webcommand: HttpCommandStream[0x3fa219d0] init: handler=0x3fa26508 command='script run home' verbosity=65535
2019-09-01 08:27:25 PDT I (2096829) webcommand: HttpCommandStream[0x3fa219d0]: 2054304 bytes free, executing: script run home
2019-09-01 08:27:25 PDT I (2096839) esp32wifi: Stopping WIFI station
2019-09-01 08:27:25 PDT D (2096849) events: Signal(system.wifi.down)
2019-09-01 08:27:25 PDT I (2096849) wifi: state: run -> init (0)
2019-09-01 08:27:25 PDT I (2096859) netmanager: WIFI client down (with MODEM down): network connectivity has been lost
2019-09-01 08:27:25 PDT I (2096869) wifi: pm stop, total sleep time: 1759188636 us / 2093887151 us
2019-09-01 08:27:25 PDT I (2096899) wifi: n:6 0, o:6 0, ap:255 255, sta:6 0, prof:1
2019-09-01 08:27:25 PDT D (2096899) events: Signal(network.wifi.down)
2019-09-01 08:27:25 PDT I (2096919) wifi: flush txq
2019-09-01 08:27:25 PDT D (2096919) netmanager: MongooseTask stopping
2019-09-01 08:27:25 PDT I (2096929) wifi: stop sw txq
2019-09-01 08:27:25 PDT D (2096959) websocket: WebSocket[0x3fa27aa0] handler 0x3fa2701c closed; 0 clients active
2019-09-01 08:27:25 PDT I (2096989) wifi: lmac stop hw txq
2019-09-01 08:27:25 PDT I (2097009) ovms-server-v2: Status: Disconnected
2019-09-01 08:27:25 PDT D (2096939) events: Signal(network.down)
2019-09-01 08:27:25 PDT I (2097039) time: Stopping SNTP client
2019-09-01 08:27:25 PDT D (2097059) events: Signal(network.interface.change)
2019-09-01 08:27:25 PDT D (2097069) events: Signal(network.mgr.stop)
2019-09-01 08:27:25 PDT I (2097099) webserver: Stopping Web Server
2019-09-01 08:27:25 PDT I (2097099) ssh: Stopping SSH Server
2019-09-01 08:27:25 PDT D (2097119) events: Signal(server.web.socket.closed)
2019-09-01 08:27:25 PDT D (2097139) events: Signal(system.event)
2019-09-01 08:27:25 PDT D (2097159) events: Signal(system.wifi.sta.disconnected)
2019-09-01 08:27:25 PDT I (2097169) esp32wifi: STA disconnected with reason 8
2019-09-01 08:27:25 PDT D (2097179) events: Signal(system.event)
2019-09-01 08:27:25 PDT D (2097219) events: Signal(system.wifi.sta.stop)
2019-09-01 08:27:25 PDT D (2097249) events: Signal(server.v2.waitreconnect)
2019-09-01 08:27:25 PDT I (2097539) ovms-server-v2: Status: Server is ready to start
2019-09-01 08:27:25 PDT D (2097549) events: Signal(server.v2.waitnetwork)
2019-09-01 08:27:28 PDT D (2100539) v-teslaroadster: CTP(0,5880,152,191,100,135.67,35)=144.8 minutes
2019-09-01 08:27:28 PDT I (2100559) housekeeping: 2019-09-01 08:27:28 PDT (RAM: 8b=113788-144664 32b=22276)
2019-09-01 08:28:23 PDT I (2155269) event: station ip lost
2019-09-01 08:28:23 PDT D (2155279) events: Signal(system.event)
2019-09-01 08:28:28 PDT D (2160539) v-teslaroadster: CTP(0,5856,152,191,100,135.67,35)=145.4 minutes
2019-09-01 08:29:28 PDT D (2220539) v-teslaroadster: CTP(0,5856,152,191,100,135.67,35)=145.4 minutes
2019-09-01 08:30:28 PDT D (2280539) v-teslaroadster: CTP(0,5880,153,191,100,135.67,35)=141.1 minutes
2019-09-01 08:31:28 PDT D (2340539) v-teslaroadster: CTP(0,5856,153,191,100,135.67,36)=142.5 minutes
2019-09-01 08:32:28 PDT D (2400539) v-teslaroadster: CTP(0,5880,153,191,100,135.67,37)=142.6 minutes
2019-09-01 08:32:28 PDT I (2400559) housekeeping: 2019-09-01 08:32:28 PDT (RAM: 8b=113788-144612 32b=22276)
2019-09-01 08:33:28 PDT D (2460539) v-teslaroadster: CTP(0,5856,154,191,100,135.67,36)=138.7 minutes
2019-09-01 08:34:28 PDT D (2520539) v-teslaroadster: CTP(0,5880,154,191,100,135.67,35)=137.4 minutes
2019-09-01 08:35:28 PDT D (2580539) v-teslaroadster: CTP(0,5856,154,191,100,135.67,35)=138.0 minutes
2019-09-01 08:36:28 PDT D (2640539) v-teslaroadster: CTP(0,5832,155,191,100,135.67,35)=134.9 minutes
2019-09-01 08:37:28 PDT D (2700539) v-teslaroadster: CTP(0,5880,155,191,100,135.67,35)=133.7 minutes
2019-09-01 08:37:28 PDT I (2700569) housekeeping: 2019-09-01 08:37:28 PDT (RAM: 8b=113788-144612 32b=22276)
The above is output from a simple script that just does a 'wifi mode off', sleeps for 90 seconds, then does a 'wifi mode client <ssid>'. In the above output, there's no indication that it ever reconnected or that it ever even tried to reconnect. The message that come afterward in the log are from me rebooting the device via power cycle to restore connectivity so I omitted them.
It doesn't seem like it should be necessary to stop services like SSH and httpd just because there is no external network connection. I get why you'd want to stop the ovms server since it would have to buffer its messages somewhere until connectivity is restored and you don't want to exhaust the module's storage and RAM in the event that connectivity isn't restored in a timely fashion. However, the same concern doesn't exist with services like ssh and httpd since they assumably would be idle in such a situation and won't store anything. Those services should also be able to run as long as the module's loopback interface is up which should be unaffected by ups/downs of other interfaces.
Is it possible that in the above described situation, 'wifi mode client <ssid>' is actually connecting to the ssid, but since many services are being stopped, the network manager/mongoose service is no longer running to start the dhcp client?
More logs:
Me leaving the house:
2019-09-01 20:12:20 PDT D (216540) events: Signal(vehicle.headlights.on)
2019-09-01 20:13:44 PDT I (300550) housekeeping: 2019-09-01 20:13:44 PDT (RAM: 8b=113788-133648 32b=22276)
2019-09-01 20:14:03 PDT D (318920) events: Signal(location.enter.home)
2019-09-01 20:14:03 PDT I (318940) script: Running script /store/events/location.enter.home/runhome.js
2019-09-01 20:14:14 PDT I (329700) esp32wifi: Stopping WIFI station
2019-09-01 20:14:14 PDT I (329710) wifi: state: run -> init (0)
2019-09-01 20:14:14 PDT I (329720) wifi: pm stop, total sleep time: 291643202 us / 325868999 us
2019-09-01 20:14:14 PDT I (329730) wifi: n:6 0, o:6 0, ap:255 255, sta:6 0, prof:1
2019-09-01 20:14:14 PDT I (329750) ovms-server-v2: Status: Disconnected
2019-09-01 20:14:14 PDT I (329760) wifi: flush txq
2019-09-01 20:14:14 PDT I (329770) wifi: stop sw txq
2019-09-01 20:14:14 PDT I (329780) wifi: lmac stop hw txq
2019-09-01 20:14:15 PDT E (331540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:16 PDT E (332540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:17 PDT E (333540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:18 PDT E (334540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:19 PDT E (335160) events: SignalEvent: queue overflow, event 'location.leave.home' dropped
2019-09-01 20:14:19 PDT E (335540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:20 PDT E (336540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:21 PDT E (337540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:22 PDT E (338540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:23 PDT E (339540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:24 PDT E (340540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:24 PDT E (340550) events: SignalEvent: queue overflow, event 'ticker.10' dropped
2019-09-01 20:14:25 PDT I (340710) wifi: mode : sta (30:ae:a4:60:34:b8)
2019-09-01 20:14:25 PDT E (340740) events: SignalEvent: queue overflow, event 'system.event' dropped
2019-09-01 20:14:25 PDT E (340760) events: SignalEvent: queue overflow, event 'system.wifi.sta.start' dropped
2019-09-01 20:14:25 PDT E (341540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:26 PDT E (342540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:27 PDT E (343160) events: SignalEvent: queue overflow, event 'system.event' dropped
2019-09-01 20:14:27 PDT E (343200) events: SignalEvent: queue overflow, event 'system.wifi.sta.disconnected' d$
2019-09-01 20:14:27 PDT E (343540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:28 PDT E (344540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:29 PDT E (345540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:30 PDT E (346540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:31 PDT E (347540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:14:32 PDT E (348540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
SignalEvent messages appear to continue until housekeeper does its thing:
2019-09-01 20:16:01 PDT E (437540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:16:02 PDT EE (438540) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 20:16:10 PDT I (10544) housekeeping: System considered stable (RAM: 8b=113788-146428 32b=22276)
2019-09-01 20:16:10 PDT D (10574) notify: Created entry type 'data' subtype 'debug.crash' size 186 has 1 readers pending
2019-09-01 20:16:12 PDT D (12544) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 20:16:12 PDT D (13004) events: Signal(system.event)
2019-09-01 20:16:12 PDT D (13034) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:16:13 PDT D (13544) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 20:16:14 PDT D (14544) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 20:16:15 PDT D (15544) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 20:16:15 PDT I (15564) simcom: State timeout, transition to 13
2019-09-01 20:16:15 PDT I (15584) simcom: State: Enter PoweredOff state
2019-09-01 20:16:15 PDT I (15604) gsm-mux: Stop MUX
2019-09-01 20:16:15 PDT D (15634) events: Signal(system.modem.poweredoff)
2019-09-01 20:17:02 PDT D (62954) events: Signal(system.event)
2019-09-01 20:17:02 PDT D (62994) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:17:12 PDT D (72954) events: Signal(system.event)
2019-09-01 20:17:12 PDT D (72984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:17:22 PDT D (82954) events: Signal(system.event)
2019-09-01 20:17:22 PDT D (82984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:17:32 PDT D (92954) events: Signal(system.event)
2019-09-01 20:17:32 PDT D (92984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:17:42 PDT D (102954) events: Signal(system.event)
2019-09-01 20:17:42 PDT D (102994) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:17:52 PDT D (112954) events: Signal(system.event)
2019-09-01 20:17:52 PDT D (112984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:18:02 PDT D (122954) events: Signal(system.event)
2019-09-01 20:18:02 PDT D (122984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:18:12 PDT D (132954) events: Signal(system.event)
2019-09-01 20:18:12 PDT D (133004) events: Signal(system.wifi.sta.disconnected)
(these messages continue until I get back into the car and hit the geofence)
Get back into the car and drive home:
2019-09-01 20:57:23 PDT D (2482814) events: Signal(vehicle.unlocked)
2019-09-01 20:57:23 PDT D (2482944) events: Signal(system.event)
2019-09-01 20:57:23 PDT D (2482974) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:57:33 PDT D (2492954) events: Signal(system.event)
2019-09-01 20:57:33 PDT D (2492984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:57:43 PDT D (2502954) events: Signal(system.event)
2019-09-01 20:57:43 PDT D (2502984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:57:53 PDT D (2512954) events: Signal(system.event)
2019-09-01 20:57:53 PDT D (2512984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:58:03 PDT D (2522954) events: Signal(system.event)
2019-09-01 20:58:03 PDT D (2522994) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:58:13 PDT D (2532954) events: Signal(system.event)
2019-09-01 20:58:13 PDT D (2532984) events: Signal(system.wifi.sta.disconnected)
2019-09-01 20:58:20 PDT D (2539994) events: Signal(vehicle.on)
2019-09-01 20:58:22 PDT D (2541994) events: Signal(vehicle.headlights.on)
Hit geofence and my runhome.js script is triggered but a problem is encountered. However, wifi does appear to still be able to connect:
2019-09-01 21:08:33 PDT D (3152994) events: Signal(system.wifi.sta.disconnected)
2019-09-01 21:08:37 PDT D (3156854) events: Signal(location.enter.home)
2019-09-01 21:08:37 PDT I (3156884) script: Running script /store/events/location.enter.home/runhome.js
2019-09-01 21:08:48 PDT I (3167634) esp32wifi: Stopping WIFI station
2019-09-01 21:08:48 PDT I (3167654) wifi: flush txq
2019-09-01 21:08:48 PDT I (3167674) wifi: stop sw txq
2019-09-01 21:08:48 PDT I (3167704) wifi: lmac stop hw txq
2019-09-01 21:08:50 PDT E (3170544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:50 PDT E (3170564) events: SignalEvent: queue overflow, event 'ticker.10' dropped
2019-09-01 21:08:51 PDT E (3171544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:52 PDT E (3172544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:53 PDT DE (317354) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:54 PDT E (3174544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:55 PDT E (3175544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:56 PDT E (3176544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:57 PDT E (3177544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:58 PDT E (3178544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:08:59 PDT I (3178644) wifi: mode : sta (30:ae:a4:60:34:b8)
2019-09-01 21:08:59 PDT E (3178674) events: SignalEvent: queue overflow, event 'system.event' dropped
2019-09-01 21:08:59 PDT E (3178694) events: SignalEvent: queue overflow, event 'system.wifi.sta.start' dropped
2019-09-01 21:08:59 PDT E (3179544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:09:00 PDT E (3180544) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:09:00 PDT E (3180574) events: SignalEvent: queue overflow, event 'ticker.10' dropped
2019-09-01 21:09:00 PDT E (3180624) events: SignalEvent: queue overflow, event 'ticker.60' dropped
2019-09-01 21:09:01 PDT I (3181094) wifi: n:6 0, o:1 0, ap:255 255, sta:6 0, prof:1
2019-09-01 21:09:02 PDT I (3181794) wifi: state: init -> auth (b0)
2019-09-01 21:09:02 PDT E (3181804) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:09:02 PDT I (3181824) wifi: state: auth -> assoc (0)
2019-09-01 21:09:02 PDT E (3181804) events: SignalEvent: queue overflow, event 'ticker.1' dropped
2019-09-01 21:09:02 PDT I (3181824) wifi: state: auth -> assoc (0)
2019-09-01 21:20:22 PDT EI (10539) housekeeping: System considered stable (RAM: 8b=113788-134052 32b=22276)
2019-09-01 21:20:24 PDT D (12539) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 21:20:25 PDT D (13539) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 21:20:26 PDT D (14539) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 21:20:27 PDT D (15539) simcom: tx scmd ch=0 len=4 : AT
2019-09-01 21:20:27 PDT EI (15559) simcom: State timeout, transition to 13
2019-09-01 21:20:27 PDT I (15589) simcom: State: Enter PoweredOff state
2019-09-01 21:20:27 PDT I (15609) gsm-mux: Stop MUX
2019-09-01 21:20:27 PDT D (15639) events: Signal(system.modem.poweredoff)
2019-09-01 21:20:41 PDT I (28749) ovms-server-v2: Incoming Msg: MP-0 Z1
2019-09-01 21:20:41 PDT I (28769) ovms-server-v2: One or more peers have connected
2019-09-01 21:20:41 PDT D (28799) events: Signal(app.connected)
2019-09-01 21:20:41 PDT I (28799) ovms-server-v2: Incoming Msg: MP-0 Z2
2019-09-01 21:20:41 PDT I (28849) ovms-server-v2: One or more peers have connected
2019-09-01 21:20:41 PDT ID (28869) events: Signal(app.connected)
2019-09-01 21:20:41 PDT I (29359) ovms-server-v2: Incoming Msg: MP-0 Z1
2019-09-01 21:20:41 PDT D (29389) events: Signal(app.connected)
2019-09-01 21:20:41 PDT I (29539) ovms-server-v2: Send MP-0 S86.0,M,0,0,stopped,standard,142,123,24,0,0,0,2,21....
Notice the gap between 21:09 and 21:20. I believe the messages at 21:20 are from me power cycling the module once I was unable to communicate with it after being home for more than 10 minutes.
To me, it appears that the wifi chipset is able to (or at least attempts to) associate with the AP, but it still has no network connectivity. There's never any indication that netmanager/mongoose ever attempts to configure the interface. Could be related to the event queue overflowing.
What's visible here are crash reboots triggered by your script. That would for example happen if you used "test sleep" in the script.
You don't need to shut down wifi to reconfigure for another SSID. Simply call "wifi mode client <newssid>".
You can't run a script from the web shell that shuts down the network, as the script will lose the output channel and get terminated. So your script never got to the wifi start command.
If you need to change the network, do it from an event script.
Also I'd like to see your script, specifically the "sleep for 90 seconds" part. If you use "test sleep", that won't work as you expect, that's a test call for deep sleep power state.
Regarding your assumptions about the network stack of the module, I suggest forking the code and implementing your ideas. Actual help is always appreciated.
@egoebelbecker:
There is no need to "enable" in a web shell, as that's always in "enabled" mode. But you can't use "wifi scan" from there, as that will disrupt the wifi mode (see issue).
The current edge release will tell you the AP MAC last/currently connected to. It also contains a fix to the signal strength detection.
There is currently no specific mesh support in the wifi client, so it may not roam to a better station but stick to the first found. It should connect to the AP with the best signal if you restart the wifi mode.
I had the same problem, wifi client not connecting fully - ie. you get the SSID but IP always shows 0.0.0.0 . So I did a bit of testing.
Read some thread that this would be a problem of the chipset, ie. not OVMS specific, so it might be hard to fix before v4 hardware.
None of the three different APs I had at home worked, but they we're all old, 5-10 years of age.
The share (mobile AP) on my Samsung S7 worked though, so I got going. It even worked when I enabled 'wifi sharing' so that I was sharing the net from any one of these three non-working APs through my phone to the OVMS.
I also tested a newer TP-Link mesh AP at another house, and it worked perfectly out of the box.
So my suggestion is that since the wlan chipset on the OVMS seems to be picky, you might need to replace your WLAN router with a brand new model in order to get it working.
No guarantees though which models will work, it would be good to compile a list of tested models based on experience (and maybe bad ones so we know which to avoid - but it seems that all of the old boxes won't work). :(
There are no known cases of router incompatibilty. If you read some thread about such, please provide a link.
Please first check if your networks don't have any security restrictions activated, e.g. to only allow known MACs.
Then provide a wifi scan result + details about your routers and network configurations + debug logs of the module attempting to connect.
You might also try connecting in fixed IP mode instead of DHCP:
Regards,
Michael
I get the error " esp32wifi: STA disconnected with reason 15 = 4WAY_HANDSHAKE_TIMEOUT " with my three different old wifi routers, and the IP is 0.0.0.0 .
I've tried with and without WPA2 and even WEP. The same results.
A newer TP-Link mesh router at another house works perfectly.
I'll have to try static IP.
The static IP doesn't help. There's IP all right, but no traffic is going through.