From 7468a0941ff207fbec25c7fa655fdefd57171317 Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Sun, 5 Feb 2023 12:41:09 +0100 Subject: [PATCH 1/6] use NullHandler by default fixes #146 --- adafruit_minimqtt/adafruit_minimqtt.py | 120 +++++++++++-------------- requirements.txt | 1 + 2 files changed, 53 insertions(+), 68 deletions(-) diff --git a/adafruit_minimqtt/adafruit_minimqtt.py b/adafruit_minimqtt/adafruit_minimqtt.py index 57de22da..b8838694 100644 --- a/adafruit_minimqtt/adafruit_minimqtt.py +++ b/adafruit_minimqtt/adafruit_minimqtt.py @@ -31,7 +31,10 @@ import struct import time from random import randint + +import adafruit_logging as logging from micropython import const + from .matcher import MQTTMatcher __version__ = "0.0.0+auto.0" @@ -186,7 +189,7 @@ def __init__( self._msg_size_lim = MQTT_MSG_SZ_LIM self._pid = 0 self._timestamp = 0 - self.logger = None + self._init_logger() self._reconnect_attempt = 0 self._reconnect_timeout = float(0) @@ -270,9 +273,9 @@ def _get_connect_socket(self, host, port, *, timeout=1): "ssl_context must be set before using adafruit_mqtt for secure MQTT." ) - if self.logger is not None and port == MQTT_TLS_PORT: + if port == MQTT_TLS_PORT: self.logger.info(f"Establishing a SECURE SSL connection to {host}:{port}") - elif self.logger is not None: + else: self.logger.info(f"Establishing an INSECURE connection to {host}:{port}") addr_info = self._socket_pool.getaddrinfo( @@ -352,8 +355,7 @@ def will_set(self, topic=None, payload=None, qos=0, retain=False): :param bool retain: Specifies if the payload is to be retained when it is published. """ - if self.logger is not None: - self.logger.debug("Setting last will properties") + self.logger.debug("Setting last will properties") self._valid_qos(qos) if self._is_connected: raise MMQTTException("Last Will should only be called before connect().") @@ -502,8 +504,7 @@ def _connect(self, clean_session=True, host=None, port=None, keep_alive=None): if keep_alive: self.keep_alive = keep_alive - if self.logger is not None: - self.logger.debug("Attempting to establish MQTT connection...") + self.logger.debug("Attempting to establish MQTT connection...") if self._reconnect_attempt > 0: if self.logger is not None: @@ -565,11 +566,9 @@ def _connect(self, clean_session=True, host=None, port=None, keep_alive=None): fixed_header.append(remaining_length) fixed_header.append(0x00) - if self.logger is not None: - self.logger.debug("Sending CONNECT packet to broker...") - self.logger.debug( - "Fixed Header: %s\nVariable Header: %s", fixed_header, var_header - ) + self.logger.debug("Sending CONNECT to broker...") + self.logger.debug(f"Fixed Header: {fixed_header}") + self.logger.debug(f"Variable Header: {var_header}") self._sock.send(fixed_header) self._sock.send(var_header) # [MQTT-3.1.3-4] @@ -581,8 +580,7 @@ def _connect(self, clean_session=True, host=None, port=None, keep_alive=None): if self._username is not None: self._send_str(self._username) self._send_str(self._password) - if self.logger is not None: - self.logger.debug("Receiving CONNACK packet from broker") + self.logger.debug("Receiving CONNACK packet from broker") stamp = time.monotonic() while True: op = self._wait_for_msg() @@ -607,15 +605,12 @@ def _connect(self, clean_session=True, host=None, port=None, keep_alive=None): def disconnect(self): """Disconnects the MiniMQTT client from the MQTT broker.""" self._connected() - if self.logger is not None: - self.logger.debug("Sending DISCONNECT packet to broker") + self.logger.debug("Sending DISCONNECT packet to broker") try: self._sock.send(MQTT_DISCONNECT) except RuntimeError as e: - if self.logger is not None: - self.logger.warning(f"Unable to send DISCONNECT packet: {e}") - if self.logger is not None: - self.logger.debug("Closing socket") + self.logger.warning(f"Unable to send DISCONNECT packet: {e}") + self.logger.debug("Closing socket") self._sock.close() self._is_connected = False self._subscribed_topics = [] @@ -628,8 +623,7 @@ def ping(self): Returns response codes of any messages received while waiting for PINGRESP. """ self._connected() - if self.logger is not None: - self.logger.debug("Sending PINGREQ") + self.logger.debug("Sending PINGREQ") self._sock.send(MQTT_PINGREQ) ping_timeout = self.keep_alive stamp = time.monotonic() @@ -699,15 +693,14 @@ def publish(self, topic, msg, retain=False, qos=0): else: pub_hdr_fixed.append(remaining_length) - if self.logger is not None: - self.logger.debug( - "Sending PUBLISH\nTopic: %s\nMsg: %s\ - \nQoS: %d\nRetain? %r", - topic, - msg, - qos, - retain, - ) + self.logger.debug( + "Sending PUBLISH\nTopic: %s\nMsg: %s\ + \nQoS: %d\nRetain? %r", + topic, + msg, + qos, + retain, + ) self._sock.send(pub_hdr_fixed) self._sock.send(pub_hdr_var) self._sock.send(msg) @@ -777,9 +770,8 @@ def subscribe(self, topic, qos=0): topic_size = len(t.encode("utf-8")).to_bytes(2, "big") qos_byte = q.to_bytes(1, "big") packet += topic_size + t.encode() + qos_byte - if self.logger is not None: - for t, q in topics: - self.logger.debug("SUBSCRIBING to topic %s with QoS %d", t, q) + for t, q in topics: + self.logger.debug("SUBSCRIBING to topic %s with QoS %d", t, q) self._sock.send(packet) stamp = time.monotonic() while True: @@ -831,12 +823,10 @@ def unsubscribe(self, topic): for t in topics: topic_size = len(t.encode("utf-8")).to_bytes(2, "big") packet += topic_size + t.encode() - if self.logger is not None: - for t in topics: - self.logger.debug("UNSUBSCRIBING from topic %s", t) + for t in topics: + self.logger.debug("UNSUBSCRIBING from topic %s", t) self._sock.send(packet) - if self.logger is not None: - self.logger.debug("Waiting for UNSUBACK...") + self.logger.debug("Waiting for UNSUBACK...") while True: stamp = time.monotonic() op = self._wait_for_msg() @@ -909,17 +899,13 @@ def reconnect(self, resub_topics=True): """ - if self.logger is not None: - self.logger.debug("Attempting to reconnect with MQTT broker") - - ret = self.connect() - if self.logger is not None: - self.logger.debug("Reconnected with broker") + self.logger.debug("Attempting to reconnect with MQTT broker") + self.connect() + self.logger.debug("Reconnected with broker") if resub_topics: - if self.logger is not None: - self.logger.debug( - "Attempting to resubscribe to previously subscribed topics." - ) + self.logger.debug( + "Attempting to resubscribe to previously subscribed topics." + ) subscribed_topics = self._subscribed_topics.copy() self._subscribed_topics = [] while subscribed_topics: @@ -938,16 +924,16 @@ def loop(self, timeout=0): """ + self.logger.debug(f"waiting for messages for {timeout} seconds") if self._timestamp == 0: self._timestamp = time.monotonic() current_time = time.monotonic() if current_time - self._timestamp >= self.keep_alive: self._timestamp = 0 # Handle KeepAlive by expecting a PINGREQ/PINGRESP from the server - if self.logger is not None: - self.logger.debug( - "KeepAlive period elapsed - requesting a PINGRESP from the server..." - ) + self.logger.debug( + "KeepAlive period elapsed - requesting a PINGRESP from the server..." + ) rcs = self.ping() return rcs @@ -960,10 +946,9 @@ def loop(self, timeout=0): if rc is None: break if time.monotonic() - stamp > self._recv_timeout: - if self.logger is not None: - self.logger.debug( - f"Loop timed out, message queue not empty after {self._recv_timeout}s" - ) + self.logger.debug( + f"Loop timed out, message queue not empty after {self._recv_timeout}s" + ) break rcs.append(rc) @@ -996,8 +981,7 @@ def _wait_for_msg(self, timeout=0.1): # If we get here, it means that there is nothing to be received return None if res[0] & MQTT_PKT_TYPE_MASK == MQTT_PINGRESP: - if self.logger is not None: - self.logger.debug("Got PINGRESP") + self.logger.debug("Got PINGRESP") sz = self._sock_exact_recv(1)[0] if sz != 0x00: raise MMQTTException(f"Unexpected PINGRESP returned from broker: {sz}.") @@ -1029,10 +1013,7 @@ def _wait_for_msg(self, timeout=0.1): # read message contents raw_msg = self._sock_exact_recv(sz) msg = raw_msg if self._use_binary_mode else str(raw_msg, "utf-8") - if self.logger is not None: - self.logger.debug( - "Receiving PUBLISH \nTopic: %s\nMsg: %s\n", topic, raw_msg - ) + self.logger.debug("Receiving PUBLISH \nTopic: %s\nMsg: %s\n", topic, raw_msg) self._handle_on_message(self, topic, msg) if res[0] & 0x06 == 0x02: pkt = bytearray(b"\x40\x02\0\0") @@ -1101,8 +1082,7 @@ def _sock_exact_recv(self, bufsize): # This will timeout with socket timeout (not keepalive timeout) rc = self._sock.recv(bufsize) if not rc: - if self.logger is not None: - self.logger.debug("_sock_exact_recv timeout") + self.logger.debug("_sock_exact_recv timeout") # If no bytes waiting, raise same exception as socketpool raise OSError(errno.ETIMEDOUT) # If any bytes waiting, try to read them all, @@ -1187,6 +1167,7 @@ def enable_logger(self, log_pkg, log_level=20, logger_name="log"): :return logger object """ + # pylint: disable=attribute-defined-outside-init self.logger = log_pkg.getLogger(logger_name) self.logger.setLevel(log_level) @@ -1194,6 +1175,9 @@ def enable_logger(self, log_pkg, log_level=20, logger_name="log"): def disable_logger(self): """Disables logging.""" - if not self.logger: - raise MMQTTException("Can not disable logger, no logger found.") - self.logger = None + self._init_logger() + + def _init_logger(self): + """Initializes logger to use NullHandler, i.e. no logging will be done.""" + self.logger = logging.getLogger("") + self.logger.addHandler(logging.NullHandler()) diff --git a/requirements.txt b/requirements.txt index 7a984a47..598c926a 100644 --- a/requirements.txt +++ b/requirements.txt @@ -3,3 +3,4 @@ # SPDX-License-Identifier: Unlicense Adafruit-Blinka +adafruit-circuitpython-logging From 033a5a13c4f7e042e6aec107e8c87b216608d8b5 Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Sun, 5 Feb 2023 22:49:19 +0100 Subject: [PATCH 2/6] document the new dependency --- README.rst | 1 + 1 file changed, 1 insertion(+) diff --git a/README.rst b/README.rst index 2ca1660e..077966c9 100644 --- a/README.rst +++ b/README.rst @@ -24,6 +24,7 @@ Dependencies This driver depends on: * `Adafruit CircuitPython `_ +* `Adafruit CircuitPython Logging `_ Please ensure all dependencies are available on the CircuitPython filesystem. This is easily achieved by downloading From 6d8b72a1e47be5073b6107dd03451d5d0fe202aa Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Tue, 14 Feb 2023 23:32:25 +0100 Subject: [PATCH 3/6] avoid importing logging use fake logger instead --- README.rst | 1 - adafruit_minimqtt/adafruit_minimqtt.py | 19 +++++++++++++++---- requirements.txt | 1 - 3 files changed, 15 insertions(+), 6 deletions(-) diff --git a/README.rst b/README.rst index 077966c9..2ca1660e 100644 --- a/README.rst +++ b/README.rst @@ -24,7 +24,6 @@ Dependencies This driver depends on: * `Adafruit CircuitPython `_ -* `Adafruit CircuitPython Logging `_ Please ensure all dependencies are available on the CircuitPython filesystem. This is easily achieved by downloading diff --git a/adafruit_minimqtt/adafruit_minimqtt.py b/adafruit_minimqtt/adafruit_minimqtt.py index b8838694..a1ba3911 100644 --- a/adafruit_minimqtt/adafruit_minimqtt.py +++ b/adafruit_minimqtt/adafruit_minimqtt.py @@ -32,7 +32,6 @@ import time from random import randint -import adafruit_logging as logging from micropython import const from .matcher import MQTTMatcher @@ -127,6 +126,19 @@ def wrap_socket(self, socket, server_hostname=None): return _FakeSSLSocket(socket, self._iface.TLS_MODE) +class NullLogger: + """Fake logger class that does not do anything""" + + # pylint: disable=unused-argument + def nothing(self, msg: str, *args) -> None: + """no action""" + pass + + def __init__(self): + for log_level in ["debug", "info", "warning", "error", "critical"]: + setattr(NullLogger, log_level, self.nothing) + + class MQTT: """MQTT Client for CircuitPython. @@ -1178,6 +1190,5 @@ def disable_logger(self): self._init_logger() def _init_logger(self): - """Initializes logger to use NullHandler, i.e. no logging will be done.""" - self.logger = logging.getLogger("") - self.logger.addHandler(logging.NullHandler()) + """Initializes logger to NullLogger, i.e. no logging will be done.""" + self.logger = NullLogger() diff --git a/requirements.txt b/requirements.txt index 598c926a..7a984a47 100644 --- a/requirements.txt +++ b/requirements.txt @@ -3,4 +3,3 @@ # SPDX-License-Identifier: Unlicense Adafruit-Blinka -adafruit-circuitpython-logging From f0720840b6dc8d08dc4cb985ace037024a8175d0 Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Tue, 14 Feb 2023 23:41:26 +0100 Subject: [PATCH 4/6] fix rebase --- adafruit_minimqtt/adafruit_minimqtt.py | 66 +++++++++++--------------- 1 file changed, 28 insertions(+), 38 deletions(-) diff --git a/adafruit_minimqtt/adafruit_minimqtt.py b/adafruit_minimqtt/adafruit_minimqtt.py index a1ba3911..d5143554 100644 --- a/adafruit_minimqtt/adafruit_minimqtt.py +++ b/adafruit_minimqtt/adafruit_minimqtt.py @@ -298,10 +298,9 @@ def _get_connect_socket(self, host, port, *, timeout=1): sock = self._socket_pool.socket(addr_info[0], addr_info[1]) except OSError as exc: # Do not consider this for back-off. - if self.logger is not None: - self.logger.warning( - f"Failed to create socket for host {addr_info[0]} and port {addr_info[1]}" - ) + self.logger.warning( + f"Failed to create socket for host {addr_info[0]} and port {addr_info[1]}" + ) raise TemporaryError from exc connect_host = addr_info[-1][0] @@ -315,8 +314,7 @@ def _get_connect_socket(self, host, port, *, timeout=1): sock.connect((connect_host, port)) except MemoryError as exc: sock.close() - if self.logger is not None: - self.logger.warning(f"Failed to allocate memory for connect: {exc}") + self.logger.warning(f"Failed to allocate memory for connect: {exc}") # Do not consider this for back-off. raise TemporaryError from exc except OSError as exc: @@ -461,10 +459,10 @@ def connect(self, clean_session=True, host=None, port=None, keep_alive=None): self._recompute_reconnect_backoff() else: self._reset_reconnect_backoff() - if self.logger is not None: - self.logger.debug( - f"Attempting to connect to MQTT broker (attempt #{self._reconnect_attempt})" - ) + + self.logger.debug( + f"Attempting to connect to MQTT broker (attempt #{self._reconnect_attempt})" + ) try: ret = self._connect( @@ -476,18 +474,15 @@ def connect(self, clean_session=True, host=None, port=None, keep_alive=None): self._reset_reconnect_backoff() return ret except TemporaryError as e: - if self.logger is not None: - self.logger.warning(f"temporary error when connecting: {e}") + self.logger.warning(f"temporary error when connecting: {e}") backoff = False except OSError as e: last_exception = e - if self.logger is not None: - self.logger.info(f"failed to connect: {e}") + self.logger.info(f"failed to connect: {e}") backoff = True except MMQTTException as e: last_exception = e - if self.logger is not None: - self.logger.info(f"MMQT error: {e}") + self.logger.info(f"MMQT error: {e}") backoff = True if self._reconnect_attempts_max > 1: @@ -519,10 +514,9 @@ def _connect(self, clean_session=True, host=None, port=None, keep_alive=None): self.logger.debug("Attempting to establish MQTT connection...") if self._reconnect_attempt > 0: - if self.logger is not None: - self.logger.debug( - f"Sleeping for {self._reconnect_timeout:.3} seconds due to connect back-off" - ) + self.logger.debug( + f"Sleeping for {self._reconnect_timeout:.3} seconds due to connect back-off" + ) time.sleep(self._reconnect_timeout) # Get a new socket @@ -867,29 +861,26 @@ def _recompute_reconnect_backoff(self): """ self._reconnect_attempt = self._reconnect_attempt + 1 self._reconnect_timeout = 2**self._reconnect_attempt - if self.logger is not None: - # pylint: disable=consider-using-f-string - self.logger.debug( - "Reconnect timeout computed to {:.2f}".format(self._reconnect_timeout) - ) + # pylint: disable=consider-using-f-string + self.logger.debug( + "Reconnect timeout computed to {:.2f}".format(self._reconnect_timeout) + ) if self._reconnect_timeout > self._reconnect_maximum_backoff: - if self.logger is not None: - self.logger.debug( - f"Truncating reconnect timeout to {self._reconnect_maximum_backoff} seconds" - ) + self.logger.debug( + f"Truncating reconnect timeout to {self._reconnect_maximum_backoff} seconds" + ) self._reconnect_timeout = float(self._reconnect_maximum_backoff) # Add a sub-second jitter. # Even truncated timeout should have jitter added to it. This is why it is added here. jitter = randint(0, 1000) / 1000 - if self.logger is not None: - # pylint: disable=consider-using-f-string - self.logger.debug( - "adding jitter {:.2f} to {:.2f} seconds".format( - jitter, self._reconnect_timeout - ) + # pylint: disable=consider-using-f-string + self.logger.debug( + "adding jitter {:.2f} to {:.2f} seconds".format( + jitter, self._reconnect_timeout ) + ) self._reconnect_timeout += jitter def _reset_reconnect_backoff(self): @@ -897,8 +888,7 @@ def _reset_reconnect_backoff(self): Reset reconnect back-off to the initial state. """ - if self.logger is not None: - self.logger.debug("Resetting reconnect backoff") + self.logger.debug("Resetting reconnect backoff") self._reconnect_attempt = 0 self._reconnect_timeout = float(0) @@ -912,7 +902,7 @@ def reconnect(self, resub_topics=True): """ self.logger.debug("Attempting to reconnect with MQTT broker") - self.connect() + ret = self.connect() self.logger.debug("Reconnected with broker") if resub_topics: self.logger.debug( From dd56de3a535031706afc7003ea7169b40dd5e3ca Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Wed, 15 Feb 2023 10:59:21 +0100 Subject: [PATCH 5/6] get rid of separate logger init function also document the self.logger --- adafruit_minimqtt/adafruit_minimqtt.py | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) diff --git a/adafruit_minimqtt/adafruit_minimqtt.py b/adafruit_minimqtt/adafruit_minimqtt.py index d5143554..31700699 100644 --- a/adafruit_minimqtt/adafruit_minimqtt.py +++ b/adafruit_minimqtt/adafruit_minimqtt.py @@ -201,7 +201,9 @@ def __init__( self._msg_size_lim = MQTT_MSG_SZ_LIM self._pid = 0 self._timestamp = 0 - self._init_logger() + self.logger = NullLogger() + """An optional logging attribute that can be set with with a Logger + to enable debug logging.""" self._reconnect_attempt = 0 self._reconnect_timeout = float(0) @@ -1177,8 +1179,4 @@ def enable_logger(self, log_pkg, log_level=20, logger_name="log"): def disable_logger(self): """Disables logging.""" - self._init_logger() - - def _init_logger(self): - """Initializes logger to NullLogger, i.e. no logging will be done.""" self.logger = NullLogger() From d9d5cceb39d7ed54710e22af737940d258dd1023 Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Wed, 15 Feb 2023 11:03:53 +0100 Subject: [PATCH 6/6] remove trailing whitespace --- adafruit_minimqtt/adafruit_minimqtt.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/adafruit_minimqtt/adafruit_minimqtt.py b/adafruit_minimqtt/adafruit_minimqtt.py index 31700699..2d74dd92 100644 --- a/adafruit_minimqtt/adafruit_minimqtt.py +++ b/adafruit_minimqtt/adafruit_minimqtt.py @@ -202,7 +202,7 @@ def __init__( self._pid = 0 self._timestamp = 0 self.logger = NullLogger() - """An optional logging attribute that can be set with with a Logger + """An optional logging attribute that can be set with with a Logger to enable debug logging.""" self._reconnect_attempt = 0