On 04/02/18 15:33, Tom Parker wrote:
I haven't yet had a chance to reproduce the original disconnection problem and see if stopping and starting the v2 server connection helps.
It does not help. I've seen a stack overflow during server v2 stop, but the backtrace didn't make any sense so I think I might have run addr2line on the wrong binary. I've also seen the server v2 stop work. Below we see the server v2 sending messages to the server which are not being received. I restarted the server v2 and then it noticed that it could not connect. Then I tried restarting the simcom and that didn't restore network connectivity. Only when I reset it with the button did it reconnect. I've tried this simcom power cycle to restore connectivity several times and it's never worked once it's in this bad state. It feels like the simcom state machine has a bug where it thinks that it is connected but actually it isn't, so it never reconnects. This bug appears to persist over simcom power cycles. I've now got verbose logging turned on and I've removed modemmanager on my data logging laptop so hopefully I'll have some more information about the cause. I (3929403) ovms-server-v2: Send MP-0 F3.0.0/factory/main build (idf v3.1-dev-217-g5bf85d0) Feb 4 2018 02:36:19,,2,1,NL,2degrees OVMS > I (3961393) ovms-server-v2: Send MP-0 S35,K,0,0,stopped,standard,29,0,0,0,0,0,13,21,0,0,0,0,62.23,0,0,0,0,-1,0,0,0,0,0,0,0,0.00,373.00,94 OVMS > I (3990393) ovms-server-v2: Send MP-0 S35,K,0,0,stopped,standard,29,0,0,0,0,0,13,21,0,0,0,0,62.23,0,0,0,0,-1,0,0,0,0,0,0,0,0.00,371.00,94 I (3990393) ovms-server-v2: Send MP-0 D128,0,5,0,0,27,0,0,49,3990,22,1,1,1,13.0385,0,0,128,0,0 I (3990403) ovms-server-v2: Send MP-0 L0,0,0,0,0,0,49,0,0,0,0 OVMS > I (4051393) ovms-server-v2: Send MP-0 S34,K,0,0,stopped,standard,29,0,0,0,0,0,13,21,0,0,0,0,62.23,0,0,0,0,-1,0,0,0,0,0,0,0,0.00,370.00,94 I (4051393) ovms-server-v2: Send MP-0 D128,0,5,0,0,27,0,0,17,4051,22,1,1,1,12.9945,0,0,128,0,0 I (4051403) ovms-server-v2: Send MP-0 L0,0,0,0,0,0,17,0,0,0,0 OVMS > simcom status SIMCOM Network Registration: RegisteredHome State: NetMode Ticker: 618 User Data: 0 Mux Open Channels: 4 PPP Connected on channel: #2 PPP Last Error: None GPS: disabled GPS time: disabled NMEA (GPS/GLONASS) Not Connected OVMS > simcom server v2 stop Stopping OVMS Server V2 connection (oscv2) OVMS > E (4104393) ovms-server-v2: Status: Error: Disconnected from OVMS Server V2 OVMS > server v2 start Launching OVMS Server V2 connection (oscv2) OVMS > I (4108553) ovms-server-v2: Status: Starting I (4108553) ovms-server-v2: OVMS Server v2 running I (4108553) ovms-server-v2: Connection is ovms.dexters-web.de:6867 NZLV3/Iekei2ae I (4108553) ovms-server-v2: Status: Connecting... OVMS > W (4119433) ovms-server-v2: Connection failed E (4119443) ovms-server-v2: Status: Error: Disconnected from OVMS Server V2 OVMS > simocom com power off Unrecognised command OVMS > power simcom off Power mode of simcom is now off OVMS > I (4139133) simcom: State: Enter PoweringOff state I (4139133) gsm-ppp: Shutting down (soft)... I (4139133) ovms-server-v2: Network is reconfigured, so disconnect network connection I (4139153) gsm-nmea: Shutdown (direct) I (4139153) simcom: Power Cycle OVMS > I (4149393) simcom: State timeout, transition to 1 I (4149393) simcom: State: Enter CheckPowerOff state OVMS > I (4151153) gsm-ppp: StatusCallBack: User Interrupt I (4151153) gsm-ppp: PPP connection has been closed OVMS > D (4160393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4161393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4162393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4163393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4164393) simcom: tx scmd ch=0 len=4 : AT|| I (4164393) simcom: State timeout, transition to 13 I (4164393) simcom: State: Enter PoweredOff state OVMS > simnc cmpower simcom off n Power mode of simcom is now on OVMS > I (4178943) simcom: State: Enter PoweringOn state I (4178943) simcom: Power Cycle D (4179393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4180393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4181393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4182393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4183393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > D (4184393) simcom: tx scmd ch=0 len=4 : AT|| OVMS > I (4184883) simcom: State: Enter PoweredOn state OVMS > D (4188213) simcom: rx line ch=0 len=12 : +CPIN: READY D (4188213) simcom: rx line ch=0 len=12 : OPL UPDATING D (4188213) simcom: rx line ch=0 len=12 : PNN UPDATING OVMS > D (4189783) simcom: rx line ch=0 len=8 : SMS DONE OVMS > D (4192823) simcom: rx line ch=0 len=10 : CALL READY D (4192823) simcom: rx line ch=0 len=7 : PB DONE OVMS > D (4194393) simcom: tx scmd ch=0 len=103 : AT+CPIN?;+CREG=1;+CTZU=1;+CTZR=1;+CLIP=1;+CMGF=1;+CNMI=1,2,0,0,0;+CSDH=1;+CMEE=2;+CSQ;+AUTOCSQ=1,1;E0|| D (4194453) simcom: rx line ch=0 len=101 : AT+CPIN?;+CREG=1;+CTZU=1;+CTZR=1;+CLIP=1;+CMGF=1;+CNMI=1,2,0,0,0;+CSDH=1;+CMEE=2;+CSQ;+AUTOCSQ=1,1;E0 D (4194533) simcom: rx line ch=0 len=12 : +CPIN: READY D (4194533) simcom: rx line ch=0 len=10 : +CSQ: 6,99 D (4194543) simcom: rx line ch=0 len=2 : OK OVMS > D (4196393) simcom: tx scmd ch=0 len=16 : AT+CGMR;+ICCID|| D (4196463) simcom: rx line ch=0 len=23 : +CGMR: 35316B10SIM5360E D (4196463) simcom: rx line ch=0 len=27 : +ICCID: 8964240002011263238 D (4196463) simcom: rx line ch=0 len=2 : OK OVMS > D (4199393) simcom: tx scmd ch=0 len=8 : AT+COPS? OVMS > D (4200393) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=3,1|| D (4200393) simcom: rx line ch=0 len=5 : ERROR OVMS > D (4201393) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=2,1|| D (4201403) simcom: rx line ch=0 len=2 : OK OVMS > D (4202393) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=1,1|| D (4202403) simcom: rx line ch=0 len=2 : OK OVMS > D (4203393) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=0,5|| D (4203423) simcom: rx line ch=0 len=2 : OK OVMS > D (4204393) simcom: tx scmd ch=0 len=11 : AT+CMUX=0|| D (4204403) simcom: rx line ch=0 len=2 : OK I (4204403) simcom: State: Enter MuxStart state I (4204403) gsm-mux: Start MUX I (4204413) gsm-mux: Channel #0 is open I (4204423) gsm-mux: Channel #1 is open I (4204423) gsm-mux: Channel #2 is open I (4204433) gsm-mux: Channel #3 is open I (4204443) gsm-mux: Channel #4 is open OVMS > D (4234413) simcom: rx line ch=3 len=10 : +CREG: 1,1 D (4234423) simcom: rx line ch=3 len=29 : +CCLK: "18/02/05,16:46:44+52" D (4234423) simcom: rx line ch=3 len=10 : +CSQ: 6,99 D (4234423) simcom: rx line ch=3 len=23 : +COPS: 0,0,"2degrees",2 D (4234423) simcom: rx line ch=3 len=2 : OK OVMS > D (4264413) simcom: rx line ch=3 len=10 : +CREG: 1,1 D (4264413) simcom: rx line ch=3 len=29 : +CCLK: "18/02/05,16:47:14+52" D (4264413) simcom: rx line ch=3 len=10 : +CSQ: 6,99 D (4264413) simcom: rx line ch=3 len=23 : +COPS: 0,0,"2degrees",2 D (4264413) simcom: rx line ch=3 len=2 : OK