<html><head><meta http-equiv="Content-Type" content="text/html charset=utf-8"></head><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" class="">I reviewed all the states, and implemented some new timeout checks as appropriate. I also made the mux timeout work in ALL states. This should address these issues that I and Tom have seen. There may be others, but the state ones should be ok now.<div class=""><br class=""></div><div class="">I’ll try it in my car tomorrow.</div><div class=""><br class=""></div><div class="">Regards, Mark<div class=""><br class=""><div><blockquote type="cite" class=""><div class="">On 13 Mar 2018, at 10:04 AM, Mark Webb-Johnson <<a href="mailto:mark@webb-johnson.net" class="">mark@webb-johnson.net</a>> wrote:</div><br class="Apple-interchange-newline"><div class=""><meta http-equiv="Content-Type" content="text/html; charset=utf-8" class=""><div style="word-wrap: break-word; -webkit-nbsp-mode: space; line-break: after-white-space;" class="">Tom,<div class=""><br class=""></div><div class="">I reviewed, and found a couple of states where we were not handling timeout conditions. Specifically:</div><div class=""><br class=""></div><div class=""><ul class="MailOutline"><li class="">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.</li><li class="">NetMode: If mux went down while in established network connection mode, it wouldn’t check. Blocked in that state until power cycle.</li><li class="">MuxStart: If the mux doesn’t come up properly (4 channels established), it would block in this state until power cycle.</li></ul><div class=""><br class=""></div><div class="">I think your issue was the NetMode one. I’ve personally seen the NetWait one in my car.</div><div class=""><br class=""></div><div class="">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).</div><div class=""><br class=""></div><div class="">Regards, Mark</div><div class=""><br class=""><blockquote type="cite" class=""><div class="">On 6 Mar 2018, at 5:51 PM, Tom Parker <<a href="mailto:tom@carrott.org" class="">tom@carrott.org</a>> wrote:</div><br class="Apple-interchange-newline"><div class=""><div class="">I had some time to put the data logger in my car and examine the results.<br class=""><br class="">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.<br class=""><br class="">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.<br class=""><br class="">The server logs for this one indicate that<br class=""><br class="">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,<br class="">2degrees<br class=""><br class="">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.<br class=""><br class="">Server Logs, note 8 minute gap (I was driving so waited to reboot it)<br class=""><br class="">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'<br class="">2018-03-04 21:17:29,61640,'#15 A rx msg A '<br class="">2018-03-04 21:22:33,62318,'#15 A rx msg A '<br class="">2018-03-04 21:23:37,62442,'#9 C got login'<br class="">2018-03-04 21:23:37,62443,'#74 C error - duplicate car login - clearing first connection'<br class="">2018-03-04 21:23:50,62467,'#9 C error - Unable to decode message - aborting connection'<br class="">2018-03-04 21:24:12,62523,'#66 C got login'<br class="">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'<br class=""><br class="">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).<br class=""><br class="">OVMS > V (35194199) simcom: tx: f9 0d ff 3b 41 54 2b 43 52 45 47 3f 3b 2b 43 43 | ...;AT+CREG?;+CC<br class="">V (35194199) simcom: tx: 4c 4b 3f 3b 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d | LK?;+CSQ;+COPS?.<br class="">V (35194199) simcom: tx: 0a cf f9                                        | ...<br class="">V (35194219) simcom: rx: 41 54 2b 43 52 45 47 3f 3b 2b 43 43 4c 4b 3f 3b | AT+CREG?;+CCLK?;<br class="">V (35194219) simcom: rx: 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d             | +CSQ;+COPS?.<br class="">V (35194279) simcom: rx: 0d 0a 2b 43 52 45 47 3a 20 30 2c 31 0d 0a 0d 0a | ..+CREG: 0,1....<br class="">V (35194279) simcom: rx: 2b 43 43 4c 4b 3a 20 22 31 38 2f 30 33 2f 30 35 | +CCLK: "18/03/05<br class="">V (35194279) simcom: rx: 2c 31 39 3a 30 39 3a 30 35 2b 35 32 22 0d 0a 0d | ,19:09:05+52"...<br class="">V (35194279) simcom: rx: 0a 2b 43 53 51 3a 20 33 2c 39 39 0d 0a 0d 0a 2b | .+CSQ: 3,99....+<br class="">V (35194279) simcom: rx: 43 4f 50 53 3a 20 30 2c 30 2c 22 32 64 65 67 72 | COPS: 0,0,"2degr<br class="">V (35194279) simcom: rx: 65 65 73 22 2c 32 0d 0a 0d 0a 4f 4b 0d 0a       | ees",2....OK..<br class="">OVMS > V (35224199) simcom: tx: f9 0d ff 3b 41 54 2b 43 52 45 47 3f 3b 2b 43 43 | ...;AT+CREG?;+CC<br class="">V (35224199) simcom: tx: 4c 4b 3f 3b 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d | LK?;+CSQ;+COPS?.<br class="">V (35224199) simcom: tx: 0a cf f9                                        | ...<br class="">V (35224209) simcom: rx: 41 54 2b 43 52 45 47 3f 3b 2b 43 43 4c 4b 3f 3b | AT+CREG?;+CCLK?;<br class="">V (35224219) simcom: rx: 2b 43 53 51 3b 2b 43 4f 50 53 3f 0d 0d 0a 2b 43 | +CSQ;+COPS?...+C<br class="">V (35224219) simcom: rx: 52 45 47 3a 20 30 2c 31 0d 0a 0d 0a 2b 43 43 4c | REG: 0,1....+CCL<br class="">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:<br class="">V (35224219) simcom: rx: 30 39 3a 33 35 2b 35 32 22 0d 0a 0d 0a 2b 43 53 | 09:35+52"....+CS<br class="">V (35224219) simcom: rx: 51 3a 20 33 2c 39 39 0d 0a 0d 0a 2b 43 4f 50 53 | Q: 3,99....+COPS<br class="">V (35224219) simcom: rx: 3a 20 30 2c 30 2c 22 32 64 65 67 72 65 65 73 22 | : 0,0,"2degrees"<br class="">V (35224219) simcom: rx: 2c 32 0d 0a 0d 0a 4f 4b 0d 0a                   | ,2....OK..<br class="">OVMS > a simcom status<br class="">SIMCOM<br class="">  Network Registration: RegisteredHome<br class="">  State: NetMode<br class="">  Ticker: 1235<br class="">  User Data: 0<br class=""><br class="">  Mux<br class="">    Status: up<br class="">    Open Channels: 4<br class="">    Framing Errors: 5103<br class="">    Last RX frame: 1222 sec(s) ago<br class="">    RX frames: 2512<br class="">    TX frames: 2500<br class=""><br class="">  PPP<br class="">    Not Connected<br class="">    Last Error: Connection Lost<br class=""><br class="">  GPS<br class="">    Status: disabled<br class="">    Time: disabled<br class="">    NMEA: GPS/GLONASS Not Connected<br class="">OVMS > simcom      power simcom off<br class="">ets Jun  8 2016 00:22:57<br class=""><br class="">rst:0x1 (POWERON_RESET),boot:0x1f (SPI_FAST_FLASH_BOOT)<br class="">configsip: 156795334, SPIWP:0xee<br class="">clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00<br class=""><br class=""><span id="cid:95DCA471-E71D-4BD5-A845-4974278EA113" class=""><ovms_2018-03-05T05_40_29+0000.log.bz2></span><span id="cid:4865EE8B-8F20-420B-B707-3779CB1E1309" class=""><ovms_2018-03-04T19_43_10+0000.log.bz2></span>_______________________________________________<br class="">OvmsDev mailing list<br class=""><a href="mailto:OvmsDev@lists.teslaclub.hk" class="">OvmsDev@lists.teslaclub.hk</a><br class=""><a href="http://lists.teslaclub.hk/mailman/listinfo/ovmsdev" class="">http://lists.teslaclub.hk/mailman/listinfo/ovmsdev</a><br class=""></div></div></blockquote></div><br class=""></div></div></div></blockquote></div><br class=""></div></div></body></html>