Moved from Duet 0.6 to DuetWiFi - first impressions

roboduet

As for WiFi issues it seems for me that I was right then I said about TCP ACK delay problem with ESP8266 library that you used.

I used Wireshark to log packet data from and to ESP8266. I'm experiencing exactly the same problem with delayed TCP ACKs.

ESP8266 sends next TCP packet with small amount of data and blocks thread until TCP ACK received. On opposite side windows host receives next TCP packet with data, then waits for ~200 milliseconds and only then sends ACK packet on timeout because of TCP delayed acknowledgment

ESP8266 library problem description: https://github.com/esp8266/Arduino/issues/922

I can upload screenshot of Wireshark with this 200ms delays, but I don't understand how to attach picture to this post without uploading it to another sites.

drmpf created this issue in esp8266/Arduino

open Request Event Driven (non-blocking) WiFi socket API #922

dc42

I've just tested M84 followed by G28, and it always works for me. But I am running a beta of firmware 1.14.

Your log file shows a 9 second delay between sending the G28 and getting the error message. So I am guessing that the last G28 tried to home but failed, then the normal G1 command at the end of homedelta.g would provoke that message.

Are you by any chance using an unusual driver mapping, by including X Y Z or E parameters in some of your M569 commands? I think I may have spotted a bug in 1.13 and earlier in those circumstances.

roboduet

No, I'm not using non-standard driver mapping and so on. I have 3 drives connected to X, Y, Z and extruder drive connected to E0.

Can it be that M84 disables steppers and then G28 tries to home without enabling them again?

UPD: Maybe this can help: I'm using this firmware instead of 1.13b because of "effector dance": https://www.duet3d.com/forum/thread.php?pid=260#p260

dc42

It must be something like G28 not enabling the motors, or enabling them at the idle current instead of full current.

Please can you try version 1.14 beta 2 at https://dl.dropboxusercontent.com/u/19369680/DuetWiFiFirmware-1.14b2.bin - but be ready to hit the power switch if anything goes wrong. I've only done one print with it so far.

roboduet

Thank you, 1.14b2 fixed M84+G28 bug for me.

Should I stay on 1.14b2 or revert firmware back to 1.14b1 until 1.14 released?

Have you seen my post about WiFi TCP ACKs?

dc42

I have just found a big in 1.14b2, it sets the wrong motor currents. So please revert to 1.14b1 until I have tested 1.14b3.

roboduet

Oh… I'm printing now with 1.14b2 and my motors are very hot. Is it possible to change currents without stopping print?

dc42

I did see your comment about TCP ACKs. I made some substantial changes to the Arduino ESP8266 http server code, pending the complete rewrite that I mean to do, to get a decent performance out of it. The underlying TCP/IP stack is Lwip, the same as we use on the wired Duet. So I don't think there is an issue with delayed ACKs, but it will be interesting to see what your Wireshark trace reveals.

roboduet

About ACK delays: 192.168.0.2 is my windows7 pc, connected by ethernet directly to my router. 192.168.0.28 is DuetWiFi beta board, connected to the same router.
I added "Delta time" column - it's time difference between this and previous packet. As you can see, windows delays sending ACK's up to 200 milliseconds almost after every packet received from duet.

roboduet

File upload process:

roboduet

Example of Wireshark logs for the same main page (GET /) for Replikeo's Duet 0.6 with 1.09r-dc42 firmware. No delays at all. Board connected to the same router as DuetWiFi. I'm using the same W7 PC.

DWC loads very fast.

dc42

It does appear to be the case that the Duet WiFi is waiting to receive the ACK for a packet before it sends the next one. Whereas on the Duet, it's quite happy to send two packets without waiting for the first one to be acknowledged. Perhaps Lwip has been configured differently.

One of the items on my firmware list is to do a total rewrite of the web server and its interface to Lwip. I'll probably base it on the code we use in the wired Duet. I'll look at the effect of delayed ACKs when I do that.

roboduet

David, is the source code for the Duet's WiFi module (DuetWiFiServer.bin) available for download?

dc42

The code is in my github repos CoreESP8266 and DuetWiFiServer. But I don't have it building correctly under Eclipse yet

roboduet

Thank you for making your source code freely available : )

I'm not very familiar with ESP8266 programming, but it seems for me that call stack looks very close to this:

Web Server calls [c]RepRapWebServer::send()[/c] to send page contents to connected client
Function above calls [c]RepRapWebServer::sendContent()[/c]
Function above calls [c]WiFiClient::write()[/c]
And function above calls [c]ClientContext::write()[/c]. This function uses [c]delay()[/c] call to wait for TCP ACK received:

[[language]]
				if (last || will_send == room)
				{
					DEBUGV(":wr\r\n");
					tcp_output( _pcb );
					_send_waiting = true;
					delay(5000); // max send timeout
					_send_waiting = false;
					DEBUGV(":ww\r\n");
				}

There is a lot of complains about this behavior as I said before:

https://github.com/esp8266/Arduino/issues/922
https://github.com/esp8266/Arduino/issues/1027
https://github.com/esp8266/Arduino/issues/1430
https://github.com/esp8266/Arduino/issues/1577

And so on.

drmpf created this issue in esp8266/Arduino

open Request Event Driven (non-blocking) WiFi socket API #922

rogerclarkmelbourne created this issue in esp8266/Arduino

closed Slow performance of FSBrowser on Chrome and Firefox #1027

nouser2013 created this issue in esp8266/Arduino

closed Again: TCP server performance completely unuseful #1430

nouser2013 created this issue in esp8266/Arduino

closed Tracking down that darn "delayed ACK" (200ms) bug... #1577

GBCues

It is a little known fallacy with WiFi that a stronger signal always makes a better connection.
Try tuning your Access Point down so that your Duet only sees -60 to -72. What happens is that the AP is "shouting" so loud that it can't "hear" the Duet talking back. This is a common problem in business WiFi with Apple products. The Apple products are designed with a low output strength to conserve battery strength.
This is an easy fix and may explain why you and DC42 are not seeing the same behavior.
Of course, it may not, but it's worth a try.

roboduet

@GBCues:

It is a little known fallacy with WiFi that a stronger signal always makes a better connection.

You are right, sometimes bigger is not better (for example I had such problems with Nordic's NRF24L01 transmitters with power amplifier), but not in this case. Just because problem source is in another place.

dc42

@roboduet:

Thank you for making your source code freely available : )

I'm not very familiar with ESP8266 programming, but it seems for me that call stack looks very close to this:

Web Server calls [c]RepRapWebServer::send()[/c] to send page contents to connected client

Function above calls [c]RepRapWebServer::sendContent()[/c]

Function above calls [c]WiFiClient::write()[/c]

And function above calls [c]ClientContext::write()[/c]. This function uses [c]delay()[/c] call to wait for TCP ACK received:
[[language]]
				if (last || will_send == room)
				{
					DEBUGV(":wr\r\n");
					tcp_output( _pcb );
					_send_waiting = true;
					delay(5000); // max send timeout
					_send_waiting = false;
					DEBUGV(":ww\r\n");
				}
There is a lot of complains about this behavior as I said before:

https://github.com/esp8266/Arduino/issues/922
https://github.com/esp8266/Arduino/issues/1027
https://github.com/esp8266/Arduino/issues/1430
https://github.com/esp8266/Arduino/issues/1577

And so on.

If you take a look at the original Arduino library code, you will see that I have changed it by adding the if-condition. Before I made that change, the server was very slow indeed. What the condition does is to wait for ACK only when either the last packet has just been sent, or there is no more room in the send buffers. If it is still waiting too often even with that change, then that suggests to me that Lwip has been configured with too small a transmit buffer size for the transmit window size.

roboduet

David, I'm sorry that I disturb you on such minor troubles that only few people experiencing (WiFi is quite usable even for me), but my curiosity will not let me rest.

I noticed that TCP PSH flag is set almost for every TCP segment outgoing from Duet WiFi. This means that both [c]last[/c] var is set to [c]true[/c] and last segment is sending now according to [c](last && will_send == size) ? TCP_WRITE_FLAG_COPY : TCP_WRITE_FLAG_COPY | TCP_WRITE_FLAG_MORE[/c] code from [c]ClientContext::write()[/c] function.

Then I realized that I was wrong about call stack that I previously posted. As browser requests static files, [c]StaticRequestHandler::handle()[/c] should be called, then [c]RepRapWebServer::streamFile()[/c] should be called and then [c]WiFiClient::write()[/c] template function should be called.

[c]WiFiClient::write()[/c] template function splits file by [c]WIFICLIENT_MAX_PACKET_SIZE[/c] byte chunks (1460 bytes, exactly as in Wireshark), and sends every chunk using [c]write(obuf, WIFICLIENT_MAX_PACKET_SIZE)[/c] call which translates to [c]size_t write(const uint8_t *buf, size_t size) { return write(buf, size, true); }[/c] from ClientContext class.

So [c]write()[/c] function from [c]ClientContext[/c] is called for every chunk of data with [c]last[/c] flag is set to [c]true[/c].

That's why code waits for TCP ACK flag for every 1460 bytes sent as in Wireshark logs.

I think correctly, or I made a mistake somewhere?

dc42

roboduet, I think you are right, I overlooked the write() calls in 'template <typename t="">size_t write(T &src)' in file WiFiClient.h. I have now corrected that to pass the 'last' flag as true on just the last fragment, and put a new binary at https://dl.dropboxusercontent.com/u/19369680/DuetWiFiServer.bin. However, if it is any faster than the old version, then the difference is small, because it still takes 10 seconds to load and connect on my system.</typename>