Moved from Duet 0.6 to DuetWiFi - first impressions

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>

roboduet

I'm doing something wrong with update process or nothing changed.

I tried (two times) to upload your file [c]DuetWiFiServer.bin[/c] (md5 hash is [c]aa6290900e3021a8d7fa76bbd2c008b7[/c]) into /sys folder using "upload file(s)" button from settings menu in DWC , then I executed [c]M997 S1[/c] from DWC. After update progress is finished and DWC reconnected I tried to reload page in Chromium, but without success. DWC loading very slow. In Wireshark logs I see the same 200-ms delays. TCP PSH flag is also set in every TCP segment sent from Duet.

Is there any methods to view current WiFi Server firmware version/revision?

dc42

Hi roboduet,

I made a mistake with the changes to the last build. There were two templated write() functions and I only changed one of them. Please try the new version at https://dl.dropboxusercontent.com/u/19369680/DuetWiFiServer.bin. This one does speed up page loading for me.

The next version of DuetWiFiServer will report its version number. I added the support that this needs in the main firmware earlier today. For now I am trying to avoid making large changes to DuetWiFiServer until I have the Eclipse build working, because Arduino IDE is so un-productive compared to Eclipse.

roboduet

David, thank you very much! DWC is loading lightning fast now! About 5-6 seconds to full load!

Windows 7 is sending now ACK packets for every two received data-packets from Duet and without any delays.

Thank you!

dc42

roboduet, thanks for diagnosing the problem! The load and connect time for me has gone down from 10 to 2 seconds. But my printer is only about 1m from the router, so the wifi connection is about as good as it gets.

There are some other oddities showing up in Wireshark that are on my list to investigate, for example why does the ESP reset the TCP connection after each status poll.

roboduet

@dc42:

There are some other oddities showing up in Wireshark that are on my list to investigate, for example why does the ESP reset the TCP connection after each status poll.

Duet sends HTTP header field "Connection: close", so browser is closing connection as soon as full response from Duet is received. Browser sends FIN to Duet after last data packet from Duet received telling "I'm done sending data, waiting for your FIN". (FIN is sent by socket's [c]shutdown(socket, SHUT_WR)[/c] function.) Duet just resets connection (sending RST, socket's function [c]close(socket)[/c]) after receiving FIN flag from browser instead of sending FIN. It's so called "abortive close" described in section 4.2.2.13 of RFC 1122.