buglwIP - A Lightweight TCP/IP stack - Bugs: bug #61558, Possibly faulty behaviour on...

 
 

You are not allowed to post comments on this tracker with your current authentication level.

bug #61558: Possibly faulty behaviour on receiving large payloads with mqtt+tls causing disconnect

Submitted by:  evot1
Submitted on:  Thu 25 Nov 2021 01:01:37 PM UTC
 
Category:  pbufs Severity:  3 - Normal
Item Group:  Faulty Behaviour Status:  Works For Me
Privacy:  Public Assigned to:  None
Open/Closed:  Closed Planned Release:  None
lwIP version:  * 2.1.0
* Mandatory Fields

Add a New Comment (Rich Markup)
   

Comment Type & Canned Response:
       No canned response available

 

( Jump to the original submission )

Tue 04 Jan 2022 07:55:23 AM UTC, comment #12: 

After further investigation, with the information Simon provided we have concluded that this issue was caused by one of our own patches. Excuse the hassle.
Thank you for your support on the matter. This issue can be closed.

evot1
Wed 01 Dec 2021 10:27:06 AM UTC, comment #11: 

Is there some indication of when it will be fixed/looked at? It would be great if you could tell me how long it usually takes.

Thank you

evot1
Mon 29 Nov 2021 08:26:35 AM UTC, comment #10: 

Ok in that case I agree with you that getting mqtt to handle this is is what needs to be fixed primarily.

Mqtt is saving the fixed mqtt header between calls, so that it can handle fragmented packets. But the variable header is not being saved between calls.
This might be a way to solve it? Saving the variable header along with the fixed one. But it is just an idea of course.

 Again, thank you for your help!

evot1
Mon 29 Nov 2021 08:11:42 AM UTC, comment #9: 

I think I know what you mean. And maybe this can be fixed for this mqtt case by chaining packets together. However, it is perfectly valid for any mqtt server's TCP stack to send out responses in split packets.

In fact, the TCP spec allows the sending TCP to split packets at any byte boundary. Even sending many packets with 1 byte each would be allowed. If mqtt cannot handle this, it needs fixing.

Merging back packets in the altcp_tls code can only be a performance improvement, not a bugfix.

Simon Goldschmidt <goldsimon>
Project Administrator
Mon 29 Nov 2021 08:00:33 AM UTC, comment #8: 

To clarify; the issue is that the a disconnect event is triggered in lwip mqtt, i.e before any function calls to our code.

Running mqtt without tls does not cause this issue.

Even if tcp is not a packet based protocol, i still think the packets should be assembled back together right?

When pbufs come in to the mqtt_recv_cb() in lwip mqtt.c and tls is not used, the ppbufs are chained together if the data is more than PBUF_POOL_BUFSIZE.

When using tls pbufs are never chained when received by mqtt_recv_cb(). This is why i suspect it might have something to do with packets not being chained back together after decryption in altcp.
Of course the reason might be something else but this is what I have found.

In any case, we can not handle this in our code since the disconnect is happening before the data reaches our part of the code.

Do you see what i mean now?

evot1
Fri 26 Nov 2021 03:59:55 PM UTC, comment #7: 

Again, I'm not sure I understand what you mean.

To clarify, if I understood your description correctly, I think the problem must be fixed in mqtt. It's not a problem in altcp_tls or anywhere else in the core stack.

Simon Goldschmidt <goldsimon>
Project Administrator
Fri 26 Nov 2021 02:53:27 PM UTC, comment #6: 

Ahh sorry, I understand what you mean now.
Do you have any ideas for a fix right of the bat? Anyways we will follow the bug and wait for it to be fixed.

Thank you for your help!

evot1
Fri 26 Nov 2021 02:28:24 PM UTC, comment #5: 

Yes, exactly this is what i see!
By "should be fixed", do you mean it already is fixed or it should be in the future? I could not fins a fix for it in later lwip versions

Yes, I am trying to push for an update of lwip. Hopefully we will update soon.

evot1
Fri 26 Nov 2021 02:13:00 PM UTC, comment #4: 

Ah, ok, I think I may know what's happening: First, the MQTT header is passed in one RX callback and only after that, a 2nd callback is made with only MQTT data (because the header has been passed in already, but in a separate call). Is this what you see?

If so, the mqtt app should be fixed because it's perfectly valid for TCP (as a streaming protocol, as opposed to UDP as a packet based protocol) to split the stream into separate packets.

BTW, you might want to update to a newere version if you're really still using 2.1.0! There have been multiple fixes since then!

Simon Goldschmidt <goldsimon>
Project Administrator
Fri 26 Nov 2021 01:15:13 PM UTC, comment #3: 

Thank you for your quick reply!

I can unfortunatly not provide any unit test since we do no unit test this part of the code.

We recently upgraded the maximum publish payload size for mqtt  of our product to 1024 bytes, and when trying to also receive this payload size we noticed that disconnect was triggered.
Our PBUF_POOL_BUFSIZE is 312 bytes. We need to keep it that size for performance reasons. Other config items that might be interesting is;
MQTT_VAR_HEADER_BUFFER_LEN 1024
MQTT_OUTPUT_RINGBUF_SIZE 1024

We use lwip for tcp, mqtt and as tls interface to mbedtls.
I will try to explain what happens:
Disconnect is being triggered in mqtt.c

"mqtt_message_received()"
      topic_len = var_hdr_payload[0];
      topic_len = (topic_len << 8) + (u16_t)(var_hdr_payload[1]); The first bytes should be variable header but is just payload bytes.
      if ((topic_len > length - (2 + qos_len)) ||
          (topic_len > var_hdr_payload_bufsize - (2 + qos_len))) { Since the payload is interpreted as "topic_len" this value is often too large
        LWIP_DEBUGF(MQTT_DEBUG_WARN,( "mqtt_message_received: Received short PUBLISH packet (topic)\n"));
        goto out_disconnect;  Disconnect is triggered here
      }

When looking in to the the actual payload I could see that this message has no variable header, it is just plain payload. Tracing this back to
"mqtt_parse_incoming()"
I the pbuf comming in to this function has no header at all, it is just consisting of payload.

I have traced the issue further back to
"altcp_mbedtls_handle_rx_appldata()"

By debugging and reading the code I could conlude that there is a loop that allocs one pbuf at a time and fills this with decrypted data
from the func "mbedtls_ssl_read()".
This pbuf is always directly passed on to the above application (in this case mqtt) using "altcp_mbedtls_pass_rx_data()" and is never chained together with another pbuf.

This is true even if there is still data left that has not yet been pulled of state->rx using "mbedtls_ssl_read()".

So when the incomming data is larger than one pbuf size this remaining data is being pulled of state->rx and sent on to the above application, without being chained to the previous
part of the data (which contains the header).

This is the part of the code that I mean;
in "altcp_mbedtls_handle_rx_appldata()"
Loop:
        if (state->rx_app == NULL) {
          state->rx_app = buf;
        } else {
          pbuf_cat(state->rx_app, buf); This is never called since state->rx is always NULL every iteration.
        }
      } else {
        pbuf_free(buf);
        buf = NULL;
      }
          err = altcp_mbedtls_pass_rx_data(conn, state); When exiting this function state->rx is NULL.

    

In "altcp_mbedtls_pass_rx_data()"

 buf = state->rx_app;
  if (buf) {
    state->rx_app = NULL; Here the state->rx is set to NULL
    if (conn->recv) {
      u16_t tot_len = buf->tot_len;
      /* this needs to be increased first because the 'recved' call may come nested */
      state->rx_passed_unrecved += tot_len;
      state->flags |= ALTCP_MBEDTLS_FLAGS_UPPER_CALLED;
      err = conn->recv(conn->arg, conn, buf, ERR_OK);
      if (err != ERR_OK) {
        if (err == ERR_ABRT) {
          return ERR_ABRT;
        }
        /* not received, leave the pbuf(s) queued (and decrease 'unrecved' again) */
        LWIP_ASSERT("state == conn->state", state == conn->state);
        state->rx_app = buf; We never get here since mqtt_recv_cb() always return ERR_OK. state->rx is still NULL
        state->rx_passed_unrecved -= tot_len;
        LWIP_ASSERT("state->rx_passed_unrecved >= 0", state->rx_passed_unrecved >= 0);
        if (state->rx_passed_unrecved < 0) {
          state->rx_passed_unrecved = 0;
        }

This means state->rx is still NULL when exiting this function.

This is what i can guess goes wrong but, I am not entirely sure how this is supposed to work? Is the above application supposed to reject the pbuf comming in from
altcp_mbedtls_pass_rx_data if it is not a full packet including header, thus propagating an error back to altcp_mbedtls_pass_rx_data?
Or could this be a bug?

I have tried two fixes to verify that the issue has to do with pbuf chaining. Increasing PBUF_POOL_BUFSIZE to 2048 bytes so that payload (we only need to send 1000 bytes) is never
big enough to be fragmented in two pbufs. This fixed the issue, but ca not be done permanently in our application.
The next fix I tested is;
Adding a condition to check if a full packet has been decoded before sending the pbuf chain to the application like this;

in "altcp_mbedtls_handle_rx_appldata()"

        if (state->rx_app == NULL) {
          state->rx_app = buf;
        } else {
          pbuf_cat(state->rx_app, buf); Now the pbufs are chained here before being sent to the appication
        }
      } else {
        pbuf_free(buf);
        buf = NULL;
      }
      /* patch start*/
      if (state->ssl_context.in_msglen == 0) { state->ssl_context.in_msglen would be decreased to 0 when all data is pulled of state->rx
          err = altcp_mbedtls_pass_rx_data(conn, state);
     }/* patch end*/

This fixed the issue, but broke tls over tcp for some reason that I have not yet looked into.

This confirms that the issue has something to do with the chaining of pbufs.

Is this more clear or do you need more information?

Thank you for your help!

evot1
Fri 26 Nov 2021 12:26:49 PM UTC, comment #2: 

I'm not sure I understand the problem at hand. Can you describe it a bit more? Ideally with an example or a unit test config that shows what's going wrong for you?

Simon Goldschmidt <goldsimon>
Project Administrator
Fri 26 Nov 2021 10:37:45 AM UTC, comment #1: 

Update: The patch solved the issues in mqtt but is causing issues for other applications using tls.
Does anyone have any ideas on how to solve this except increasing the pbuf size?

evot1
Thu 25 Nov 2021 01:01:37 PM UTC, original submission:  

We are using
When receiving packets that are larger than PBUF_POOL_BUFSIZE  with mqtt using tls, the packets are not being chained correctly in altcp_tls_mbedtls.c.

Data arrives in  altcp_mbedtls_handle_rx_appldata and are decrypted using "mbedtls_ssl_read", and put in pbuf.
Thereafter the pbuf should be chained if there is any unreceived pbufs still in state-rx_app.

This never happens since the pbuf is emediately passed to the application with altcp_mbedtls_pass_rx_data.
Mqtt does no sanity check to see if the received packet is a full packet with header or not. Thus not returning an error when it receives only the first PBUF_POOL_BUFSIZE bytes of a packet that should have another pbuf chained after it.
Since error is not returned back to altcp_mbedtls_pass_rx_data the state->rx-app is set to NULL and the next part of the decoded message coming out from "mbedtls_ssl_read" is never concated with the previous one.
This pbuf is lacking mqtt headers since it should have been the tail of the previous packet (pbuf-chain) and the mqtt stack can not deal with a headerless packet, and random disconnects happen because the payload is being interpreted as header data.

Might this be bug or should this be handled somewhere else?

We think this fix have solved the issue but we are not sure if it should be handled in a different way.
We added an if check to see if the full incomming buffer is decoded.

in "altcp_mbedtls_handle_rx_appldata" func:

if (state->ssl_context.in_msglen==0) {
   err = altcp_mbedtls_pass_rx_data(conn, state);
}

evot1

 

(Note: upload size limit is set to 16384 kB, after insertion of the required escape characters.)

Attach Files:
   
   
Comment:
   

No files currently attached

 

Depends on the following items: None found

Items that depend on this one: None found

 

Carbon-Copy List
  • -email is unavailable- added by yarrick (Updated the item)
  • -email is unavailable- added by goldsimon (Posted a comment)
  • -email is unavailable- added by evot1 (Submitted the item)
  • -email is unavailable- added by evot1
  • -email is unavailable- added by evot1
  •  

    There are 0 votes so far. Votes easily highlight which items people would like to see resolved in priority, independently of the priority of the item set by tracker managers.

    Only logged-in users can vote.

     

     

     

     

    Follow 4 latest changes.

    Date Changed by Updated Field Previous Value => Replaced by
    2022-01-04 yarrick StatusNone => Works For Me
        Open/ClosedOpen => Closed
    2021-11-25 evot1 Carbon-Copy- => Added -email is unavailable-
        Carbon-Copy- => Added -email is unavailable-

    Back to the top


    Powered by Savane 3.9