Publishing or receiving large-ish messages reproducibly fails in 2 ways #107
Assignees
Labels
Comments
|
I believe the negative (or giant, depending on how you look at it) allocation error should be fixed in the next release (PR #133) - the one that comes after 7.1.0, that is. |
|
@vladak Did you test this? |
|
Tested with CP 8.0.0 beta 6 on QtPy with adafruit_minimqtt==7.3.2 using: import json
import ssl
import time
import traceback
import adafruit_logging as logging
import adafruit_minimqtt.adafruit_minimqtt as MQTT
import board
import microcontroller
import neopixel
import socketpool
import supervisor
import wifi
from logutil import get_log_level
try:
from secrets import secrets
except ImportError:
print(
"WiFi and Adafruit IO credentials are kept in secrets.py, please add them there!"
)
raise
# pylint: disable=unused-argument, redefined-outer-name, invalid-name
def connect(mqtt_client, userdata, flags, rc):
"""
This function will be called when the mqtt_client is connected
successfully to the broker.
"""
logger = logging.getLogger(__name__)
logger.info("Connected to MQTT Broker!")
logger.debug(f"Flags: {flags}\n RC: {rc}")
# pylint: disable=unused-argument, invalid-name
def disconnect(mqtt_client, userdata, rc):
"""
This method is called when the mqtt_client disconnects from the broker.
"""
logger = logging.getLogger(__name__)
logger.info("Disconnected from MQTT Broker!")
def publish(mqtt_client, userdata, topic, pid):
"""
This method is called when the mqtt_client publishes data to a feed.
"""
logger = logging.getLogger(__name__)
logger.info(f"Published to {topic} with PID {pid}")
def message(mqtt_client, topic, msg):
"""
This method is called when the mqtt_client publishes data to a feed.
"""
logger = logging.getLogger(__name__)
logger.info(f"Got message to {topic} of {len(msg)} bytes")
def blink(pixel):
"""
Blink the Neo pixel blue.
"""
pixel.brightness = 0.3
pixel.fill((0, 0, 255))
time.sleep(0.5)
pixel.brightness = 0
def main():
pixel = neopixel.NeoPixel(board.NEOPIXEL, 1)
log_level = get_log_level(secrets["log_level"])
logger = logging.getLogger(__name__)
logger.setLevel(log_level)
logger.info("Running")
# Connect to Wi-Fi
logger.info("Connecting to wifi")
wifi.radio.connect(secrets["ssid"], secrets["password"], timeout=10)
logger.info(f"Connected to {secrets['ssid']}")
logger.debug(f"IP: {wifi.radio.ipv4_address}")
logger.debug(f"MAC: {wifi.radio.mac_address}")
# Create a socket pool
pool = socketpool.SocketPool(wifi.radio)
ssl_context = ssl.create_default_context()
cadata = """
-----BEGIN CERTIFICATE-----
MIIEAzCCAuugAwIBAgIUBY1hlCGvdj4NhBXkZ/uLUZNILAwwDQYJKoZIhvcNAQEL
BQAwgZAxCzAJBgNVBAYTAkdCMRcwFQYDVQQIDA5Vbml0ZWQgS2luZ2RvbTEOMAwG
A1UEBwwFRGVyYnkxEjAQBgNVBAoMCU1vc3F1aXR0bzELMAkGA1UECwwCQ0ExFjAU
BgNVBAMMDW1vc3F1aXR0by5vcmcxHzAdBgkqhkiG9w0BCQEWEHJvZ2VyQGF0Y2hv
by5vcmcwHhcNMjAwNjA5MTEwNjM5WhcNMzAwNjA3MTEwNjM5WjCBkDELMAkGA1UE
BhMCR0IxFzAVBgNVBAgMDlVuaXRlZCBLaW5nZG9tMQ4wDAYDVQQHDAVEZXJieTES
MBAGA1UECgwJTW9zcXVpdHRvMQswCQYDVQQLDAJDQTEWMBQGA1UEAwwNbW9zcXVp
dHRvLm9yZzEfMB0GCSqGSIb3DQEJARYQcm9nZXJAYXRjaG9vLm9yZzCCASIwDQYJ
KoZIhvcNAQEBBQADggEPADCCAQoCggEBAME0HKmIzfTOwkKLT3THHe+ObdizamPg
UZmD64Tf3zJdNeYGYn4CEXbyP6fy3tWc8S2boW6dzrH8SdFf9uo320GJA9B7U1FW
Te3xda/Lm3JFfaHjkWw7jBwcauQZjpGINHapHRlpiCZsquAthOgxW9SgDgYlGzEA
s06pkEFiMw+qDfLo/sxFKB6vQlFekMeCymjLCbNwPJyqyhFmPWwio/PDMruBTzPH
3cioBnrJWKXc3OjXdLGFJOfj7pP0j/dr2LH72eSvv3PQQFl90CZPFhrCUcRHSSxo
E6yjGOdnz7f6PveLIB574kQORwt8ePn0yidrTC1ictikED3nHYhMUOUCAwEAAaNT
MFEwHQYDVR0OBBYEFPVV6xBUFPiGKDyo5V3+Hbh4N9YSMB8GA1UdIwQYMBaAFPVV
6xBUFPiGKDyo5V3+Hbh4N9YSMA8GA1UdEwEB/wQFMAMBAf8wDQYJKoZIhvcNAQEL
BQADggEBAGa9kS21N70ThM6/Hj9D7mbVxKLBjVWe2TPsGfbl3rEDfZ+OKRZ2j6AC
6r7jb4TZO3dzF2p6dgbrlU71Y/4K0TdzIjRj3cQ3KSm41JvUQ0hZ/c04iGDg/xWf
+pp58nfPAYwuerruPNWmlStWAXf0UTqRtg4hQDWBuUFDJTuWuuBvEXudz74eh/wK
sMwfu1HFvjy5Z0iMDU8PUDepjVolOCue9ashlS4EB5IECdSR2TItnAIiIwimx839
LdUdRudafMu5T5Xma182OC0/u/xRlEm+tvKGGmfFcN0piqVl8OrSPBgIlb+1IKJE
m/XriWr/Cq4h/JfB7NTsezVslgkBaoU=
-----END CERTIFICATE-----
"""
ssl_context.load_verify_locations(cadata=cadata)
broker_port = secrets["broker_port"]
# Set up a MiniMQTT Client
mqtt_client = MQTT.MQTT(
broker=secrets["broker"],
port=broker_port,
socket_pool=pool,
ssl_context=ssl_context,
is_ssl=True,
)
mqtt_client.enable_logger(logging, log_level=logging.INFO)
# Connect callback handlers to mqtt_client
mqtt_client.on_connect = connect
mqtt_client.on_disconnect = disconnect
mqtt_client.on_publish = publish
mqtt_client.on_message = message
logger.info(f"Attempting to connect to MQTT broker {mqtt_client.broker} on port {broker_port}")
mqtt_client.connect()
mqtt_topic = secrets["mqtt_topic"]
logger.info(f"Subscribing to {mqtt_topic}")
mqtt_client.subscribe(mqtt_topic)
SIZE = 1024
data = {'FRAME': [25.8683] * SIZE, 'C': 24.3511, 'RH': 16.9207}
logger.info("Entering loop")
while True:
mqtt_client.loop(timeout=1)
logger.info("Out from loop()")
logger.info(f"Publishing to {mqtt_topic}")
mqtt_client.publish(mqtt_topic, json.dumps(data))
blink(pixel)
logger.info(f"Disconnecting from MQTT broker")
mqtt_client.disconnect()
try:
main()
# pylint: disable=broad-except
except Exception as e:
# This assumes that such exceptions are quite rare.
# Otherwise this would drain the battery quickly.
print("Code stopped by unhandled exception:")
print(traceback.format_exception(None, e, e.__traceback__))
RELOAD_TIME = 10
print(f"Performing a supervisor reload in {RELOAD_TIME} seconds")
time.sleep(RELOAD_TIME)
supervisor.reload()and works fine: |
|
@vladak Thank you for the test! Seeing as there is no allocation issue anymore, I'll close the issue. |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
This is related to #101 and #81 (I think) but I have a single simple script (attached, zipped for github reasons) that reproduces both problems by adjusting the size of the message. Publishing one particular message gives MemoryError: memory allocation failed, while larger messages than that stop the client from interacting with the broker, resulting in disconnects.
Platform: UnexpectedMaker FeatherS2; No Peripherals
USB: power and serial; LiPo connected
boot_out.txt : Adafruit CircuitPython 7.2.5 on 2022-04-06; FeatherS2 with ESP32S2
Board ID:unexpectedmaker_feathers2
[Just tested on Adafruit MagTag and the behavior is the same as the FeatherS2.]
Working control platform: Same data (up to FRAME size 768) works with same broker CP and lib versions
and client running on Feather M4 Express with AirLift Wing
MQTT Broker: mosquitto version 1.4.15
By varying the size of the message (json encoded) you get different results:
payload = {'FRAME': [25.8683] * SIZE, 'C': 24.3511, 'RH': 16.9207}SIZE <=313
NO ERROR, payload is published and read back on subscribed topic.
SIZE = 314
Payload is published, but MemoryError is thrown when mqtt_client.loop() is called
Traceback (most recent call last):
File "main.py", line 70, in
File "adafruit_minimqtt/adafruit_minimqtt.py", line 805, in loop
File "adafruit_minimqtt/adafruit_minimqtt.py", line 854, in _wait_for_msg
File "adafruit_minimqtt/adafruit_minimqtt.py", line 902, in _sock_exact_recv
MemoryError: memory allocation failed, allocating 4294952961 bytes
SIZE >=315
Broker never receives PUBLISH from client;
client stops sending PINGREQ; Broker disconnects @ timeout.
Client traceback:
Traceback (most recent call last):
File "main.py", line 63, in
File "adafruit_minimqtt/adafruit_minimqtt.py", line 802, in loop
File "adafruit_minimqtt/adafruit_minimqtt.py", line 565, in ping
MMQTTException: PINGRESP not returned from broker.
SIZE >=315 [alternate while loop timing]
If one adjusts the while loop to force a second publish before the timeout,
the 2nd time is publish is called, a message of the correct size
gets to broker; broker sends message back, reports socket error and disconnects.
Client traceback:
Traceback (most recent call last):
File "main.py", line 70, in
File "adafruit_minimqtt/adafruit_minimqtt.py", line 802, in loop
File "adafruit_minimqtt/adafruit_minimqtt.py", line 556, in ping
OSError: [Errno 104] ECONNRESET
Broker Log (2nd publish):
1649712800: Received PUBLISH from coop_v0 (d0, q0, r0, m0, 'test_zz', ... (2875 bytes))
1649712800: Sending PUBLISH to coop_v0 (d0, q0, r0, m0, 'test_zz', ... (2875 bytes))
1649712800: Socket error on client coop_v0, disconnecting.
main.zip
The text was updated successfully, but these errors were encountered: