Can't receive the data larger than 1447 bytes in Websocket(tls mode)?

[gechc_1843576]

Hi. I use the websocket library in WICED SDK 4.1.1, and I tried to use it to read larger websocket data(>=1447 bytes). Unfortunately, it failed to read the larger data.

I tried to trace the library code, and I found that there is a "tls_get_next_record_failed" in wiced_tls_receive_packet(wiced_tls.c).

Do you have any suggestions for this issue?

[DaBa_2244756]

Hi,

I have similar problem. I noticed that one off possible cause is too small dynamic memory.

How much memory you have on your system?

But possible more cause.

What error code return tls_get_next_record?

Maybe it "RECORD_OVERFLOW" //0x13b7   ?

BR

Darius

[gechc_1843576]

My error code is 2 in tls_get_next_record (timeout?).

It seems like the tcp fragmentation handling has some problems? 

[gechc_1843576]

sbrk heap size:     185108

sbrk current free:  118776

malloc allocated:    52484

malloc free:         13848

total free memory:  132624

This is my current memory usage.

[GauravS_31]

Can you check if you are facing this problem in WICED 5.0.1?

[gechc_1843576]

I also found "tcp_reply_packet" will be NULL when this situation happens, and the following code in websocket.c will delete the NULL pointer to make the system crash.

[DaBa_2244756]

It seems to me, that need insert additional check code exmp.:

    /* Unpack websocket frame */

    while ( read_state != ( READ_COMPLETED_SUCCESSFULLY ) || ( read_state == READ_FRAME_ERROR ) )

    {

        tcp_reply_packet=NULL;

        result = wiced_tcp_receive( &websocket->socket, &tcp_reply_packet, WICED_NO_WAIT );

        if ( result != WICED_SUCCESS )

.....................

     if( NULL != tcp_reply_packet )

          wiced_packet_delete( tcp_reply_packet );

But this maybe help avoid side effect.

BR

Darius

[gechc_1843576]

HI, Darius.

Thank you. I know this issue, so I also added the if statement in the websocket.c.

It can avoid system crashing, but it still can't receive huge websocket data.

Gene.

[DaBa_2244756]

Ok,

I have some additional investigation on this problem. I some debugging tls_get_next_record. I using sdk 3.7.0.

Currently I cant test with sdk 5, because my system memory limited. Tls used 16kb chunk size for big data and maybe additional 16kb buffer for decode.  Tls standard say, that chunk size possible change from 512byte to 128kb, but not all servers support it. Openssl only 16kb.

Second:

tls_get_next_record  internally using tls_host_get_packet_data ->  wiced_packet_get_data.

I was reported about  wiced_packet_get_data her: Re: Incorrectly using wiced_packet_get_data return params

I using freeRtos-LWIP, which using chained buffs.  I think, that with   wiced_packet_get_data    function difficult work with chained buffs.

Sdk 4 not support freeRtos, so how working tread_x  i don't known. If it have chained buffs, then maybe problem in wiced_packet_get_data.

Maybe wiced team can open tls_get_next_record  function code, that better understudy problem? grsr​

BR.

Darius

[gechc_1843576]

I use ThreadX in Wiced SDK 4.1.1, so it seems this problem is not in the old version or freertos/lwip.

[gechc_1843576]

I use ThreadX in Wiced SDK 4.1.1, so it seems this problem is not only in the old version or freertos/lwip.

Maybe WICED team should give us more information about this function.

[GauravS_31]

Please share your WICED application code so that we can reproduce this issue.

[gechc_1843576]

Hi, the part of the code is this function:

int

    websocket_wrapper_receive(  ws_context_t *context,

                                                      char *msg,

                                                      size_t msgBufferSize)

{

    wiced_result_t result = WICED_ERROR;

    wiced_websocket_initialise_rx_frame(&context->rxFrame,

                                                                 (void *)msg,

                                                                 msgBufferSize);

    if((result = wiced_websocket_receive(&context->ws, &context->rxFrame)) != WICED_SUCCESS)

    {

        on_close((void *)&context->ws);

        return 0;

    }

    return context->rxFrame.payload_length;

}

I think you can try to reproduce the situation by setting up a wss server.

Then, use this server to send a huge message to the wss client.

[DaBa_2244756]

Hi Gene,

Can you insert debug code in wiced function and sent log output:

tls_result_t tls_host_get_packet_data( ssl_context* ssl, tls_packet_t* packet, uint32_t offset, uint8_t** data, uint16_t* data_length, uint16_t* available_data_length )

{

    uint16_t temp_length;

    uint16_t temp_available_length;

    if ( packet == NULL )

    {

        return TLS_ERROR_BAD_INPUT_DATA;

    }

    if ( ssl->transport_protocol == TLS_TCP_TRANSPORT )

    {

        wiced_result_t result = wiced_packet_get_data((wiced_packet_t*)packet, (uint16_t)offset, data, &temp_length, &temp_available_length);

printf("TLS info: result: %d offset: %u chunk_length: %u available: %u\n",result,offset,temp_length,temp_available_length);

        if ( result != WICED_SUCCESS)

        {

            return (tls_result_t) result;

        }

        *data_length = temp_length;

        *available_data_length = temp_available_length;

        return TLS_SUCCESS;

    }

................

[gechc_1843576]

Hi, there are logs when wss error happened:

TLS info: result: 0 offset: 0 chunk_length: 1432 available: 1432

TLS info: result: 0 offset: 0 chunk_length: 35 available: 35

another error log:

TLS info: result: 0 offset: 0 chunk_length: 1432 available: 1432

TLS info: result: 0 offset: 33 chunk_length: 1399 available: 1399

If the message is smaller, the log will look like this:

TLS info: result: 0 offset: 0 chunk_length: 1186 available: 1186

TLS info: result: 0 offset: 33 chunk_length: 1153 available: 1153

TLS info: result: 4 offset: 1186 chunk_length: 23216 available: 8193

there are no error happened.

[DaBa_2244756]

Hi Gene,

Currently, I dont have ideas.

Looks, that  internal wiced code waiting additional data. (so timeout). At smaller message, we see

TLS info: result: 4 offset: 1186 chunk_length: 23216 available: 8193

Code get result 4 (because packet data length and offset same size), and it exit success.

But if you can, repeat test with this debug string to detect different packets.

printf("TLS info: result: %d offset: %u chunk_length: %u available: %u  packet_addr: %p\n",result,offset,temp_length,temp_available_length,(void*)packet);

BR

Darius

[GauravS_31]

I configured two WICED devices as websocket server and websocket client. In snip websocket_server.c, I increased the characters in char tx_buffer[] and found that it could send up to 1371 bytes to the client with TLS enabled. Beyond that, I could not send. The error code 5 is received in the function on_error_websocket_callback() in websocket_client.c which means WEBSOCKET_FRAME_SEND_ERROR. I will talk to our engineer and continue to investigate. May I know which device was configured as websocket server and which device was configured as websocket client in your setup?

[gechc_1843576]

Hi, I use Ampak AP72438 wifi module as websocket client, and the websocket server is the service in our company's cloud.

[gechc_1843576]

Hi grsr, any update for this issue?

[GauravS_31]

This is still in progress. We have traced the problem to tls_get_next_record_failed. We will probe further to find the problem. I will keep you updated. I believe there are length and fragmentation limitations but I need to confirm the same with the engineers.

[Anonymous]

WICED websockets doesn't appear to work with fragmented TCP packets.  This is, incidentally, a known issue with HTTP on WICED.  So it's no suprise it's also an issue with Websockets.

Like many IEEE 802 devices, WICED uses an MTU of 1500 bytes.  Your observed payload size limitations are dependent on this figure.  Because it doesn't support fragmentation, you have this problem where you'll need to deal with fragmentation in the application layer.  If you review the websocket code, it's clear that it can do only one frame per packet -- no fragmented frames.

[gechc_1843576]

So, it means I can't use Wiced websocket to transfer larger data?

I know the comment in the websocket header, but I thinked it means websocket fragmentation before.

Does Cypress have any plan to improve this issue? Or, just tell the customer don't use your chip to transfer lager data?

[DaBa_2244756]

Wiced team found bug. So need wait.

At current situation I do not see fragmentation problem, because

chunk_length: 1432 available: 1432 have same length.

Fragmentation can occur, but not now.

To avoid "fragmentation" maybe possible using 1 chained rx buff length.

......

Hi, there are logs when wss error happened:

TLS info: result: 0 offset: 0 chunk_length: 1432 available: 1432

TLS info: result: 0 offset: 0 chunk_length: 35 available: 35

...

BR.

Darius

[gechc_1843576]

OK. Wait for Cypress team's official response.

[Anonymous]

Do you have some information about this bug?  I can show Wireshark logs, where after trying to handle TCP segmentation in Websockets retries, the entire IP networking stack of WICED goes down.

This seems like a bug at layer 4 (TCP).

Websocket implementation, though, is defined.  It is defined to have FIN bit set for each frame, so transfer of large data over websockets must be handled by the user application.  On systems with 128KB RAM, common to use with WICED, it is unreasonable to expect a large file buffer. 

[DaBa_2244756]

You can try disable TLS like her:

Snip.websocket_client worked without TLS but doens't work with TLS

Then test your code.

If your code working ok without TLS, then problem not in tcp layer.

BR.

Darius

[Anonymous]

No, it fails with or without TLS.

[GauravS_31]

genecheng_1843576​

I discussed with the engineer. Currently there is an MTU size limitation of 1500 bytes. I have raised a ticket internally on this. I will update this thread once I receive feedback.

jp.norair_2304996​

Can you share the Wireshark logs containing the failure? How many bytes are you trying to send from websocket server to client (or vice versa) without TLS? It will be helpful if you could share a sample code on this issue.

[gechc_1843576]

OK. Thank you.

[AxLi_1746341]

Any update for the fix?

[GauravS_31]

No updates. I have sent a follow up e-mail internally.

[AxLi_1746341]

Does sdk-5.2 fix this issue or not?

[gechc_1843576]

It seems that the issue still exist on sdk 5.2.

I tried to use wiced sdk 5.2, and I still faced the same issue.

So, it need the wiced sdk team to resolve the issue.

[AxLi_1746341]

genecheng_1843576 wrote:

It seems that the issue still exist on sdk 5.2.

I tried to use wiced sdk 5.2, and I still faced the same issue.

So, it need the wiced sdk team to resolve the issue.

grsr​

This issue has been reported for 3 months.

Do you know when will this issue get fixed? When will next release available?

[GauravS_31]

We are working internally to address this limitation. The fix is expected to be available in WICED 6.x (tentatively 6.1).

[GauravS_31 · Accepted solution]

genecheng_1843576​

We do not see this issue in WICED SDK 6.1. Please test your setup in this SDK version and let us know.

[gechc_1843576]

Hi.

Our project changes to use MQTT protocol now(with TLS encryption); however, this TCP issue seems solved in the latest SDK.

I use WICED SDK 6.2.1 to send the large TLS encrypted data from the MQTT broker to the client, and the client(device) can receive the large data.

As the result, I think this issue is resolved.

[Anonymous]

attn: grsr

I can't send the logs to this public forum as that would violate my corporate NDA, but probably we could send them to the engineers at Cypress with an NDA in place.

In any case, I can send publicly a screenshot of the log summary in the place of the error. Note: this log is not using TLS (hard to debug a protocol when it is encrypted), so frame size is bigger than 1447 (no TLS overhead).  The application payload is somewhat arbitrarily set to 1412 bytes.

• 10.1.0.133 is the WICED device
• Things go wrong when the 1460 byte message is segmented into a 1240 byte message for retransmission (2362)
• The TCP stack on .102 has now decided to use segmented frames.  In 2367 and 2368, there is a segmented frame that is treated as broken by the websocket application.  Websocket is closed in 2370.
• The damage is already done though.  The TCP stack seems to be in a race condition.  By 2376, no communication over TCP is possible.  The WICED device must be reset.

I've tried adding some delay slots at the application level, which seems to help somewhat, but it doesn't solve the problem entirely.

[gechc_1843576]

Hi grsr any update on this issue?