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