Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

improve ping handling #199

Merged
merged 3 commits into from
Jan 29, 2024
Merged

improve ping handling #199

merged 3 commits into from
Jan 29, 2024

Conversation

vladak
Copy link
Contributor

@vladak vladak commented Jan 24, 2024

This changes the way how pings are treated. Rather than sending PINGREQ based on how loop() is called, it is based on how messages are sent to the broker (in accordance with the MQTT spec). Also, the ping handling was folded into the loop in loop() to make it work in cases with loop timeouts longer than the keep alive timeout.

I plan to test this on a QtPy.

- do not send PINGREQ unnecessarily
- send PINGREQ even on long loop timeouts

fixes adafruit#198
@vladak
Copy link
Contributor Author

vladak commented Jan 25, 2024

Tested on my trusty Adafruit CircuitPython 8.2.6 on 2023-09-12; Adafruit QT Py ESP32-S3 no psram with ESP32S3 with:

#!/usr/bin/env python3

"""
test for https://github.com/adafruit/Adafruit_CircuitPython_MiniMQTT/pull/199
"""

import ssl
import time
import wifi
import socketpool

import adafruit_minimqtt.adafruit_minimqtt as MQTT

import adafruit_logging as logging

from secrets import secrets


def main():
    logger = logging.getLogger(__name__)
    logger.setLevel(logging.DEBUG)

    logger.info(f"Connecting to wifi {secrets['SSID']}")
    wifi.radio.connect(secrets["SSID"], secrets["password"], timeout=20)
    logger.info(f"Connected to {secrets['SSID']}")
    logger.debug(f"IP: {wifi.radio.ipv4_address}")

    pool = socketpool.SocketPool(wifi.radio)

    keep_alive_timeout = 8
    host = "172.40.0.3"
    port = 1883
    mqtt_client = MQTT.MQTT(
        broker=host,
        port=port,
	socket_pool=pool,
        ssl_context=ssl.create_default_context(),
        connect_retries=1,
        recv_timeout=5,
        keep_alive=keep_alive_timeout,
    )

    # mqtt_client.logger = logger

    logger.debug(f"connecting with keep alive = {keep_alive_timeout}")
    mqtt_client.connect()

    # Subscribe to something with traffic to be more real. No on_message, tho.
    mqtt_client.subscribe("#")

    logger.info("### loop() with egress MQTT message traffic")
    # No PINGREQ should be sent during this cycle.
    rcs_test = []
    num_iter = 8 * keep_alive_timeout
    for i in range(1, num_iter):
        logger.debug(f"iteration #{i}/{num_iter - 1}")
        mqtt_client.publish("foo", "bar")
        rcs = mqtt_client.loop(1)
	rcs_test.extend(rcs)
    logger.info(f"rcs = {rcs_test}")
    assert 208 not in rcs_test

    # Give the user some time to digest the test result.
    logger.info("### sleeping for 10 seconds")
    time.sleep(10)

    logger.info("### loop() with no egress message traffic and long timeout")
    # Multiple PINGREQs should be sent during this cycle.
    delay = 2 * keep_alive_timeout
    rcs_test = []
    for _ in range(3):
        logger.debug(f"calling loop({delay})")
        try:
            rcs = mqtt_client.loop(delay)
	    rcs_test.extend(rcs)
	    logger.info(f"Got message types: {rcs}")
        except MQTT.MMQTTException as e:
            logger.error(f"failed: {e}")
    logger.info(f"rcs = {rcs_test}")
    assert 208 in rcs_test


if __name__ == "__main__":
    main()

the output looked like this:

code.py output:
1804.847: INFO - Connecting to wifi XXX
1804.848: INFO - Connected to XXX
1804.850: DEBUG - IP: 172.40.0.23
1804.853: DEBUG - connecting with keep alive = 8
1804.916: INFO - ### loop() with egress MQTT message traffic
1804.918: DEBUG - iteration #1/63
1806.383: DEBUG - iteration #2/63
1807.436: DEBUG - iteration #3/63
1808.456: DEBUG - iteration #4/63
1809.509: DEBUG - iteration #5/63
1810.621: DEBUG - iteration #6/63
1812.141: DEBUG - iteration #7/63
1813.678: DEBUG - iteration #8/63
1814.734: DEBUG - iteration #9/63
1815.791: DEBUG - iteration #10/63
1817.458: DEBUG - iteration #11/63
1818.513: DEBUG - iteration #12/63
1820.208: DEBUG - iteration #13/63
1822.050: DEBUG - iteration #14/63
1823.201: DEBUG - iteration #15/63
1825.043: DEBUG - iteration #16/63
1826.096: DEBUG - iteration #17/63
1827.154: DEBUG - iteration #18/63
1828.423: DEBUG - iteration #19/63
1829.476: DEBUG - iteration #20/63
1830.534: DEBUG - iteration #21/63
1832.176: DEBUG - iteration #22/63
1833.723: DEBUG - iteration #23/63
1834.874: DEBUG - iteration #24/63
1835.927: DEBUG - iteration #25/63
1836.984: DEBUG - iteration #26/63
1838.639: DEBUG - iteration #27/63
1839.703: DEBUG - iteration #28/63
1841.404: DEBUG - iteration #29/63
1842.456: DEBUG - iteration #30/63
1844.168: DEBUG - iteration #31/63
1845.677: DEBUG - iteration #32/63
1846.682: DEBUG - iteration #33/63
1847.776: DEBUG - iteration #34/63
1849.698: DEBUG - iteration #35/63
1850.750: DEBUG - iteration #36/63
1852.462: DEBUG - iteration #37/63
1853.515: DEBUG - iteration #38/63
1854.534: DEBUG - iteration #39/63
1855.587: DEBUG - iteration #40/63
1856.682: DEBUG - iteration #41/63
1858.220: DEBUG - iteration #42/63
1859.429: DEBUG - iteration #43/63
1860.483: DEBUG - iteration #44/63
1861.541: DEBUG - iteration #45/63
1863.430: DEBUG - iteration #46/63
1865.365: DEBUG - iteration #47/63
1866.418: DEBUG - iteration #48/63
1868.128: DEBUG - iteration #49/63
1869.183: DEBUG - iteration #50/63
1870.218: DEBUG - iteration #51/63
1872.044: DEBUG - iteration #52/63
1873.098: DEBUG - iteration #53/63
1874.823: DEBUG - iteration #54/63
1875.884: DEBUG - iteration #55/63
1876.938: DEBUG - iteration #56/63
1878.574: DEBUG - iteration #57/63
1879.625: DEBUG - iteration #58/63
1881.338: DEBUG - iteration #59/63
1882.875: DEBUG - iteration #60/63
1884.176: DEBUG - iteration #61/63
1885.183: DEBUG - iteration #62/63
1886.426: DEBUG - iteration #63/63
1887.485: INFO - rcs = [48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 
48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 
48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 
48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48]
1887.486: INFO - ### sleeping for 10 seconds
1897.488: INFO - ### loop() with no egress message traffic and long timeout
1897.490: DEBUG - calling loop(16)
1913.672: INFO - Got message types: [48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 48]
1913.674: DEBUG - calling loop(16)
1929.796: INFO - Got message types: [48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48]
1929.797: DEBUG - calling loop(16)
1945.927: INFO - Got message types: [208, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48]
1945.929: INFO - rcs = [48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 4
8, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48, 48, 48, 48, 48, 48, 48, 208, 48, 48, 48, 48
, 48, 48, 48, 48, 48, 48, 48, 48, 48]

# Conflicts:
#	adafruit_minimqtt/adafruit_minimqtt.py
Copy link
Contributor

@FoamyGuy FoamyGuy left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks good to me.

I merged main and resolved the conflicts.

I tried testing with the given test and did get it to run part way but I think the second half of it doesn't work with adafruit.io in the same way as your test broker. on AIO I hit rate limits that the front end warned me about and the PINGRESP was not sent as the script expected.

I did test basic MQTT functionality seperately and both receiving and sending data appears to be working successfully.

My testing was on a feather TFT ESP32-S3

@FoamyGuy FoamyGuy merged commit a05b19f into adafruit:main Jan 29, 2024
1 check passed
adafruit-adabot added a commit to adafruit/Adafruit_CircuitPython_Bundle that referenced this pull request Jan 30, 2024
Updating https://github.com/adafruit/Adafruit_CircuitPython_Wiznet5k to 5.0.6 from 5.0.5:
  > Merge pull request adafruit/Adafruit_CircuitPython_Wiznet5k#125 from FoamyGuy/recv_timeout

Updating https://github.com/adafruit/Adafruit_CircuitPython_HTTPServer to 4.5.1 from 4.5.0:
  > Merge pull request adafruit/Adafruit_CircuitPython_HTTPServer#76 from michalpokusa/routes-refactor

Updating https://github.com/adafruit/Adafruit_CircuitPython_MiniMQTT to 7.5.8 from 7.5.6:
  > Merge pull request adafruit/Adafruit_CircuitPython_MiniMQTT#199 from vladak/loop_vs_keep_alive
  > Merge pull request adafruit/Adafruit_CircuitPython_MiniMQTT#200 from vladak/loop_timeout_vs_socket_timeout
  > Merge pull request adafruit/Adafruit_CircuitPython_MiniMQTT#184 from rjauquet/rej-fix-loop-blocking

Updating https://github.com/adafruit/Adafruit_CircuitPython_PIOASM to 1.0.0 from 0.8.2:
  > Merge pull request adafruit/Adafruit_CircuitPython_PIOASM#61 from Gebhartj/Gebhartj-patch-1

Updating https://github.com/adafruit/Adafruit_CircuitPython_Bundle/circuitpython_library_list.md to NA from NA:
  > Updated download stats for the libraries
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants