[Ovmsdev] Problems with AP + Client mode
Michael Balzer
dexter at expeedo.de
Mon Mar 19 01:15:13 HKT 2018
The effect just came up with standard AP mode and a build based on the commit before, so is not caused by the last mDNS change. It just gets triggered more
likely after the change.
Am 18.03.2018 um 15:31 schrieb Michael Balzer:
> Am 18.03.2018 um 14:38 schrieb Mark Webb-Johnson:
>> I think I’ve fixed the MDNS issues.
>>
>> The problem was when MDNS is initialised, it looks at all the active interfaces on the system and then uses those for it’s broadcasts. If another interface comes up later, it doesn’t know about it and doesn’t broadcast on it.
>>
>> The solution I wrote was to issue a new event network.interface.change whenever a network interface goes up/down (as seen by net manager). Then MDNS picks up on that and uses it to re-initialise the MDNS service.
>>
>> It seems to be ok for me now on AP, CLIENT, and APCLIENT wifi modes. Haven’t tried it with modem yet.
>>
>> Regards, Mark.
>>
> Not working at all for me…
>
> On the mDNS restart after the ppp connect, the webserver loses all connections (→ queue starts filling up) and the wifi task begins allocating RAM in large
> blocks, the module crashes within seconds due to out of memory.
>
>
> Welcome to the Open Vehicle Monitoring System (OVMS) - Async Console
> I (4859) wifi: n:1 1, o:1 0, ap:1 1, sta:1 0, prof:1
> I (5519) wifi: state: init -> auth (b0)
> I (5529) wifi: state: auth -> assoc (0)
> I (5529) wifi: state: assoc -> run (10)
> I (5569) wifi: connected with WLAN-214677, channel 1
> OVMS > enable dee4shi!
> Secure mode
> OVMS # log level debug
> Logging level for * set to debug
> OVMS # event trace on
> Event tracing is now on
> I (6659) event: sta ip: 192.168.2.105, mask: 255.255.255.0, gw: 192.168.2.1
> I (6659) events: Signal(network.interface.up)
> I (6659) netmanager: Set DNS#0 8.8.8.8
> I (6659) netmanager: Set DNS#1 8.8.4.4
> I (6669) events: Signal(system.wifi.sta.gotip)
> I (6669) netmanager: Interface priority is st1 (192.168.2.105/255.255.255.0 gateway 192.168.2.1)
> I (6669) events: Signal(network.wifi.up)
> I (6669) events: Signal(network.up)
> I (6669) time: Starting SNTP client
> I (6669) ovms-server-v2: Network is up, scheduling connection retry
> I (6669) events: Signal(network.interface.change)
> I (6669) ovms-mdns: Restarting MDNS service
> I (6699) esp32wifi: WiFi UP with SSID: WLAN-214677, MAC: 30:ae:a4:37:25:88, IP: 192.168.2.105, mask: 255.255.255.0, gw: 192.168.2.1
> D (6839) time: ntp (stratum 1 trusted 1) provides time Sun Mar 18 14:23:44 2018 (350351us) UTC
> D (7019) websocket: new WebSocket slot 0, registered modifier is 3
> D (7019) websocket: WebSocket connection 0x3fff5568 opened; 1 clients active
> I (7989) webserver: HTTP GET /
> D (7989) webserver: Serve /: 4128 bytes used, 34172 free
> D (8039) websocket: WebSocket connection 0x3fff5568 closed; 0 clients active
> I (8149) ovms-server-v2: Connection is ovms.dexters-web.de:6867 test1/aeL1aN9j
> I (8149) ovms-server-v2: Status: Connecting...
> I (8149) webserver: HTTP GET /status
> I (8409) ovms-server-v2: Connection successful
> I (8409) ovms-server-v2: Status: Logging in...
> I (8419) ovms-server-v2: Sending server login: MP-C 0 R6hz25YMJ5jHndqCi198oR /0rgyY32gJ09KJx21z7PHA== test1
> I (8439) ovms-server-v2: Got server response: MP-S 0 ZGV011ItmTBjI4it2cfeel UcEyYrgS0VfYRcaPezPw4A==
> I (8449) ovms-server-v2: Server token is ZGV011ItmTBjI4it2cfeel and digest is UcEyYrgS0VfYRcaPezPw4A==
> I (8449) ovms-server-v2: Status: Server auth ok. Now priming crypto.
> I (8449) ovms-server-v2: Shared secret key is ZGV011ItmTBjI4it2cfeelR6hz25YMJ5jHndqCi198oR (44 bytes)
> I (8459) ovms-server-v2: Status: OVMS V2 login successful, and crypto channel established
> I (8469) ovms-server-v2: Incoming Msg: MP-0 Z0
> OVMS # mo m
> Free 8-bit 29148/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> no task 5312 0 0 0 +5312 +0 +0 +0
> esp_timer 50220 0 644 0 +50220 +0 +644 +0
> main 24628 0 0 0 +24628 +0 +0 +0
> Housekeeping 35692 56804 0 0 +35692 +56804 +0 +0
> ipc0 10848 0 0 0 +10848 +0 +0 +0
> tiT 156 5656 0 0 +156 +5656 +0 +0
> ipc1 12 0 0 0 +12 +0 +0 +0
> NetManTask 16 5552 0 0 +16 +5552 +0 +0
> eventTask 8 12752 0 0 +8 +12752 +0 +0
> wifi 32 5084 0 0 +32 +5084 +0 +0
> Tmr Svc 0 1360 0 0 +0 +1360 +0 +0
> mdns 0 552 0 0 +0 +552 +0 +0
> AsyncConsole 0 20 27488 0 +0 +20 +27488 +0
> I (9149) ovms-server-v2: Send MP-0 S50,K,0,0,done,storage,50,50,15,0,0,0,0,4,1,0,0,0,96.89,0,0,0,85,-1,0,0,0,0,0,0,0,0.00,0.00,0
> I (9159) ovms-server-v2: Send MP-0 D0,0,5,0,0,-40,0,0,0,8,0,0,0,0,0.967033,0,0,0,0,0
> I (9159) ovms-server-v2: Send MP-0 L0,0,0,0,0,0,0,10003,0.0,0,0
> I (9159) ovms-server-v2: Send MP-0 W0,0,0,0,0,0,0,0,0
> I (9159) ovms-server-v2: Send MP-0 F3.0.991-60-gcb891b8-dirty/factory/main build (idf v3.1-dev-453-g0f978bcb) Mar 18 2018 15:14:33,,0,1,RT,WLAN-214677
> D (9169) websocket: WebSocket connection 0x3fff5564 opened; 1 clients active
> OVMS # mo m
> Free 8-bit 35456/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 2544 0 0 +0 -3112 +0 +0
> NetManTask 16 5436 0 0 +0 -116 +0 +0
> Tmr Svc 0 1132 0 0 +0 -228 +0 +0
> mdns 0 0 0 0 +0 -552 +0 +0
> D (12149) 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||
> I (12149) simcom: State timeout, transition to 2
> I (12149) simcom: State: Enter PoweringOn state
> I (12149) simcom: Power Cycle
> I (13149) housekeeping: System considered stable (free: 36156 bytes)
> D (13149) simcom: tx scmd ch=0 len=4 : AT||
> D (14149) simcom: tx scmd ch=0 len=4 : AT||
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 540 0 0 +0 -592 +0 +0
> D (15149) simcom: tx scmd ch=0 len=4 : AT||
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (16149) simcom: tx scmd ch=0 len=4 : AT||
> OVMS # mo m
> Free 8-bit 34364/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 668 0 0 +0 +128 +0 +0
> D (17149) simcom: tx scmd ch=0 len=4 : AT||
> D (18149) simcom: tx scmd ch=0 len=4 : AT||
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 540 0 0 +0 -128 +0 +0
> I (19129) simcom: State: Enter PoweredOn state
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> OVMS # mo m
> Free 8-bit 36304/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 2528 0 0 +0 -16 +0 +0
> D (21809) simcom: rx line ch=0 len=12 : +CPIN: READY
> D (21809) simcom: rx line ch=0 len=12 : OPL UPDATING
> D (21809) simcom: rx line ch=0 len=12 : PNN UPDATING
> D (22419) simcom: rx line ch=0 len=8 : SMS DONE
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 2544 0 0 +0 +16 +0 +0
> D (23149) simcom: rx line ch=0 len=10 : CALL READY
> D (23149) simcom: rx line ch=0 len=7 : PB DONE
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (28149) 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 (28179) 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 (28259) simcom: rx line ch=0 len=12 : +CPIN: READY
> D (28259) simcom: rx line ch=0 len=10 : +CSQ: 9,99
> D (28259) simcom: rx line ch=0 len=2 : OK
> OVMS # mo m
> Free 8-bit 36272/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (30149) simcom: tx scmd ch=0 len=16 : AT+CGMR;+ICCID||
> OVMS # mo m
> Free 8-bit 34048/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 4404 0 0 +0 +1860 +0 +0
> SIMCOMTask 0 416 0 0 +0 +416 +0 +0
> D (30179) simcom: rx line ch=0 len=23 : +CGMR: 35316B10SIM5360E
> D (30179) simcom: rx line ch=0 len=27 : +ICCID: 8944500408175816389
> D (30179) simcom: rx line ch=0 len=2 : OK
> OVMS # mo m
> Free 8-bit 36172/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 2544 0 0 +0 -1860 +0 +0
> SIMCOMTask 0 64 0 0 +0 -352 +0 +0
> D (33149) simcom: tx scmd ch=0 len=8 : AT+COPS?
> OVMS # mo m
> Free 8-bit 36172/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (34149) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=3,1||
> D (34159) simcom: rx line ch=0 len=5 : ERROR
> OVMS # mo m
> Free 8-bit 36172/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (35149) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=2,1||
> D (35179) simcom: rx line ch=0 len=2 : OK
> D (36149) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=1,1||
> D (36169) simcom: rx line ch=0 len=2 : OK
> OVMS # mo m
> Free 8-bit 36172/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (37149) simcom: tx scmd ch=0 len=20 : AT+CMUXSRVPORT=0,5||
> D (37179) simcom: rx line ch=0 len=2 : OK
> OVMS # mo m
> Free 8-bit 36172/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (38149) simcom: tx scmd ch=0 len=11 : AT+CMUX=0||
> D (38169) simcom: rx line ch=0 len=2 : OK
> I (38169) simcom: State: Enter MuxStart state
> I (38169) gsm-mux: Start MUX
> I (38179) gsm-mux: Channel #0 is open
> I (38189) gsm-mux: Channel #1 is open
> I (38199) gsm-mux: Channel #2 is open
> I (38199) gsm-mux: Channel #3 is open
> I (38209) gsm-mux: Channel #4 is open
> I (39149) simcom: State: Enter NetWait state
> I (39149) gsm-nmea: Startup
> OVMS # mo m
> Free 8-bit 31416/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 552 0 0 +0 +12 +0 +0
> SIMCOMTask 0 4520 0 0 +0 +4456 +0 +0
> D (39209) simcom: rx line ch=4 len=2 : OK
> OVMS # mo m
> Free 8-bit 31620/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 540 0 0 +0 -12 +0 +0
> SIMCOMTask 0 4404 0 0 +0 -116 +0 +0
> OVMS # mo m
> Free 8-bit 28432/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 5656 0 0 +0 +3112 +0 +0
> D (43149) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43149) events: Signal(notify.data)
> D (43149) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43149) events: Signal(notify.data)
> D (43159) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43159) events: Signal(notify.data)
> D (43159) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43159) events: Signal(notify.data)
> D (43169) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43169) events: Signal(notify.data)
> D (43169) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43169) events: Signal(notify.data)
> D (43179) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43179) events: Signal(notify.data)
> D (43179) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43179) events: Signal(notify.data)
> D (43179) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43179) events: Signal(notify.data)
> D (43189) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43189) events: Signal(notify.data)
> D (43199) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43199) events: Signal(notify.data)
> D (43199) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43199) events: Signal(notify.data)
> D (43209) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43209) events: Signal(notify.data)
> D (43209) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43209) events: Signal(notify.data)
> D (43219) notify: Created entry for verbosity 1024 has 1 readers pending
> I (43219) events: Signal(notify.data)
> D (43219) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-P,1,86400,1,1,5000,10000,0,0,0,0,-40,200,-40,0,0,0,0|
> I (43219) ovms-server-v2: Send MP-0 h1,0,RT-BAT-P,1,86400,1,1,5000,10000,0,0,0,0,-40,200,-40,0,0,0,0
> D (43219) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,1,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43219) ovms-server-v2: Send MP-0 h2,0,RT-BAT-C,1,86400,1,1,0,10000,0,0,-40,200,-40,0
> D (43219) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,2,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43219) ovms-server-v2: Send MP-0 h3,0,RT-BAT-C,2,86400,1,1,0,10000,0,0,-40,200,-40,0
> D (43219) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,3,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43219) ovms-server-v2: Send MP-0 h4,0,RT-BAT-C,3,86400,1,1,0,10000,0,0,-40,200,-40,0
> D (43219) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,4,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43219) ovms-server-v2: Send MP-0 h5,0,RT-BAT-C,4,86400,1,1,0,10000,0,0,-40,200,-40,0
> D (43219) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,5,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43219) ovms-server-v2: Send MP-0 h6,0,RT-BAT-C,5,86400,1,1,0,10000,0,0,-40,200,-40,0
> D (43229) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,6,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43229) ovms-server-v2: Send MP-0 h7,0,RT-BAT-C,6,86400,1,1,0,10000,0,0,-40,200,-40,0
> D (43229) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,7,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43229) ovms-server-v2: Send MP-0 h8,0,RT-BAT-C,7,86400,1,1,0,10000,0,0,-40,200,-40,0
> D (43229) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,8,86400,1,1,0,10000,0,0,-40,200,-40,0|
> D (43229) ovms-server-v2: TransmitNotifyData: msg=RT-BAT-C,14,86400,1,1,0,10000,0,0,-40,200,-40,0|
> I (43459) ovms-server-v2: Incoming Msg: MP-0 h1
> I (43469) ovms-server-v2: Incoming Msg: MP-0 h2
> I (43479) ovms-server-v2: Incoming Msg: MP-0 h3
> I (43479) ovms-server-v2: Incoming Msg: MP-0 h4
> I (43489) ovms-server-v2: Incoming Msg: MP-0 h5
> I (43489) ovms-server-v2: Incoming Msg: MP-0 h6
> I (43489) ovms-server-v2: Incoming Msg: MP-0 h7
> I (43489) ovms-server-v2: Incoming Msg: MP-0 h8
> I (43709) ovms-server-v2: Incoming Msg: MP-0 h9
> I (43729) ovms-server-v2: Incoming Msg: MP-0 h10
> I (43729) ovms-server-v2: Incoming Msg: MP-0 h11
> I (43729) ovms-server-v2: Incoming Msg: MP-0 h12
> I (43739) ovms-server-v2: Incoming Msg: MP-0 h13
> I (43739) ovms-server-v2: Incoming Msg: MP-0 h14
> I (43739) ovms-server-v2: Incoming Msg: MP-0 h15
> [12 log messages lost]
> OVMS # mo m
> Free 8-bit 31620/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 2544 0 0 +0 -3112 +0 +0
> OVMS # mo m
> Free 8-bit 31620/283212, 32-bit 27544/55820, SPIRAM 0/0
> OVMS # mo m
> Free 8-bit 31620/283212, 32-bit 27544/55820, SPIRAM 0/0
> OVMS # mo m
> Free 8-bit 31620/283212, 32-bit 27544/55820, SPIRAM 0/0
> D (49169) simcom: rx line ch=3 len=10 : +CREG: 1,5
> I (49169) simcom: CREG Network Registration: RegisteredRoaming
> D (49169) simcom: rx line ch=3 len=29 : +CCLK: "80/01/06,06:50:42+04"
> D (49179) simcom: rx line ch=3 len=10 : +CSQ: 9,99
> D (49179) simcom: rx line ch=3 len=34 : +COPS: 0,0,"Telekom.de Hologram",2
> D (49179) simcom: rx line ch=3 len=2 : OK
> OVMS # mo m
> Free 8-bit 31360/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 668 0 0 +0 +128 +0 +0
> SIMCOMTask 0 4436 0 0 +0 +32 +0 +0
> I (50149) simcom: State: Enter NetStart state
> D (51189) simcom: rx line ch=2 len=14 : CONNECT 115200
> I (51189) simcom: PPP Connection is ready to start
> OVMS # mo m
> Free 8-bit 31536/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 540 0 0 +0 -128 +0 +0
> I (52149) simcom: State: Enter NetMode state
> I (52149) gsm-ppp: Initialising...
> OVMS # mo m
> Free 8-bit 26384/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 7612 0 0 +0 +5068 +0 +0
> I (54129) gsm-ppp: StatusCallBack: None
> I (54129) gsm-ppp: status_cb: Connected
> I (54139) gsm-ppp: our_ipaddr = 10.170.195.13
> I (54139) gsm-ppp: his_ipaddr = 10.64.64.64
> I (54139) gsm-ppp: netmask = 255.255.255.255
> I (54139) gsm-ppp: our6_ipaddr = ::
> I (54139) events: Signal(network.interface.up)
> I (54139) netmanager: Set DNS#0 8.8.8.8
> I (54139) netmanager: Set DNS#1 8.8.4.4
> I (54139) events: Signal(system.modem.gotip)
> I (54139) netmanager: Interface priority is st1 (192.168.2.105/255.255.255.0 gateway 192.168.2.1)
> I (54139) events: Signal(network.modem.up)
> I (54139) events: Signal(network.up)
> I (54139) time: Starting SNTP client
> I (54149) events: Signal(network.interface.change)
> I (54149) ovms-mdns: Restarting MDNS service
> OVMS # mo m
> Free 8-bit 27268/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> tiT 156 9384 0 0 +0 +1772 +0 +0
> NetManTask 16 5488 0 0 +0 +52 +0 +0
> eventTask 8 8260 0 0 +0 -4492 +0 +0
> Tmr Svc 0 552 0 0 +0 +12 +0 +0
> SIMCOMTask 0 5968 0 0 +0 +1532 +0 +0
> OVMS # mo m
> Free 8-bit 27204/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 576 0 0 +0 +24 +0 +0
> OVMS # mo m
> Free 8-bit 25388/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> wifi 32 6808 0 0 +0 +1724 +0 +0
> Tmr Svc 0 588 0 0 +0 +12 +0 +0
> OVMS # mo m
> Free 8-bit 25356/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 600 0 0 +0 +12 +0 +0
> W (59669) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (59919) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (60149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (60169) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> OVMS # mo m
> Free 8-bit 23392/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> wifi 32 8532 0 0 +0 +1724 +0 +0
> Tmr Svc 0 624 0 0 +0 +24 +0 +0
> W (60419) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (60669) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (60919) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (61149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (61149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (61149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (61169) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (61419) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (61669) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> OVMS # mo m
> Free 8-bit 21624/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> wifi 32 10256 0 0 +0 +1724 +0 +0
> Tmr Svc 0 660 0 0 +0 +36 +0 +0
> W (61919) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (62149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (62169) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (62419) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (62669) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (62919) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> OVMS # mo m
> Free 8-bit 21596/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 672 0 0 +0 +12 +0 +0
> W (63149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (63169) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (63419) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (63669) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (63919) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (64149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> OVMS # mo m
> Free 8-bit 21360/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> Tmr Svc 0 812 0 0 +0 +140 +0 +0
> W (64169) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (64419) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (64669) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (64919) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (65149) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (65169) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> W (65419) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
> OVMS # mo m
> Free 8-bit 17932/283212, 32-bit 27544/55820, SPIRAM 0/0
> --Task-- Total DRAM D/IRAM IRAM SPIRAM +/- DRAM D/IRAM IRAM SPIRAM
> wifi 32 13708 0 0 +0 +3452 +0 +0
> Tmr Svc 0 708 0 0 +0 -104 +0 +0
> W (65669) websocket: WebSocketHandler[0x3fff5564]: job queue overflow
>
> … and so on → crash
>
>
>>> On 18 Mar 2018, at 6:38 PM, Michael Balzer <dexter at expeedo.de> wrote:
>>>
>>> Greg,
>>>
>>> fix for webserver not starting in AP mode is pushed.
>>>
>>> AP+client mode also works now.
>>>
>>> Be aware there is an issue with the mDNS service in this mode, it's working on neither AP nor client interface, but the webserver responds on both interfaces
>>> when using their IP addresses.
>>>
>>> Regards,
>>> Michael
>>>
>>>
>>> Am 18.03.2018 um 00:13 schrieb Greg D.:
>>>> Hi Michael,
>>>>
>>>> As in my last note, I think something broke the webserver for me. I
>>>> can't seem to connect to it, from either phone/tablet or brower
>>>> (chrome/firefox). I can't think of anything I did in the configuration,
>>>> either, and even tried paring things back to a much simpler config with
>>>> just wifi mode ap. No joy.
>>>>
>>>> With Mark's latest changes, the network activation seems a lot better
>>>> than it was before, and if I just look at the ability to ping the
>>>> module, I think it's in pretty good shape. But why would I be
>>>> consistently getting a connection refused from the browser? And, why
>>>> (sometimes) would either the modem or wifi interface seem to be up
>>>> (network status shows an ip address, and default interface pointing to
>>>> it), but the module wouldn't connect through it to the v2 server?
>>>>
>>>> The overflow warnings may be related to the above, in that they would
>>>> persist until there was a timeout from the browser, or if I tapped on,
>>>> say, the home link. That would send the new command across, and both
>>>> stop the warnings, and execute the new command. But today's work was
>>>> focused on just getting to the home page, not Status, so Mongoose is
>>>> getting stuck before even that. No indication of a command, for
>>>> example, on the console. Is the issue in the network socket layer?
>>>>
>>>> Still poking at it...
>>>>
>>>> Greg
>>>>
>>>>
>>>> Michael Balzer wrote:
>>>>> Thanks for testing, I haven't had time to experiment with it yet.
>>>>>
>>>>> Maybe we should tag the AP+Client mode as "experimental" for the release?
>>>>>
>>>>> Regarding the "job queue overflow" warnings: those occur when the network manager task is busy. I think I'll change them to debug level or avoid repeating them.
>>>>>
>>>>> All mongoose socket processing is done in the network manager task, as mongoose is single threaded. So if one connection is busy, all other connections are blocked.
>>>>>
>>>>> Regards,
>>>>> Michael
>>>>>
>>>>>
>>>>> Am 16.03.2018 um 23:47 schrieb Greg D.:
>>>>>> Hi folks,
>>>>>>
>>>>>> Are any of you having trouble with AP+Client mode? A couple of
>>>>>> observations....
>>>>>>
>>>>>> AP mode, by itself, works great. AP+Client, however, seems to depend on
>>>>>> whether the client side gets connected or not. If it does, I can also
>>>>>> connect to the AP, and when connected, navigate the webserver. If the
>>>>>> client side doesn't get connected (the specified SSID isn't available),
>>>>>> my phone can connect to the AP, but accessing the webserver never works
>>>>>> (times out).
>>>>>>
>>>>>> This is with the simcom modem unconnected (antenna removed). I also
>>>>>> have the DNS server address fixed to '9.9.9.9 8.8.8.8', to remove that
>>>>>> from being an issue.
>>>>>>
>>>>>> If I go into the webserver (when it's working) and configure the client
>>>>>> SSID to connect to any available, neither the client nor the AP come up
>>>>>> after a module reset. This is apparently due to an error during the
>>>>>> Auto execution, where the 'wifi mode apclient' command is failing due to
>>>>>> not having the client ssid specified (it's coded as required, should be
>>>>>> optional).
>>>>>>
>>>>>> As I noted earlier, if the module comes up and the client SSID isn't
>>>>>> immediately available, the ability for it to connect later is limited.
>>>>>> Mark suggested this is because the wifi client isn't scanning channels
>>>>>> other than the one the AP mode is on, so it's a matter of luck if the
>>>>>> client AP happens to come up on the right one. (Here, that never seems
>>>>>> to occur :( ).
>>>>>>
>>>>>> If the AP+Client does come up (client SSID is available), and later the
>>>>>> modem gets connected, connection to the v2 server hangs. Seems like the
>>>>>> internal routing of traffic is getting confused, or rather, the module
>>>>>> is getting a new IP address, but the server's connection is not
>>>>>> bounced. (Enhancement request: Have the network status command to note
>>>>>> which interface is considered active.) IMHO, we really shouldn't even
>>>>>> try to run the modem if the server is connected via the wifi client,
>>>>>> because, besides messing up the network configuration, it's also causing
>>>>>> a slow drain on the modem's data plan (I'm seeing the Rx/Tx counters
>>>>>> increment) for no benefit.
>>>>>>
>>>>>> Sometimes I get a spew of 'job queue overflow' errors (see below). Not
>>>>>> sure of all the conditions, but tapping the Status tab seems the most
>>>>>> often cause, though it can be tapped without causing the error too.
>>>>>>
>>>>>> Under conditions where the AP+Client had the client connected and the AP
>>>>>> able to associate, but not able to access the webserver, I was able to
>>>>>> get to the webserver if I joined the same network as the client and
>>>>>> surfed to the module's address there.
>>>>>>
>>>>>> Lots of test cases here. I really need a test matrix to be sure I can
>>>>>> reproduce the issues and successes later... Part of the puzzle is that
>>>>>> the retries built into the software often recover things, so it's hard
>>>>>> to know what's a fatal failure, and what is recoverable in time, and so
>>>>>> may be less serious for the end user.
>>>>>>
>>>>>> Finally, I have seen circumstances where the simcom model gets into a
>>>>>> state where it comes up and starts connecting, but after a few frames
>>>>>> (less than 10) gets stuck with an increasing number of framing errors,
>>>>>> but no progress on receive. Eventually it will reset and try again, and
>>>>>> after some number of these, sometimes finally connect (and mess up the
>>>>>> wifi that was running happily all along).
>>>>>>
>>>>>> Greg
>>>>>>
>>>>>>
>>>>>> I (473446) simcom: Power Cycle
>>>>>> I (479406) simcom: State: Enter PoweredOn state
>>>>>> I (498456) simcom: State: Enter MuxStart state
>>>>>> I (498456) gsm-mux: Start MUX
>>>>>> I (498466) gsm-mux: Channel #0 is open
>>>>>> I (498466) gsm-mux: Channel #1 is open
>>>>>> I (498476) gsm-mux: Channel #2 is open
>>>>>> I (498476) gsm-mux: Channel #3 is open
>>>>>> I (498486) gsm-mux: Channel #4 is open
>>>>>> I (499446) simcom: State: Enter NetWait state
>>>>>> I (503836) webserver: HTTP POST /api/execute
>>>>>> I (503836) webcommand: HttpCommandStream[0x3fff96c0]: 20240 bytes free,
>>>>>> executing: simcom status
>>>>>> I (509506) simcom: CREG Network Registration: RegisteredRoaming
>>>>>> I (510446) simcom: State: Enter NetStart state
>>>>>> I (511596) simcom: PPP Connection is ready to start
>>>>>> I (512446) simcom: State: Enter NetMode state
>>>>>> I (512446) gsm-ppp: Initialising...
>>>>>> I (512456) webserver: HTTP GET /home
>>>>>> I (515616) gsm-ppp: StatusCallBack: None
>>>>>> I (515616) gsm-ppp: status_cb: Connected
>>>>>> I (515616) gsm-ppp: our_ipaddr = 10.170.146.142
>>>>>> I (515616) gsm-ppp: his_ipaddr = 10.64.64.64
>>>>>> I (515616) gsm-ppp: netmask = 255.255.255.255
>>>>>> I (515616) gsm-ppp: our6_ipaddr = ::
>>>>>> I (515616) netmanager: Set DNS#0 9.9.9.9
>>>>>> I (515616) netmanager: Set DNS#1 8.8.8.8
>>>>>> I (515616) time: Starting SNTP client
>>>>>> I (517746) webserver: HTTP GET /home
>>>>>> I (520476) webserver: HTTP GET /status
>>>>>> W (526166) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>> W (526416) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>> W (526446) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>> W (526666) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>> W (526916) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>> W (527166) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>> W (527416) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>> W (527446) websocket: WebSocketHandler[0x3fff5f2c]: job queue overflow
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> _______________________________________________
>>>>>> OvmsDev mailing list
>>>>>> OvmsDev at lists.teslaclub.hk
>>>>>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev
>>>> _______________________________________________
>>>> OvmsDev mailing list
>>>> OvmsDev at lists.teslaclub.hk
>>>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev
>>> --
>>> Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
>>> Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
>>>
>>>
>>> _______________________________________________
>>> OvmsDev mailing list
>>> OvmsDev at lists.teslaclub.hk
>>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev
>> _______________________________________________
>> OvmsDev mailing list
>> OvmsDev at lists.teslaclub.hk
>> http://lists.teslaclub.hk/mailman/listinfo/ovmsdev
--
Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal
Fon 02333 / 833 5735 * Handy 0176 / 206 989 26
More information about the OvmsDev
mailing list