I’m developing my first project with FreeRTOS TCP+ and coreHTTP.
I’m using FreeRTOS LTS version with STM32H7 network driver.
I’m facing a strange problem. When I try to send some HTTP request to an active connection, I’m getting connection reset from server (Apache on Ubuntu).
I have found interesting things with Wireshark - FreeRTOS TCP sends HTTP request with an active SYN flag, after connection is already established. I think this is causeing server to reset connection.
EDIT:
I have attached Wireshark file and my HTTP client + slightly modified transport layer source files.
Thank you, Richard! I made attachments.
I also made a raw TCP connection and sent some data. The result was the same, so I think coreHTTP library works fine. I also noticed that web server sends two SYN-ACK packets as response to SYN. Can this somehow “confuse” TCP stack?
Other clients (curl, web browsers, some devices) work fine with this server.
It seems to me that the repeated SYN+ACK from the server might be causing an issue as you correctly pointed out.
Would you mind enabling the debug messages by setting the macro ipconfigHAS_DEBUG_PRINTF in FreeRTOSIPConfig.h present in your project? It would help us debug the issue faster.
Additionally, would you mind adding the following lines here:
EDIT:
A bit more explanation for the next person looking for this.
The FreeRTOS+TCP stack copies the last packet it received on a socket so that it can reuse the TCP packet header directly without much effort while sending the packet back to the peer. Generally, this works fine since the server doesn’t send a SYN-ACK packet again and the code goes on a merry path to sending an ACK and making the connection.
In this case, however, what is happening is that by the time when the server sends the SYN-ACK again, the FreeRTOS+TCP stack has marked the connection as established. The stack stores the SYN/ACK packet to be reused and discards it. Now, when it is time to send data (the HTTP packet), the TCP stack reuses the last packet it received (the one with SYN-ACK) to send data back to the server. And that is where the problem starts. The SYN flag is not reset and that makes the server unhappy.
The work around that I propose above removes the SYN flag unconditionally when the socket has gone beyond the eESTABLISHED state - since the SYN flag should not be set anyways.
A point to note though: This is an extremely weird corner case. It doesn’t happen often. We shall create a PR in the repository to fix this issue.
Looks that your suggestion did the trick. Now I can get normal communication. The server still send repeated SYN+ACK packets ( I have no idea why), but now they are just ignored and the next packet with HTTP request is correct.
Is it safe to use this workaround and continue on my project?
This is debugging log before:
prvIPTask started
PHY ID 7C130
xPhyReset: phyBMCR_RESET 0 ready
+TCP: advertise: 01E1 config 3100
prvEthernetUpdateConfig: LS mask 00 Force 1
Autonego ready: 00000004: full duplex 100 mbit high status
Network buffers: 56 lowest 56
Link Status is high
prvInitialiseDHCP: start after 250 ticks
vDHCPProcess: discover
Network buffers: 56 lowest 55
vDHCPProcess: discover
vDHCPProcess: timeout 10000 ticks
vDHCPProcess: offer c0a858feip
vDHCPProcess: reply c0a858feip
vDHCPProcess: offer c0a858feip
vDHCPProcess: acked c0a858feip
prvProcessDNSCache: add: 'ntp.dtg.lv' @ 5b871f04ip
DNS[0x6AB3]: The answer to 'ntp.dtg.lv' (91.135.31.4) will be stored
[DEBUG] [HTTP-Transport] [HTTP_TransportConnect:37] Created new TCP socket.
[DEBUG] [HTTP-Transport] [HTTP_TransportConnect:63] Creating TCP Connection to 192.168.18.35.
FreeRTOS_connect: 40037 to c0a81223ip:3002
Socket 40037 -> c0a81223ip:3002 State eCLOSED->eCONNECT_SYN
prvSocketSetMSS: 1400 bytes for c0a81223ip:3002
prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
Connect[c0a81223ip:3002]: next timeout 1: 3000 ms
Heap: current 58408 lowest 58408
RX descriptors 2/4
Network buffers: 54 lowest 54
MSS change 1400 -> 1460
TCP: active 40037 => c0a81223ip:3002 set ESTAB (scaling 1)
Socket 40037 -> c0a81223ip:3002 State eCONNECT_SYN->eESTABLISHED
MSS change 1400 -> 1460
[INFO] [HTTP-Transport] [HTTP_TransportConnect:70] Established TCP connection with 192.168.18.35.
TCP: RST received from c0a81223ip:3002 for 40037
Socket 40037 -> c0a81223ip:3002 State eESTABLISHED->eCLOSED
TCP: No active socket on port 40037 (c0a81223ip:3002)
[INFO] [HTTP] [HTTPClientTask:136] KEEP ALIVE - NETWORK ERROR, DISCONNECTING
FreeRTOS_closesocket[40037 to c0a81223ip:3002]: buffers 56 socks 0
This is debugging log after:
prvIPTask started
PHY ID 7C130
xPhyReset: phyBMCR_RESET 0 ready
+TCP: advertise: 01E1 config 3100
prvEthernetUpdateConfig: LS mask 00 Force 1
Autonego ready: 00000004: full duplex 100 mbit high status
Network buffers: 56 lowest 56
Link Status is high
prvInitialiseDHCP: start after 250 ticks
vDHCPProcess: discover
Network buffers: 56 lowest 55
vDHCPProcess: discover
vDHCPProcess: timeout 10000 ticks
vDHCPProcess: offer c0a858feip
vDHCPProcess: reply c0a858feip
vDHCPProcess: offer c0a858feip
vDHCPProcess: acked c0a858feip
prvProcessDNSCache: add: 'ntp.dtg.lv' @ 5b871f04ip
DNS[0x8681]: The answer to 'ntp.dtg.lv' (91.135.31.4) will be stored
[DEBUG] [HTTP-Transport] [HTTP_TransportConnect:37] Created new TCP socket.
[DEBUG] [HTTP-Transport] [HTTP_TransportConnect:63] Creating TCP Connection to 192.168.18.35.
FreeRTOS_connect: 35735 to c0a81223ip:3002
Socket 35735 -> c0a81223ip:3002 State eCLOSED->eCONNECT_SYN
prvSocketSetMSS: 1400 bytes for c0a81223ip:3002
prvWinScaleFactor: uxRxWinSize 1 MSS 1400 Factor 0
Connect[c0a81223ip:3002]: next timeout 1: 3000 ms
Heap: current 58400 lowest 58400
RX descriptors 2/4
Network buffers: 54 lowest 54
MSS change 1400 -> 1460
TCP: active 35735 => c0a81223ip:3002 set ESTAB (scaling 1)
Socket 35735 -> c0a81223ip:3002 State eCONNECT_SYN->eESTABLISHED
MSS change 1400 -> 1460
[INFO] [HTTP-Transport] [HTTP_TransportConnect:70] Established TCP connection with 192.168.18.35.
[INFO] [HTTP] [HTTPClientTask:128] KEEP ALIVE response 200 OK
[INFO] [HTTP] [HTTPClientTask:128] KEEP ALIVE response 200 OK
[INFO] [HTTP] [HTTPClientTask:128] KEEP ALIVE response 200 OK
I also attached Wireshark trace with working connection: fixed_connection.zip (2.0 KB)
@janis.barscausks : thank you very much for taking the effort to report this problem.
@kanherea : thank you also for providing a quick hack. That indeed prevents the problem form occurring.
I am still very curious why a server would send a SYN+ACK response two times. I assume that that causes the problem.
I tried to simulate you problem by feeding this particular SYN+ACK response two times to the device. Unfortunately I can not replicate it.
But is is late now, tomorrow I will give it a new try.
Hello @janis.barscausks, I am glad that the work-around worked for you!
I was trying to think of a scenario where the SYN packet should be sent but the connection state is >= eESTABLISHED. I could not. Neither could I find anything over the internet about the same.
Thus, I would like to go out on a limb and say that this should not cause a problem and you should be able to use this in your project.
@htibosch, as always, thank you for your efforts. What do you think about the statement that I made above about this “hack” being safe? It is always better to have 2 sets of eyes than 1.
Hello, I just produced PR #279 to solve this problem: “When storing the last TCP packet, clear the TCP flags”
It is very similar to Aniruddha’s solution, except that it acts earlier, at the moment the received TCP header is stored. It will clear all TCP flags except the ACK.
The only TCP packet without an ACK is the very first one: the SYN packet.
I totally agree with Aniruddha’s analysis.
And Janis, thanks for your clear report on this. If you like you can try the change in the PR.
