Tom,

This (and the subsequent work to do this globally, irrespective of the state) seems to be working well in my car for the past couple of days.

How is it working out for you? Are you still getting cases where the SIMCOM loses connectivity and it can’t recover?

Regards, Mark.

On 13 Mar 2018, at 10:04 AM, Mark Webb-Johnson <mark@webb-johnson.net> wrote:

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@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@lists.teslaclub.hk
http://lists.teslaclub.hk/mailman/listinfo/ovmsdev