[Ovmsdev] v3 hardware disconnecting from v2 server

Tue Mar 6 17:51:34 HKT 2018

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

-------------- next part --------------
A non-text attachment was scrubbed...
Name: ovms_2018-03-05T05_40_29+0000.log.bz2
Type: application/x-bzip
Size: 40621 bytes
Desc: not available
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20180306/2922a085/attachment-0004.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ovms_2018-03-04T19_43_10+0000.log.bz2
Type: application/x-bzip
Size: 85990 bytes
Desc: not available
URL: <http://lists.openvehicles.com/pipermail/ovmsdev/attachments/20180306/2922a085/attachment-0005.bin>