[BUG] Freed memory is being used #1110
Comments
|
Thanks for raising this bug. Tagging @shubnil and @tony-josi-aws for review |
|
@ATDOR-RIH |
|
@tony-josi-aws |
|
@ATDOR-RIH Thanks In your project, is the macro If so, could you please define it as 0?: |
|
I tried it with #define ipconfigTCP_HANG_PROTECTION ( 0 ). D:FreeRTOS_Sockets.c;1;173709;FreeRTOS_socket 0x702b5a60 |
|
Just wondering how its verified that I would try associating each socket creation with a random ID when created and then comparing the IDs when the socket pointers happen to match. |
|
@tony-josi-aws };` ulCreationTime is set in the function FreeRTOS_socket. FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c Line 759 in ee730aa I then added ulCreationTime to the logs I mentioned in the description above. First I tried it with ipconfigTCP_HANG_PROTECTION set to 1. (log_ipconfigTCP_HANG_PROTECTION_1.txt) D:FreeRTOS_Sockets.c;1;47391;FreeRTOS_socket 0x7030cdc8 47391 You can see that in the log line pxClientSocket = pxParentSocket->u.xTCP.pxPeerSocket; 0x0 0x70349180 2361 0x7030cdc8 0 ulCreationTime is 0. I assume that the memory was already taken by something else. I removed FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c Line 2175 in ee730aa D:FreeRTOS_Sockets.c;1;31698;FreeRTOS_socket 0x7033dab8 31698 Then I tried it with ipconfigTCP_HANG_PROTECTION set to 0. (log_ipconfigTCP_HANG_PROTECTION_0_do_not_free_memory.txt) D:FreeRTOS_Sockets.c;1;210483;FreeRTOS_socket 0x7034eca8 210483 Summary log_ipconfigTCP_HANG_PROTECTION_1.txt |
|
Hi @ATDOR-RIH, Data: Cycle 1: Cycle 2: Cycle 3: Cycle 4: Cycle 5: Observation 1:
There is less possibility for a to happen because of the following prints: Can you please confirm if point no b is not the case. Observation 2: Will it be ok for you to share the code with the above prints. This will help us better co-relate the print sequence and the code sequence. Thanks, |
|
I would like to propose the following change in FreeRTOS_printf( ( "vTCPStateChange: Closing socket\n" ) );
if( pxSocket->u.xTCP.bits.bReuseSocket == pdFALSE_UNSIGNED )
{
configASSERT( xIsCallingFromIPTask() != pdFALSE );
+
+ if( ( xParent != NULL ) &&
+ ( xParent->u.xTCP.pxPeerSocket == pxSocket ) )
+ {
+ xParent->u.xTCP.pxPeerSocket = NULL;
+ }
vSocketCloseNextTime( pxSocket );
}So we'll clear the field |
|
attached you will find the following files:
changes.patch The suggested changes do not solve the issue. I added this log "vSocketCloseNextTime xParent 0x7027b4d8 pxSocket 0x7027b4d8 0x0" right before the suggested changes. Regarding priorities: |
|
@ATDOR-RIH wrote:
Normally we recommend to use these priorities:
Tasks that have nothing to do with TCP/IP are free to choose a priority. I will comment |
|
Here are the extended logs: At timestamp 642815 the socket (created at timestamp 639023) is assigned as peer socket of the parent. Is it possible to set the peer socket of pxFound in xTCPCheckNewClient or is this a bad idea? |
|
When I look at your latest logs, I see lots of calls to Another thing: could you run the test while the application has a lower priority than |
|
Hi @ATDOR-RIH , |
|
I think vSocketCloseNextTime() is called because of a RST, but I am not sure. Changes:
pcap_and_changed_priorities.zip pcap_and_changed_priorities.zip contains the following folders and files:
folder contents:
Changing the priorities did not help. |
|
Thanks for these tests. This gives a new insight: the client (browser) manages to get a connection, and then immediately it is closing it. This lasts like 15 ms. Here is an example:
So it's not a timeout, it is not cause by an unexpected RST packet. The client is closing the connection immediately for some reason. I will think about this and come back to it. |
|
I made a simulation and get the same pattern of events:
When debug printf enabled, I see this logging: I made some extra logging in FreeRTOS_TCP_IP.c: if( ( eTCPState == eCLOSED ) ||
( eTCPState == eCLOSE_WAIT ) )
{
/* Socket goes to status eCLOSED because of a RST.
* When nobody owns the socket yet, delete it. */
FreeRTOS_printf( ( "vTCPStateChange: Closing socket (Queued %d, Accept %d Reuse %d)\n",
pxSocket->u.xTCP.bits.bPassQueued,
pxSocket->u.xTCP.bits.bPassAccept,
pxSocket->u.xTCP.bits.bReuseSocket ) );
...
}Would you mind to send me the same type of logging, i.e. by enabling the following in your FreeRTOSIPConfig.h : I can not replicate the problem. It would help to understand the order of events. EDIT : I'm one step further: when I delay the call to |
|
Hi @ATDOR-RIH, after attempts to reproduce your problem, here is a possible solution: Please merge them into you repo using a source compare program. It looks like it is possible that the field EDIT whereas I'm not claiming that all is solved, but I would be very curious if you can show the logging produced by the TCP/IP stack. |
|
Hi @htibosch, logs.zip contains three different logs.
|
|
There are too many differences between your and my source code. Please find my complete directory "source": except for the directory "portable". I tested this version with real hardware, and the problem looks "solved". Thanks for you patience and corporation, Hein |
|
Can you please point out where in the logfile you can see that freed memory is being accessed? |
|
This is from log1.txt. It is similar for the other log files. Here 0x703c7018 is set to be closed the next time in FreeRTOS_TCP_IP.c vTCPStateChange(FreeRTOS_Socket_t * pxSocket, enum eTCP_STATE eTCPState). 0x702e8920 is the parent of this socket.
Here the socket is closed.
Here 0x703c7018 is still the peer socket of 0x702e8920 and is accessed here: if( pxClientSocket->u.xTCP.bits.bPassAccept != pdFALSE_UNSIGNED ) in FreeRTOS_Sockets.c prvAcceptWaitClient(FreeRTOS_Socket_t * pxParentSocket, struct freertos_sockaddr * pxAddress, socklen_t * pxAddressLength)
pxClientSocket (0x703c7018) is already free when accessing pxClientSocket->u.xTCP.bits.bPassAccept. In this case the memory is still free and still has the correct value, but there is no guarantee that it does not get allocated and overwritten. |
|
How strange, both with your source and my sources, I can not replicate the problem you mention. As you know:
In your case, ``server->pxPeerSocket` doesn't get cleared. Please find a proposal to further investigate this: FreeRTOS_TCP_IP_hein.zip I added a function: It will iterate through all sockets to find a socket the is the parent of |
|
Hi @htibosch, server->pxPeerSocket doesn't get cleared because client->pxPeerSocket is NULL at some point when vSocketCloseNextTime is called. But this is already removed in the source I am using and it is still happening. I will try to find out where client->pxPeerSocket is set to NULL or if it is not set at all. But this might take some time. |
|
That is good news! |
|
Could it be that you do not have In that case, see FreeRTOS_TCP_State_Handling.c, around line 995 : BaseType_t prvTCPSocketCopy( FreeRTOS_Socket_t * pxNewSocket,
FreeRTOS_Socket_t * pxSocket )
{
...
#if ( ipconfigTCP_HANG_PROTECTION == 1 )
{
/* Only when there is anti-hanging protection, a socket may become an
* orphan temporarily. Once this socket is really connected, the owner of
* the server socket will be notified. */
/* When bPassQueued is true, the socket is an orphan until it gets
* connected. */
pxNewSocket->u.xTCP.bits.bPassQueued = pdTRUE_UNSIGNED;
pxNewSocket->u.xTCP.pxPeerSocket = pxSocket;
}
#else
{
/* A reference to the new socket may be stored and the socket is marked
* as 'passable'. */
/* When bPassAccept is true, this socket may be returned in a call to
* accept(). */
pxNewSocket->u.xTCP.bits.bPassAccept = pdTRUE_UNSIGNED;
+ /* Assign the parent 'pxSocket' to the child socket. */
+ pxNewSocket->u.xTCP.pxPeerSocket = pxSocket;
if( pxSocket->u.xTCP.pxPeerSocket == NULL )
{
pxSocket->u.xTCP.pxPeerSocket = pxNewSocket;
}
}
#endif /* if ( ipconfigTCP_HANG_PROTECTION == 1 ) */Could you test the above patch while disabling the new function Thanks |
|
Hi @htibosch, yes you are right. ipconfigTCP_HANG_PROTECTION is 0. logs.zip contains logs with ipconfigTCP_HANG_PROTECTION set to 1 for different versions.
With the version from March 26 the problem still exists with ipconfigTCP_HANG_PROTECTION set to 1. Thanks for your help |
Describe the bug
This bug releates to #570 which was solved in #707.
The bug was fixed by clearing pPassQueued and pPassAccept.
By calling
FreeRTOS-Plus-TCP/source/FreeRTOS_TCP_IP.c
Line 461 in ef14a08
and
FreeRTOS-Plus-TCP/source/FreeRTOS_IP_Timers.c
Line 309 in ef14a08
the socket gets freed, however the parent socket might still have a reference to the socket.
When the user task calls FreeRTOS_accept it will check if the pPassAccept bit is set. If not FreeRTOS_accept will return NULL and everything is fine.
But the memory is freed already, so there is no guarantee that pPassAccept is still cleared.
Target
Host
To Reproduce
The device acts as web server and the error happened by continuously refreshing the web site using https.
It did not happen when using http.
Expected behavior
Do not leave references to freed memory.
Screenshots
None
Wireshark logs
None
Additional context
Added log lines:
FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 761 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 1773 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 2019 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 2175 in ef14a08
if( pxParentSocket->u.xTCP.pxPeerSocket != NULL ) { logll_debug( BASE_FILE_NAME, "pxClientSocket = pxParentSocket->u.xTCP.pxPeerSocket; 0x%x 0x%x 0x%x", pxClientSocket, pxParentSocket, pxParentSocket->u.xTCP.pxPeerSocket ); }beforeFreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 3892 in ef14a08
if( pxParentSocket != NULL ) { logll_debug( BASE_FILE_NAME, "pxClientSocket = pxParentSocket; 0x%x 0x%x", pxClientSocket, pxParentSocket ); }beforeFreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 3896 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 3910 in ef14a08
if( pxClientSocket != NULL && pxClientSocket != FREERTOS_INVALID_SOCKET ) { logll_debug( BASE_FILE_NAME, "FreeRTOS_accept 0x%x 0x%x", pxSocket, pxClientSocket ); }beforeFreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 4059 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_Sockets.c
Line 4756 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_TCP_IP.c
Line 111 in ef14a08
else if( pxSocket != NULL ) { logll_debug( BASE_FILE_NAME, "vSocketCloseNextTime set xSocketToClose 0x%x 0x%x", xSocketToClose, pxSocket ); }afterFreeRTOS-Plus-TCP/source/FreeRTOS_TCP_IP.c
Line 112 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_TCP_IP.c
Line 325 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_TCP_IP.c
Line 345 in ef14a08
FreeRTOS-Plus-TCP/source/FreeRTOS_TCP_IP.c
Line 718 in ef14a08
logll_debug is a function which writes the given text to a serial interface which is connected to the computer used for debugging.
Format of the log line: (file name provided by macro BASE_FILE_NAME);(log level 1 in case of debug);(monotonic time in ms);(log message)
Log lines where the described bug happens:
Creation of socket.
D:FreeRTOS_Sockets.c;1;38081;FreeRTOS_socket 0x7035c548
D:FreeRTOS_TCP_IP.c;1;38113;xParent = pxSocket->u.xTCP.pxPeerSocket; 0x70284130 0x7035c548 0x70284130
D:FreeRTOS_TCP_IP.c;1;38113;xParent->u.xTCP.pxPeerSocket = pxSocket; 0x70284130 0x7035c548
IP-Task is closing the socket.
D:FreeRTOS_TCP_IP.c;1;38130;vSocketCloseNextTime set xSocketToClose 0x0 0x7035c548
D:FreeRTOS_Sockets.c;1;38130;vSocketClose 0x7035c548
D:FreeRTOS_TCP_IP.c;1;38130;vSocketCloseNextTime 0x7035c548 0x0
Call FreeRTOS_accept from user task. The memory was not overwritten yet, so prvAcceptWaitClient returns NULL.
D:FreeRTOS_Sockets.c;1;38706;pxClientSocket = pxParentSocket->u.xTCP.pxPeerSocket; 0x0 0x70284130 0x7035c548
Full logs
logs.txt
Config
ipconfig.txt
The text was updated successfully, but these errors were encountered: