WiFi disconnect errors

[zlowred]

David, I'm not sure if that's the same problem or not, but here is what I'm observing:
WiFi connection works most of the time, signal strength looks ok (between -60dBm and -50dBm) but sometimes it just fails throwing AJAX error and doesn't come back until I reset the WiFi module by using M552 S0 followed by M552 S1.
It was always the case, and I thought it just a signal level issue. I tried using two different routers (one noname provided by my provider, the other one is Apple TimeCapsule). Now the strange part I noticed just recently, is that when it fails, it is till showing as connected in the WiFi router web UI. Even more, if I connect using the USB and issue M122, it is showing wifi as connected, with good signal strength and valid IP address. That makes me thinking that at least in some cases what looks like a WiFi connectivity issue is not related to connectivity. I believe it might be the web server firmware crashing or hanging.
It happens pretty often, and I'm happy to provide further diagnostic data - just tell me what exactly do I need to do.

[dc42]

zlowred, please upgrade to the just-released DuetWiFiFirmware 1.20beta8 and DuetWiFiServer 1.20beta9. Connect a PC via USB and send M111 S1 P14 to enable the new WiFi debugging feature. You will get a few WiFi debug messages during startup and initial connection to your router, but there should be no more after that. If the disconnect occurs again, look at the console on the PC to see whether any more debug messages have been received, and report what you find.

[zlowred]

That means to keep USB connected all the time, right? (no problems with that, just to confirm)
added: maybe it's better to keep debug log somewhere on the flash card so that nothing is lost in case when PC went to sleep for example.

[peirof]

I think I've sent my Duet3D WiFi to England, because of symptoms very similar to those described …

I hope not....

[dc42]

@peirof:

I think I've sent my Duet3D WiFi to England, because of symptoms very similar to those described …

I hope not....

Yours was different, it wouldn't upload new wifi firmware.

[peirof]

i hope….

[zlowred]

So I was able to reproduce the disconnect. Below is the full log. Note that I temporarily disabled M552 S1 in the config.g so that full log is captured.
I issued M122 after the disconnect in case it contains something useful.

RepRapFirmware for Duet WiFi Version 1.20beta8 dated 2017-11-17

Executing config.g...HTTP is enabled on port 80
FTP is disabled
TELNET is disabled

Done!
Network disabled.
RepRapFirmware for Duet WiFi is up and running.
M111 S1 P14
Debugging enabled for modules: WiFi(14)
Debugging disabled for modules: Platform(0) Network(1) Webserver(2) GCodes(3) Move(4) Heat(5) DDA(6) Roland(7) Scanner(8) PrintMonitor(9) Storage(10) PortControl(11) DuetExpansion(12) FilamentSensors(13)
ok
M552 S1
ok
WiFi: 
WiFi:  ets Jan  8 2013,rst cause:2, boot mode:(3,7)
WiFi: 
WiFi: load 0x4010f000, len 1384, room 16 
WiFi: tail 8
WiFi: chksum 0x2d
WiFi: csum 0x2d
WiFi: v00007fff
WiFi: ~ld
WiFi module started
WiFi: mode : sta(ec:fa:bc:02:1e:41)
WiFi: add if0
WiFi: scandone
WiFi: sleep enable,type: 2
WiFi: scandone
WiFi: state: 0 -> 2 (b0)
WiFi: state: 2 -> 3 (0)
WiFi: state: 3 -> 5 (10)
WiFi: add 0
WiFi: aid 3
WiFi: cnt 
WiFi: 
WiFi: connected with Lrrr, channel 1
WiFi: dhcp client start...
Wifi module is connected to access point Lrrr, IP address 192.168.1.102
WiFi: ip:192.168.1.102,mask:255.255.255.0,gw:192.168.1.1
WiFi: pm open,type:2 0
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
WiFi: p->ref == 1
M122
=== Diagnostics ===
Used output buffers: 1 of 32 (8 max)
=== Platform ===
RepRapFirmware for Duet WiFi version 1.20beta8 running on Duet WiFi 1.0
Board ID: 08DDM-9FAM2-LW4S8-6JTDD-3SJ6P-9MXBY
Static ram used: 15488
Dynamic ram used: 99624
Recycled dynamic WiFi: 
ram: 3672
Stack ram used: 4328 current, 5324 maximum
NeveWiFi: LINK
r used ram: 6964
Last reset 00:02:07 ago, cause: power up
Last software reset reason: User, spinning module GCodes, available RAM 6960 bytes (slot 4)
Software reset code 0x0003, HFSR 0x00000000, CFSRWiFi: 	xmit: 0
 0x00000000, ICSR 0x00400000, BFAR 0xe000ed38, SP 0xffffffff
Error status: 0
Free file entries:WiFi: 	recv: 0
 10
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest block write time: 0.0ms
MCU temperature: min 31.5, current 34.8, max 35.0
Supply voltage:WiFi: 	fw: 0
 min 0.3, current 0.5, max 0.5, under voltage events: 0, over voltage events: 0
Driver 0: ok
Driver 1: ok
Driver 2: ok
Driver 3: okWiFi: 	drop: 0

Driver 4: ok
Date/time: 2017-11-18 11:55:08
Cache data hit count 436514026
Slowest main loop (seconds): 0.099160; fastest: 0WiFi: 	chkerr: 0
.000034
=== Move ===
MaxReps: 0, StepErrors: 0, FreeDm: 240, MinFreeDm 240, MaxWait: 0ms, Underruns: 0, 0
Scheduled moves: 0, completed moves: 0
Bed compensation iWiFi: 	lenerr: 0
n use: none
Bed probe heights: 0.000 0.000 0.000 0.000 0.000
=== Heat ===
Bed heater = 0, chaWiFi: 	memerr: 0
mber heater = -1
Heater 1 is on, I-accum = 0.0
=== GCodes ===
Segments left: 0
Stack records: 2 allocated, 0 in use
Movement lock held by null
http is idle in state(s) 0
telnet is idle in stateWiFi: 	rterr: 0
(s) 0
file is idle in state(s) 0
serial is ready with "M122" inWiFi: 	proterr: 0
 state(s) 0
aux is idle in state(s) 0
daemon is idle in state(s) 0
queue is idle in state(s) 0
autopause is idle in state(s) 0
Code queue is empty.
Network state is running
WiFi module is connected to access point 
Failed mWiFi: 	opterr: 0
essages: pending 0, notready 0, nWiFi: 	err: 0
oresp 0
WiFi firmware version 1.20b9
WiFi MAC address ec:fa:bc:02:1e:41
WiFi Vcc 3.35, reset reason Turned on by main processor
WiFi flash size 4194304, free heap 25224
WiFi IP address 192.168.1.102
WiFi signal strength -58dBm, reconnections 0, sleep mode WiFi: 	cachehit: 0
modem
HTTP sessions: 1 of 8
Socket states:  0 0 0 0 0 0 0 0
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
ok
WiFi: 
WiFi: ETHARP
WiFi: 	xmit: 4
WiFi: 	recv: 2
WiFi: 	fw: 0
WiFi: 	drop: 39
WiFi: 	chkerr: 0
WiFi: 	lenerr: 0
WiFi: 	memerr: 0
WiFi: 	rterr: 0
WiFi: 	proterr: 39
WiFi: 	opterr: 0
WiFi: 	err: 0
WiFi: 	cachehit: 1605
WiFi: 
WiFi: IP
WiFi: 	xmit: 1614
WiFi: 	recv: 1892
WiFi: 	fw: 0
WiFi: 	drop: 1
WiFi: 	chkerr: 1
WiFi: 	lenerr: 0
WiFi: 	memerr: 0
WiFi: 	rterr: 0
WiFi: 	proterr: 0
WiFi: 	opterr: 0
WiFi: 	err: 0
WiFi: 	cachehit: 0
WiFi: 
WiFi: IGMP
WiFi: 	xmit: 4
WiFi: 	recv: 1
WiFi: 	drop: 0
WiFi: 	chkerr: 0
WiFi: 	lenerr: 0
WiFi: 	memerr: 0
WiFi: 	proterr: 0
WiFi: 	rx_v1: 0
WiFi: 	rx_group: 0
WiFi: rx_general: 1
WiFi: rx_rmit: 1174
WiFi: 	recv: 1831
WiFi: 	fw: 0
WiFi: 	drop: 0
WiFi: 	chkerr: 0
WiFi: 	lenerr: 0
WiFi: 	memerr: 0
WiFi: 	rterr: 0
WiFi: 	proterr: 0
WiFi: 	opterr: 0
WiFi: 	err: 0
WiFi: 	cachehit: 0

The "WiFi: p->ref == 1" messages appeared around every few seconds or so, and the "AJAX error" appeared after the last "WiFi: p->ref == 1" message. I waited for another 10 minutes, but didn't see these messages after the "AJAX error"

[dc42]

Thanks. Did the p->ref==1 messages start appearing as soon as you connected, or not until shortly before the disconnection message?

[zlowred]

First message is seconds after I connected. Others are at irregular intervals between few seconds and somewhere around a minute between each other.
In the meanwhile, I've replaced the wifi module with ESP-07S with external antenna, and it didn't change anything, e.g. behaviour is exactly the same.

[dc42]

I've never seen those p->ref==1 messages on my test systems. I suspect they are related to the disconnections. Please do a few more tests, to establish how many p->ref messages you get, before they start appearing every few seconds and the disconnection occurs.

Edit: those p->ref == 1 messages indicate an assertion failure within the TCP/IP stack, so they are definitely indicative of something going wrong.

[zlowred]

Sure, I'll collect more data and post it here

In the meanwhile – I can build the firmware myself, so if you need me to build it with maybe some additional debug flags, or quickly test some changes without releasing the new beta version – feel free to ask.

[dc42]

Thanks. Those debug messages come from the firmware on the wifi module, so it's that firmware that is likely to contain the fault.

[dc42]

Please can anyone else who is still getting WiFi disconnections even though the RSSI is good do the following:

1. Upgrade to the just-released DuetWiFiFirmware 1.20beta8 and DuetWiFiServer 1.20beta9.

2. Connect a PC via USB and send M111 S1 P14 to enable the new WiFi debugging feature. If you have already started wifi, send M552 S-1 and then M552 S1 to restart it. You will get some WiFi debug messages during startup and connection to your router, similar to the following:

WiFi:
WiFi: ets Jan 8 2013,rst cause:2, boot mode:(3,6)
WiFi:
WiFi: load 0x4010f000, len 1384, room 16
WiFi: tail 8
WiFi: chksum 0x2d
WiFi: csum 0x2d
WiFi: v00007fff
WiFi: ~ld
WiFi module started
WiFi: mode : sta(a0:20:a6:19:28:23)
WiFi: add if0
WiFi: scandone
WiFi: sleep enable,type: 2
WiFi: scandone
WiFi: state: 0 -> 2 (b0)
WiFi: state: 2 -> 3 (0)
WiFi: state: 3 -> 5 (10)
WiFi: add 0
WiFi: aid 2
WiFi: cnt
WiFi:
WiFi: connected with ********, channel 6
WiFi: dhcp client start…
Wifi module is connected to access point ********* IP address 192.168.1.123
WiFi: ip:192.168.1.123,mask:255.255.255.0,gw:192.168.1.254
WiFi: pm open,type:2 0

3. Load DuetWebControl in your browser.

4. If/when the wifi disconnects unexpectedly, look at the console on the PC to see whether any more debug messages have been displayed, and report what you find.

[zlowred]

Hi David,

So I was able to reproduce few more times. Here are my observations:

• (obvious one) I didn't see any debug messages including p->buf==1 while DWC page is not opened
• these p->buf==1 messages always (or most of the time) come out in pairs
• there are no regular intervals between these messages, sometimes I see few per second, sometimes I don't any for 10-15 minutes
• they are not getting more often before the disconnect
• I feel that messages are coming much more often when printer is printing (compared to the idle) - suspect it may be related to some timings, e.g. CPU is busy with something and can't send some command or data to the WiFi module in time. Or maybe noise in power line due to heaters PWM. My power supply is able to provide enough current, so it's not under-voltage, but maybe some noise…

I'll post here if I get more data

[dc42]

Thanks. Please can you install this DuetWiFiServer.bin file twice (the second time you can just send M997 S1 to install it again from the existing SD card file). It will provide a slightly more detailed debug message.

[zlowred]

Sure, will do. I wonder if there is anything of interest to you in the debug message showing when I do M552 S0 after such disconnect:

WiFi: state: 5 -> 0 (0)
WiFi: rm 0
WiFi: pm close 7
WiFi: tcp_pcb_purge: pcb->state == SYN_RCVD but tcp_listen_pcbs is NULL
Wifi module is idle
WiFi: tcp_pcb_purge: pcb->state == SYN_RCVD but tcp_listen_pcbs is NULL
WiFi: tcp_pcb_purge: pcb->state == SYN_RCVD but tcp_listen_pcbs is NULL
WiFi: del if0
WiFi: usl
WiFi: mode : null

Not sure if these pcb->state checks are ok

[dc42]

Yes, those are interesting too, in particular the tcp_pcb_purge messages.

[zlowred]

I did additional M997 S1 and then reproduced disconnect once again, but it didn't result in any additional messages in the log.

[dc42]

There shouldn't be additional messages, but some of the messages should have additional detail.

[zlowred]

I had to revert to 1.20beta6 for now because starting from 1.20beta7 it resets every now and then and I have lots of failed prints because of that. I'm still running the latest 1.20beta9 WiFi firmware though.