[Ovmsdev] v3 hardware disconnecting from v2 server

Mark Webb-Johnson mark at webb-johnson.net
Tue Mar 13 10:04:42 HKT 2018


Tom,

I reviewed, and found a couple of states where we were not handling timeout conditions. Specifically:

NetWait: If waiting for GSM signal, and the mux went down, the indication that GSM is back would never come. Blocked in that state until power cycle.
NetMode: If mux went down while in established network connection mode, it wouldn’t check. Blocked in that state until power cycle.
MuxStart: If the mux doesn’t come up properly (4 channels established), it would block in this state until power cycle.

I think your issue was the NetMode one. I’ve personally seen the NetWait one in my car.

I’ve fixed those three, and committed that. This has been running 24x7 in my car for the past few days, and I’m fixing these as and when I find them. I’ll try to make some time to look at the state checks with a critical eye and try to ensure we have sensible timeouts on all of them (pro-actively). I’m wondering if the mux checking can be taken out generically to always reset if mux fails (no matter the state).

Regards, Mark

> On 6 Mar 2018, at 5:51 PM, Tom Parker <tom at carrott.org> wrote:
> 
> I had some time to put the data logger in my car and examine the results.
> 
> It turns out I spoke too soon when I said that the framing errors had gone away. I've seen this pattern of disconnection several times now with the large number of framing errors and the long time since the last RX frame in the Mux statistics. I'm not really sure what is salient in the log leading up to the disconnection, please see attached for a couple of examples.
> 
> The ovms_2018-03-04T19_43_10+0000.log is particularly interesting because the gsm-ppp and server-v2 processes are still working, but no data is being sent and the normal gsm-mux chatter is missing.
> 
> The server logs for this one indicate that
> 
> I (2085209) ovms-server-v2: Send MP-0 F3.0.990-30-g613bfd2/factory/main build (idf v3.1-dev-453-g0f978bc) Mar  2 2018 06:35:40,,5,1,NL,
> 2degrees
> 
> was the last message received. I stopped the data logger before rebooting the ovms, so there's no record of the reconnection from the ovms module's point of view.
> 
> Server Logs, note 8 minute gap (I was driving so waited to reboot it)
> 
> 2018-03-04 21:16:05,61446,'#74 C rx msg F 3.0.990-30-g613bfd2/factory/main build (idf v3.1-dev-453-g0f978bc) Mar  2 2018 06:35:40,,5,1,NL,2degrees'
> 2018-03-04 21:17:29,61640,'#15 A rx msg A '
> 2018-03-04 21:22:33,62318,'#15 A rx msg A '
> 2018-03-04 21:23:37,62442,'#9 C got login'
> 2018-03-04 21:23:37,62443,'#74 C error - duplicate car login - clearing first connection'
> 2018-03-04 21:23:50,62467,'#9 C error - Unable to decode message - aborting connection'
> 2018-03-04 21:24:12,62523,'#66 C got login'
> 2018-03-04 21:24:40,62597,'#66 C rx msg S 74,K,0,0,stopped,standard,62,0,0,0,0,0,13,21,0,0,0,0,0.00,0,0,0,0,-1,0,0,0,0,0,0,0,0.00,384.50,0'
> 
> This is an extract from ovms_2018-03-05T05_40_29+0000.log.bz2 where the disconnection seems like it was detected and we're left with the modem status queries in a loop. When I tried to power off the simcom modem, the ovms locked up and wouldn't respond to the serial console. I rebooted the modem with the button and it immediately reconnected (not shown but it's in the attached log).
> 
> OVMS > V (35194199) simcom: tx: f9 0d ff 3b 41 54 2b 43 52 45 47 3f 3b 2b 43 43 | ...;AT+CREG?;+CC
> V (35194199) simcom: tx: 4c 4b 3f 3b 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d | LK?;+CSQ;+COPS?.
> V (35194199) simcom: tx: 0a cf f9                                        | ...
> V (35194219) simcom: rx: 41 54 2b 43 52 45 47 3f 3b 2b 43 43 4c 4b 3f 3b | AT+CREG?;+CCLK?;
> V (35194219) simcom: rx: 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d             | +CSQ;+COPS?.
> V (35194279) simcom: rx: 0d 0a 2b 43 52 45 47 3a 20 30 2c 31 0d 0a 0d 0a | ..+CREG: 0,1....
> V (35194279) simcom: rx: 2b 43 43 4c 4b 3a 20 22 31 38 2f 30 33 2f 30 35 | +CCLK: "18/03/05
> V (35194279) simcom: rx: 2c 31 39 3a 30 39 3a 30 35 2b 35 32 22 0d 0a 0d | ,19:09:05+52"...
> V (35194279) simcom: rx: 0a 2b 43 53 51 3a 20 33 2c 39 39 0d 0a 0d 0a 2b | .+CSQ: 3,99....+
> V (35194279) simcom: rx: 43 4f 50 53 3a 20 30 2c 30 2c 22 32 64 65 67 72 | COPS: 0,0,"2degr
> V (35194279) simcom: rx: 65 65 73 22 2c 32 0d 0a 0d 0a 4f 4b 0d 0a       | ees",2....OK..
> OVMS > V (35224199) simcom: tx: f9 0d ff 3b 41 54 2b 43 52 45 47 3f 3b 2b 43 43 | ...;AT+CREG?;+CC
> V (35224199) simcom: tx: 4c 4b 3f 3b 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d | LK?;+CSQ;+COPS?.
> V (35224199) simcom: tx: 0a cf f9                                        | ...
> V (35224209) simcom: rx: 41 54 2b 43 52 45 47 3f 3b 2b 43 43 4c 4b 3f 3b | AT+CREG?;+CCLK?;
> V (35224219) simcom: rx: 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d 0d 0a 2b 43 | +CSQ;+COPS?...+C
> V (35224219) simcom: rx: 52 45 47 3a 20 30 2c 31 0d 0a 0d 0a 2b 43 43 4c | REG: 0,1....+CCL
> V (35224219) simcom: rx: 4b 3a 20 22 31 38 2f 30 33 2f 30 35 2c 31 39 3a | K: "18/03/05,19:
> V (35224219) simcom: rx: 30 39 3a 33 35 2b 35 32 22 0d 0a 0d 0a 2b 43 53 | 09:35+52"....+CS
> V (35224219) simcom: rx: 51 3a 20 33 2c 39 39 0d 0a 0d 0a 2b 43 4f 50 53 | Q: 3,99....+COPS
> V (35224219) simcom: rx: 3a 20 30 2c 30 2c 22 32 64 65 67 72 65 65 73 22 | : 0,0,"2degrees"
> V (35224219) simcom: rx: 2c 32 0d 0a 0d 0a 4f 4b 0d 0a                   | ,2....OK..
> OVMS > a simcom status
> SIMCOM
>   Network Registration: RegisteredHome
>   State: NetMode
>   Ticker: 1235
>   User Data: 0
> 
>   Mux
>     Status: up
>     Open Channels: 4
>     Framing Errors: 5103
>     Last RX frame: 1222 sec(s) ago
>     RX frames: 2512
>     TX frames: 2500
> 
>   PPP
>     Not Connected
>     Last Error: Connection Lost
> 
>   GPS
>     Status: disabled
>     Time: disabled
>     NMEA: GPS/GLONASS Not Connected
> OVMS > simcom      power simcom off
> ets Jun  8 2016 00:22:57
> 
> rst:0x1 (POWERON_RESET),boot:0x1f (SPI_FAST_FLASH_BOOT)
> configsip: 156795334, SPIWP:0xee
> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
> 
> <ovms_2018-03-05T05_40_29+0000.log.bz2><ovms_2018-03-04T19_43_10+0000.log.bz2>_______________________________________________
> OvmsDev mailing list
> OvmsDev at lists.teslaclub.hk
> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.teslaclub.hk/pipermail/ovmsdev/attachments/20180313/28a94bcd/attachment-0001.html>


More information about the OvmsDev mailing list