This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

CC3220MODA: HTTPClient_readResponseBody Delay over Port 443

Part Number: CC3220MODA

We have designed a product with the CC3220SFMODA that awakes from hibernation, makes a connection to the AP, then sends a request to our Server.  The Server responds with a payload of about 1KB or so, then the device returns to hibernation.  We are able to complete this transaction over Port 80, 8443, and 443 as part of our testing, although we prefer use of Port 443.  

We notice that when Port 443 is used the response packets from the Server are delayed, so our code hangs in HTTPClient_readResponseBody waiting for it to return.  This does not happen when Port 80 or 8443 used.  We secure Port 443 and 8443 with the same certificate.  

Wireshark Trace Port 8443 (“normal” case):

Reference 2636/2637, the responses from the Server on .208 are back to back.  Our unit hibernates again at the end which I think is responsible for the TCP Retransmissions.  Ultimately the entire process is completed in about 3 seconds, and while I see the real delay with the FIN, ACK from the CC3220, this has not been an area of focus.  



Wireshark Trace Port 443 (problem case):



The problem here is the time between line 271 and 514 for the delivery of two transfers from the Server on .208.  We can see from the serial debug that the expected server response is returned by HTTPClient_readResponseBody from line 271 and the code just sits waiting for the function to return after calling again because moreDataFlag is not clear. When this returns there is no additional data from the function so we do not understand what we are waiting for.  This is really a symptom of how the data comes back from the Server, and we are trying to figure out why operation on Port 443 would cause it to operate differently.  We have other software products that when connected to the same Server over Port 443 do not have this anomaly.

Application Code:

We followed the example code recommendation to continue calling HTTPClient_readResponseBody until moreDataFlag is clear.  The first call returns the message content we are expecting, the second call processes the remainder that is sent from the Server.

Code portion w/debug statements:

    len = 0;

    int rOnce = 0;

    do

    {

        Display_printf(display, 0, 0, "do loop start, Reading readResponse \r\n");

        ret = HTTPClient_readResponseBody(httpClientHandle, data, sizeof(data),

                                          &moreDataFlag);

        Display_printf(display, 0, 0, "Read Response Done \r\n");

        if(ret > 0){

            //Loop has read at least once

            rOnce = 1;

            Display_printf(display, 0, 0, "rOnce \r\n");

        }

        //True if read response returned data at least once in this loop AND current loop is 0

        if(rOnce && ret == 0){

            //First 2 elements of data array are overwritten with garbage data for some reason

            //Manually fix the issue here

            data[0] = '{';

            data[1] = 0x22; // double quote in ascii

            Display_printf(display, 0, 0, "Manual Fix \r\n");

        }

        if(ret < 0)

        {

            printError("httpTask: response body processing failed", ret);

        }

        Display_printf(display, 0, 0, "DISPLAY PRINT: %.*s END LINE \r\n",ret,data);

        len += ret;

        Display_printf(display, 0, 0, "DISPLAY PRINT DONE LEN = %d  \r\n",len);

        Display_printf(display, 0, 0, "moreDataFlag = %d  \r\n",moreDataFlag);

    }

    while(moreDataFlag);

Serial output during runtime on Port 8443:

do loop start, Reading readResponse

Read Response Done

rOnce

Manual Fix

DISPLAY PRINT: {"message":"Success","enabled":true,"heartbeatSchedule":{"sunday":["10","20","13","16"],"monday":["10","20","19","6"],"tuesday":["10","20","13","16"],"wednesday":["0","8","19","16"],"thursday":["10","13","19","6"],"friday":["10","0","19","16"],"saturday":["10","8","19","6"]},"returnCode":"200","serverTime":"2022-11-15T10:48:31.638-0500"} END LINE

DISPLAY PRINT DONE LEN = 339

moreDataFlag = 1

do loop start, Reading readResponse

Read Response Done

Manual Fix

DISPLAY PRINT:  END LINE

DISPLAY PRINT DONE LEN = 339

moreDataFlag = 0

Serial output during runtime on Port 443:

do loop start, Reading readResponse

Read Response Done

rOnce

Manual Fix

DISPLAY PRINT: {"message":"Success","enabled":true,"heartbeatSchedule":{"sunday":["10","20","13","16"],"monday":["10","20","19","6"],"tuesday":["10","20","13","16"],"wednesday":["0","8","19","16"],"thursday":["10","13","19","6"],"friday":["10","0","19","16"],"saturday":["10","8","19","6"]},"returnCode":"200","serverTime":"2022-11-15T11:31:04.718-0500"} END LINE

DISPLAY PRINT DONE LEN = 339

moreDataFlag = 1

do loop start, Reading readResponse

Read Response Done

Manual Fix

DISPLAY PRINT:  END LINE

DISPLAY PRINT DONE LEN = 339

moreDataFlag = 0

Tool Versions:

Simplelink Version: 4.40.0.07

Compiler Version: TI v20.2.7.LTS

XDCtools Version: 3.62.1.14_core



Any thoughts on what we can do to address this situation are appreciated.

  • Hi,

    Maybe I am missing something here but it seems that the output is identical for both cases. Is this expected?

    second, the printouts and flow do not make sense. I expect that on the first round ret>0 so rOnce is flagged, hence, "rOnce" printout is shown and "Manual Fix" is not shown (since ret is not 0) but I see it is printed. Can you explain? can you print ret since I do not see it when you tried to print it.

    Regardless, you test for rOnce  in the loop without zeroing it out for each cycle (so it remains 1 once flagged).

    Regards,

    Shlomi

  • Hi Shlomi, let me clarify.  When the loop enters the second time because moreDataFlag = 1 when using Port 443 we see a significant gap between the print of these 2 lines :

    do loop start, Reading readResponse

    Read Response Done

    When we reviewed the Wireshark it lined up with the delayed second packet response from our Server.  We are trying to understand why this second 'chunk' is delayed in this case and not at all when using Port 8443. 

    To answer your second question, "Manual Fix" is printed after rOnce is set AND HTTPClient_readResponseBody returns a 0 which only happens after this second iteration of the loop.  rOnce is just a flag we use to detect we have received something and the code that prints "Manual Fix" is used to detect when we think everything received.

    The issue here really is about the speed of the transaction on Port 8443 vs Port 443 using the exact same code.

    Does this help clarify?

  • Hi,

    It is clear now, thanks.

    So the client seems to behave OK since in both cases it gets the moreFlag and as expected call to read another chunk. However, in case of port 443, the server for some reason is deferred and it takes ~5 seconds for it to response. Looking at the TCP frame prior to this gap, seems like the client sends TCP ACK, acknowledging 6817 bytes. Just before it, the server sent sequence 5601 with packet of aggregated length of 1270 bytes (including headers) so if I do the calculation it becomes 5601+1270 - 20 (TCP header) - 20 (IP header) - 14 (encryption) = 6817!

    So the client seems to behave correctly. Does this happen with other HTTP server as well? does this happen in non-encrypted sessions as well? what server are you using?

    Regards,

    Shlomi

  • The Server is a company software product in use for many years, it is not new.  We have other SW Clients that perform similar periodic connection and I do not see this delay in their transfers on either Port 443 or 8443.  

    As far as this issue is concerned you can see in the Wireshark I included of the same transfer over Port 8443, we do not see the delay in this case nor when using Port 80.  This device is not designed to connect to any other Server since the protocol is very custom.  

    I realize we are focused on the receive data end of the transfer, but could there be something on the initiation that creates this symptom?  The fact that this happens on EVERY transfer over Port 443 on all instances of our Server we have tested, even ones that are not serving any other loads suggests it is not a resource issue to me.  

    Did you compare the 8443 transfer to the 443 transfer?  Maybe you can spot something we aren't noticing.

    Thanks

  • Hi,

    Just from the snapshot it is hard to see anything.

    The TCP windows and stream looks OK.

    Are you able to see logs on the server side to understand more?

    Regards,

    Shlomi

  • We are checking the Server side.

  • OK, let me know when you have some concrete feedback.