2

I've got powerful dual-core IoT gateways in the field with high-speed cellular modems and good internet connections, but they fail to send 2.5 KB MQTT messages to my AWS IoT message broker. My program sends messages of various sizes, and the 0.1 KB or 0.2 KB messages succeed >99% of the time. The 1.5 KB messages are about 50/50, and the 2.5 KB messages succeed less than 10% of the time... if I'm not watching them (It gets weirder).

My gateways will go several days without being able to send in the 2.5 KB message (all the while successfully sending the smaller 0.1 KB and 1.5 KB messages), but as soon as I VPN into the gateway with OpenVPN to investigate, it instantly sends in the 2.5 KB message. It's like asking my kids to do something while I'm gone; as soon as I return, it gets done instantly… So weird and frustrating!!

Thus, I'm guessing it's got something to do with my gateways' internet connections. I could stream Netflix movies on them, but they can't send 2.5 KB MQTT messages... When I install software on them, they can download megabytes of data in seconds. I'm also guessing it's not AWS IoT, because when I reproduce the problem from my development computer, the 2.5 KB message always publishes successfully to the AWS IoT message broker.

USD $580 gateway specs:

  • Axiomtek ICO120 dual core x86
  • Ubuntu Linux 18.04 LTS
  • SIMCom SIM7600AH modems

Python code for connecting to AWS IoT message broker with Paho MQTT library:


class PahoContainer:
    def __init__(
        self,
        c,
        mqtt_broker,
        cert_dir="/home/user/certs",
        set_on_message=True,
        set_on_publish=True,
        aws_thing=None,
        set_will=True,
    ):
        """Connects a client to MQTT broker"""

        self.c = c
        self.mqtt_broker = mqtt_broker
        self.cert_dir = cert_dir
        self.set_on_message = set_on_message
        self.set_on_publish = set_on_publish
        self.aws_thing = aws_thing

        self.connect(set_will=set_will)

    def on_connect(self, client, userdata, flags, rc):
        """The callback for when the client receives a CONNACK response from the server."""

        self.c.logger.info(f"Paho connected with result code: {rc}")

        # If the result code == 0 == True, set the connected_flag = True
        if rc == 0:
            self.c.logger.info(f"Setting Paho client.connected_flag = True")
            client.connected_flag = True

    def on_disconnect(self, client, userdata, rc):
        """
        The callback for a disconnection. You will need to reconnect as soon as possible.

        Since we run a network loop using loop_start() or loop_forever(), the re-connections are automatically handled.

        A new connection attempt is made automatically in the background every 3 to 6 seconds.
        """
        self.c.logger.info(f"on_disconnect callback. Disconnection reason rc: '{rc}'")

        client.connected_flag = False
        client.disconnect_flag = True

    def on_message(self, client, userdata, msg):
        """The callback for when a PUBLISH message is received from the server"""
        self.c.logger.info(f"Paho msg.topic: {msg.topic}; str(msg.payload): {str(msg.payload)}")

    def on_publish(self, client, userdata, mid):
        """The callback for when a PUBLISH message is sent to the server"""
        self.c.logger.info(f"Paho on_publish callback for Message ID (mid): {mid}")

    def on_log(self, client, userdata, level, buf):
        """Callback to record log messages"""
        self.c.logger.info(f"on_log callback. Level: '{level}'; msg buf: '{buf}'")

    def try_connecting(self, broker, port, keepalive, try_x_times=20):
        """Try connecting up to 20 times before raising an error"""
        counter = 0
        while True:
            counter += 1
            try:
                self.client.connect(broker, port=port, keepalive=keepalive)
            except Exception:
                x_more_times = try_x_times - counter
                if x_more_times == 0:
                    raise
                self.c.logger.exception(f"Problem connecting. Will try again {x_more_times}...")
                time.sleep(0.1)
            else:
                break

    def connect(self, set_will=True):
        """Connect to the message broker server"""

        client_id = mqtt.base62(uuid.uuid4().int, padding=22)
        self.client = mqtt.Client(client_id=client_id, clean_session=True)

        # Set a will to be sent by the broker in case the client disconnects unexpectedly.
        # This must be called before connect() to have any effect.
        # topic: The topic that the will message should be published on.
        # payload: The message to send as a will. If not given, or set to None a
        # zero length message will be used as the will.
        if set_will:
            if self.aws_thing is None:
                self.c.logger.warning("set_will is True but there is no self.aws_thing, so it can't happen")
            else:
                topic_lwt = f'last_will/{self.aws_thing.upper()}'
                payload_lwt = json.dumps({"connected": 0})
                self.client.will_set(topic_lwt, payload=payload_lwt, qos=1, retain=False)

        # We MUST use this on_connect callback to set the client.connected_flag = True.
        # Otherwise we'll be in an infinite loop
        self.client.on_connect = self.on_connect
        self.client.on_disconnect = self.on_disconnect

        # Enable logging using the standard python logging package.
        # This may be used at the same time as the on_log callback method
        # If logger is specified (default logger=None), then that logging.Logger object will be used;
        # otherwise one will be created automatically
        self.client.enable_logger(logger=self.c.logger)
        # self.client.enable_logger(logger=None)
        # Set the log level, if logger=None in enable_logger()
        self.client._logger.setLevel(logging.DEBUG)
        self.client.on_log = self.on_log
        # The client will automatically retry connection.
        # Between each attempt it will wait a number of seconds between min_delay and max_delay
        # When the connection is lost, initially the reconnection attempt is delayed of min_delay seconds.
        # It's doubled between subsequent attempt up to max_delay.
        # The delay is reset to min_delay when the connection complete (e.g. the CONNACK is received,
        # not just the TCP connection is established).
        self.client.reconnect_delay_set(min_delay=1, max_delay=5)
        # Set the maximum number of messages with QoS>0 that can be part way through their network flow at once.
        # Defaults to 20. Increasing this value will consume more memory but can increase throughput
        self.client.max_inflight_messages_set(10)
        # Set the maximum number of outgoing messages with QoS>0 that can be pending in the outgoing message queue.
        # Defaults to 0. 0 means unlimited. When the queue is full, any further outgoing messages would be dropped.
        self.client.max_queued_messages_set(0)
        # Set the time in seconds before a message with QoS>0 is retried, if the broker does not respond.
        # This is set to 5 seconds by default and should not normally need changing. 
        self.client.message_retry_set(2)

        if self.set_on_message:
            self.client.on_message = self.on_message
        if self.set_on_publish:
            self.client.on_publish = self.on_publish

        # Initialize client.connected_flag = False
        self.client.connected_flag = False
        self.c.logger.info(f"Connecting to broker: {self.mqtt_broker}")
        self.root_ca, self.device_cert, self.private_key = get_certs(self.c, self.cert_dir)
        self.client.tls_set(
            ca_certs=self.root_ca,
            certfile=self.device_cert,
            keyfile=self.private_key,
            cert_reqs=ssl.CERT_REQUIRED,
            tls_version=ssl.PROTOCOL_TLSv1_2,
            ciphers=None,
        )
        self.try_connecting(
            self.mqtt_broker,
            port=8883,
            keepalive=60,
            try_x_times=20
        )

        # We must start the loop before the while not client.connected_flag loop
        self.client.loop_start()

        # If we are not connected yet, wait a bit, then try again before returning the client
        while not self.client.connected_flag:
            seconds_to_sleep = 0.05
            self.c.logger.info(
                f"Waiting {seconds_to_sleep} seconds, then checking client.connected_flag again"
            )
            time.sleep(seconds_to_sleep)

Simple code for sending a message to AWS IoT:

# The metrics_dict is a Python dictionary with 2.5 KB of key/value pairs
payload = json.dumps({"metrics": metrics_dict})

info = paho_container.client.publish(
    topic,
    payload,
    qos=1,
)

Linux Network Manager (nmcli) command to create GSM cellular internet connection:

sudo nmcli radio wwan on
sudo nmcli c add type gsm ifname '*' con-name 'my_conn' apn 'pda.bell.ca' connection.autoconnect yes ipv4.dns '8.8.8.8 8.8.4.4'
sudo nmcli c up

EDIT Jan 26, 2021:

output from ifconfig tun0 command for OpenVPN connection (I've changed the IP addresses):

tun0: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1500
        inet 172.27.abc.def  netmask 255.255.248.0  destination 172.27.abc.def
        inet6 fe80::4597:4b9f:abcd:efgh  prefixlen 64  scopeid 0x20<link>
        unspec 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  txqueuelen 100  (UNSPEC)
        RX packets 9235  bytes 2655505 (2.6 MB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 9768  bytes 3329110 (3.3 MB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

output from ifconfig wwp0s21f0u4i5 command for GSM cellular connection, which shows the MTU is 1500 bytes (I've changed the IP addresses):

wwp0s21f0u4i5: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1500
        inet 174.90.ghi.jkl  netmask 255.255.255.248  destination 174.90.ghi.jkl
        unspec 00-00-00-00-00-00-00-00-00-00-00-00-00-00-00-00  txqueuelen 1000  (UNSPEC)
        RX packets 11784052  bytes 2475908779 (2.4 GB)
        RX errors 0  dropped 0  overruns 0  frame 0
        TX packets 12009517  bytes 2104615202 (2.1 GB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

Output from nmcli c s user_apn (I've changed the IP addresses):

$ nmcli c s user_apn
connection.id:                          user_apn
connection.uuid:                        05ebc6d3-4fbb-4ddb-93fd-25fb57314ca2
connection.stable-id:                   --
connection.type:                        gsm
connection.interface-name:              cdc-wdm0
connection.autoconnect:                 yes
connection.autoconnect-priority:        0
connection.autoconnect-retries:         -1 (default)
connection.auth-retries:                -1
connection.timestamp:                   1611695541
connection.read-only:                   no
connection.permissions:                 --
connection.zone:                        --
connection.master:                      --
connection.slave-type:                  --
connection.autoconnect-slaves:          -1 (default)
connection.secondaries:                 --
connection.gateway-ping-timeout:        0
connection.metered:                     unknown
connection.lldp:                        default
connection.mdns:                        -1 (default)
ipv4.method:                            auto
ipv4.dns:                               8.8.8.8,8.8.4.4
ipv4.dns-search:                        --
ipv4.dns-options:                       ""
ipv4.dns-priority:                      0
ipv4.addresses:                         --
ipv4.gateway:                           --
ipv4.routes:                            --
ipv4.route-metric:                      -1
ipv4.route-table:                       0 (unspec)
ipv4.ignore-auto-routes:                no
ipv4.ignore-auto-dns:                   no
ipv4.dhcp-client-id:                    --
ipv4.dhcp-timeout:                      0 (default)
ipv4.dhcp-send-hostname:                yes
ipv4.dhcp-hostname:                     --
ipv4.dhcp-fqdn:                         --
ipv4.never-default:                     no
ipv4.may-fail:                          yes
ipv4.dad-timeout:                       -1 (default)
ipv6.method:                            auto
ipv6.dns:                               --
ipv6.dns-search:                        --
ipv6.dns-options:                       ""
ipv6.dns-priority:                      0
ipv6.addresses:                         --
ipv6.gateway:                           --
ipv6.routes:                            --
ipv6.route-metric:                      -1
ipv6.route-table:                       0 (unspec)
ipv6.ignore-auto-routes:                no
ipv6.ignore-auto-dns:                   no
ipv6.never-default:                     no
ipv6.may-fail:                          yes
ipv6.ip6-privacy:                       -1 (unknown)
ipv6.addr-gen-mode:                     stable-privacy
ipv6.dhcp-send-hostname:                yes
ipv6.dhcp-hostname:                     --
ipv6.token:                             --
gsm.number:                             *99#
gsm.username:                           --
gsm.password:                           <hidden>
gsm.password-flags:                     0 (none)
gsm.apn:                                wrmstatic.bell.ca.ioe
gsm.network-id:                         --
gsm.pin:                                <hidden>
gsm.pin-flags:                          0 (none)
gsm.home-only:                          no
gsm.device-id:                          --
gsm.sim-id:                             --
gsm.sim-operator-id:                    --
gsm.mtu:                                auto
proxy.method:                           none
proxy.browser-only:                     no
proxy.pac-url:                          --
proxy.pac-script:                       --
GENERAL.NAME:                           user_apn
GENERAL.UUID:                           05ebc6d3-4fbb-4ddb-93fd-25fb57314ca2
GENERAL.DEVICES:                        cdc-wdm0
GENERAL.STATE:                          activated
GENERAL.DEFAULT:                        yes
GENERAL.DEFAULT6:                       no
GENERAL.SPEC-OBJECT:                    --
GENERAL.VPN:                            no
GENERAL.DBUS-PATH:                      /org/freedesktop/NetworkManager/ActiveConnection/1
GENERAL.CON-PATH:                       /org/freedesktop/NetworkManager/Settings/1
GENERAL.ZONE:                           --
GENERAL.MASTER-PATH:                    --
IP4.ADDRESS[1]:                         174.90.123.456/29
IP4.GATEWAY:                            174.90.123.457
IP4.ROUTE[1]:                           dst = 174.90.123.452/29, nh = 0.0.0.0, mt = 700
IP4.ROUTE[2]:                           dst = 169.254.0.0/16, nh = 0.0.0.0, mt = 1000
IP4.ROUTE[3]:                           dst = 54.218.161.180/32, nh = 174.90.186.221, mt = 0
IP4.ROUTE[4]:                           dst = 0.0.0.0/0, nh = 174.90.186.221, mt = 700
IP4.DNS[1]:                             70.28.245.227
IP4.DNS[2]:                             184.151.118.254
IP4.DNS[3]:                             8.8.8.8
IP4.DNS[4]:                             8.8.4.4
IP6.GATEWAY:                            --

EDIT Jan 27, 2021 at 9:00 a.m. MST: Output from traceroute --mtu <broker>

Trying to figure out if this is a packet fragmentation issue related to the MTU of 1500 and the fact that MQTT messages start to fail around the 1.5 KB size, and almost always fail at the 2.5 KB size.

$ traceroute --mtu abcdefg-ats.iot.us-west-2.amazonaws.com
traceroute to abcdefg-ats.iot.us-west-2.amazonaws.com (52.43.abc.def), 30 hops max, 65000 byte packets
 1  172.27.abc.def (172.27.abc.def)  78.980 ms F=1500  75.051 ms  77.459 ms
 2  ec2-50-112-abc-def.us-west-2.compute.amazonaws.com (50.112.abc.def)  101.733 ms ec2-34-221-abc-def.us-west-2.compute.amazonaws.com (34.221.abc.def)  78.166 ms ec2-50-112-abc-def.us-west-2.compute.amazonaws.com (50.112.abc.def)  93.053 ms
 3  * * *
 4  * * *
 5  * * *
 6  * * *
 7  * * *
 8  * * *
 9  * * *
10  * * *
11  * * *
12  * * *
13  * * *
14  * * *
15  * * *
16  * * *
17  * * *
18  * * *
19  * * *
20  * * *
21  * * *
22  * * *
23  * * *
24  * * *
25  * * *
26  * * *
27  * * *
28  * * *
29  * * *
30  * * *

EDIT Jan 27, 2021 at 9:50 a.m. MST showing output of ping commands:

When I ping the AWS IoT message broker with 1300 bytes, it gets through every time:

$ ping -c 3 -s 1300 52.43.abc.def
PING 52.43.abc.def (52.43.abc.def) 1300(1328) bytes of data.
1308 bytes from 52.43.abc.def: icmp_seq=1 ttl=253 time=87.7 ms
1308 bytes from 52.43.abc.def: icmp_seq=2 ttl=253 time=99.7 ms
1308 bytes from 52.43.abc.def: icmp_seq=3 ttl=253 time=106 ms

However, when I ping the broker with 1400 bytes (1.4 KB), it times out! Why?

$ ping -c 3 -s 1400 52.43.abc.def
PING 52.43.abc.def (52.43.abc.def) 1400(1428) bytes of data.

--- 52.43.163.79 ping statistics ---
3 packets transmitted, 0 received, 100% packet loss, time 2051ms

EDIT Jan 27 at 13:00 MST showing ip route show output:

@hardillb asked if the "default route" changed due to OpenVPN (tun0 interface) starting. I wasn't sure what that meant at first, but now I think OpenVPN does change the default route. See the following ip route show output that references tun0 (the OpenVPN network interface):

$ ip route show
0.0.0.0/1 via 172.27.abc.def dev tun0
default via 10.74.abc.def dev wwp0s21f0u4i5 proto static metric 700
10.74.abc.def/30 dev wwp0s21f0u4i5 proto kernel scope link src 10.74.abc.def metric 700
54.218.abc.def via 10.74.abc.def dev wwp0s21f0u4i5
128.0.0.0/1 via 172.27.abc.def dev tun0
169.254.0.0/16 dev enp2s0 scope link metric 1000 linkdown
172.27.abc.def/21 dev tun0 proto kernel scope link src 172.27.abc.def
192.168.2.0/24 dev enp2s0 proto kernel scope link src 192.168.2.2 metric 100 linkdown
7
  • 1
    What's the MTU of the connection? And does the OpenVPN connection change the default route on the device when it connect to be via the VPN?
    – hardillb
    Jan 26 at 19:27
  • @hardillb nmcli c s <name> says the gsm.mtu = auto. I'm afraid I don't yet know how to answer your other questions about the "default route" because I don't yet know what that is... If you want to take this conversation offline, I see you're an expert on this stuff, and my company would be happy to pay you as a consultant to help us out with this. Seriously. Jan 26 at 20:19
  • @hardillb I disconnected OpenVPN and reconnected, and the IP4.ROUTE[x] values didn't change. However, this time the 2.5 KB message did not publish successfully either. It's a bit random when it sends successfully... The 0.1 KB messages are much more reliable Jan 26 at 20:47
  • @hardillb I've added information about the connections to the question. The ifconfig command shows the MTU = 1500. Jan 26 at 21:19
  • 2
    The MTU matches where the problem starts 1.5k ~ 1500 so it sounds like it might be a packet fragmentation problem. Try running traceroute -mtu [broker ip address] and see what value you get back for the full path
    – hardillb
    Jan 27 at 8:22
2

Based on what we've seen in the comments and edits, I think it might be worth setting a lower MTU for the cellular link.

Try running something like the following:

nmcli con mod "user_apn" gsm.mtu 1300

This should cause the MQTT client (in combination with the network stack) to break packets up into smaller chunks which hopefully should be able to make it all the way to the broker without being fragmented along the route.

2
  • I think this is the answer! But I also had to run sudo nmcli connection down 'user_apn'; wait; sudo nmcli connection up 'user_apn'; to reboot the connection and apply the changes. If I only run nmcli con mod 'user_apn' gsm.mtu 1300, and then I check it with ifconfig it still reports a 1500 MTU. After restarting the connection, it reported a 1300 MTU, and I think it's actually working!!! Jan 29 at 21:24
  • 1
    yeah, sorry. I should have said to bounce the connection after making the change.
    – hardillb
    Jan 29 at 21:29
2

There may be paths with a MTU of 1280 in the way. Try 1100 or 1200 and see if that fixes it. If not, try to find an MTU finder app to try to find the MTU to your destination from your source.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.