WiFi hangs on write() on busy SSL connection

[sterwill]

I think this related to our old friend #118, the firmware update having fixed the issue when plain TCP connections are used, but problems persist when an SSL connection is used. I did some quick testing with SSL when the fix for #118 was released, and I reported no problems, but recently I figured out that I just wasn't sending enough data out to trigger the issue.

Symptoms are similar to #118; write() on WiFiClient hangs for somewhere between seconds and forever depending on how much data is being sent and received at the same time. A sample sketch, atwinc1500_hang_ssl.ino, paired with a simple server program (see instructions in the sketch) usually reproduces the problem in less than 30 seconds.

A surprising thing that seems to hint at the underlying problem is that receive throughput is good when the client is sending very little to the server, but awful as it starts sending more (but still not very many) bytes each second. When BYTES_TO_WRITE is set to a small value, like 1, read throughput is between 49-65 KB/s and the connection doesn't hang.

I see similarly good read throughputs with BYTES_TO_WRITE set to values from 1-20. At 30, things start to get shaky. The speeds fluctuate between 1-50 KB/s and the connection often hangs for good around the 30 second mark. With BYTES_TO_WRITE at 100 it usually hangs withing 20 seconds. At 200 read throughput is awful (never breaking 2 KB/s), most calls to write() take a second or more to complete, and the connection hangs up permanently in under 20 seconds.

One positive aspect of this issue compared to #118 is that the scope of the hang seems to be the SSL connection or Wifi library. If the server closes the TCP connection, write() finishes and control does return to my program pretty quickly.

Here's the sketch's output with BYTES_TO_WRITE at to 200, showing very low throughput and a hang at around 3 seconds:

wifi...  connected
ssl...  connected
1: read 0 bytes/s, writing 200 bytes...  done.
2: read 1388 bytes/s, writing 200 bytes...  done.
3: read 1446 bytes/s, writing 200 bytes... 

pcap of the conversation is attached, showing the hang and me killing the server at the end and the connection being reset.

atwinc_1500_ssl.pcap.zip

[delcomp]

Try changing SOCKET_BUFFER_MTU (1446u) to (1500u) in socket_buffer.h.

[sterwill]

I tried 1500, then 2000, and it didn't seem to make any difference. My application (telnet over SSL) hangs after roughly the same amount of time either way.

[sandeepmistry]

Hi @sterwill,

So I just tried the sketch you provided on a MKR1000, here's the output:

started
wifi...  connected
ssl...  connected
1: read 0 bytes/s, writing 200 bytes...  done.
2: read 1351 bytes/s, writing 200 bytes...  done.
3: read 1446 bytes/s, writing 200 bytes...  done.
ssl...  connected
4: read 13587 bytes/s, writing 200 bytes...  done.
ssl...  connected
5: read 0 bytes/s, writing 200 bytes...  done.
6: read 0 bytes/s, writing 200 bytes...  done.
7: read 0 bytes/s, writing 200 bytes...  done.
8: read 0 bytes/s, writing 200 bytes...  done.
9: read 0 bytes/s, writing 200 bytes...  done.
10: read 0 bytes/s, writing 200 bytes...  done.
11: read 0 bytes/s, writing 200 bytes...  done.
12: read 0 bytes/s, writing 200 bytes...  done.
13: read 0 bytes/s, writing 200 bytes...  done.
14: read 0 bytes/s, writing 200 bytes...  done.
15: read 0 bytes/s, writing 200 bytes...  done.
16: read 0 bytes/s, writing 200 bytes...  done.
17: read 0 bytes/s, writing 200 bytes...  done.
18: read 0 bytes/s, writing 200 bytes...  done.
19: read 0 bytes/s, writing 200 bytes...  done.
20: read 0 bytes/s, writing 200 bytes...  done.
21: read 0 bytes/s, writing 200 bytes...  done.
22: read 0 bytes/s, writing 200 bytes... 

The last time keeps on repeating on my first attempt.

[sandeepmistry]

Another set of output from the second run:

started
wifi...  connected
ssl...  connected
1: read 0 bytes/s, writing 200 bytes...  done.
2: read 1351 bytes/s, writing 200 bytes...  done.
3: read 1446 bytes/s, writing 200 bytes...  done.
4: read 1446 bytes/s, writing 200 bytes...  done.
ssl...  connected
5: read 12141 bytes/s, writing 200 bytes...  done.
6: read 0 bytes/s, writing 200 bytes...  done.
7: read 0 bytes/s, writing 200 bytes...  done.
8: read 0 bytes/s, writing 200 bytes... 

Would you be able to setup a server so I can try on the same one as you? Also, it would be great if you can test the upcoming 19.5.4 WINC1500 firmware release. You can find a IDE build that contains an update WiFi101 updater here: arduino/Arduino#6840 (comment)

[sandeepmistry]

I'm closing this for now do to lack of feedback, please re-open with requested info if you are still interested.