Add exception stack traces to logging. Fixes #105

amqtt/broker.py

@@ -250,7 +250,7 @@ async def start(self) -> None:
         except (MachineError, ValueError) as exc:
             # Backwards compat: MachineError is raised by transitions < 0.5.0.
             self.logger.warning(
-                "[WARN-0001] Invalid method call at this moment: %s" % exc
+                "[WARN-0001] Invalid method call at this moment", exc_info=True
             )
             raise BrokerException("Broker instance can't be started: %s" % exc)
 
@@ -347,7 +347,7 @@ async def start(self) -> None:
 
             self.logger.debug("Broker started")
         except Exception as e:
-            self.logger.error("Broker startup failed: %s" % e)
+            self.logger.error("Broker startup failed", exc_info=True)
             self.transitions.starting_fail()
             raise BrokerException("Broker instance can't be started: %s" % e)
 
@@ -364,7 +364,7 @@ async def shutdown(self):
             self.transitions.shutdown()
         except (MachineError, ValueError) as exc:
             # Backwards compat: MachineError is raised by transitions < 0.5.0.
-            self.logger.debug("Invalid method call at this moment: %s" % exc)
+            self.logger.debug("Invalid method call at this moment", exc_info=True)
             raise BrokerException("Broker instance can't be stopped: %s" % exc)
 
         # Fire broker_shutdown event to plugins
@@ -419,18 +419,20 @@ async def client_connected(
             handler, client_session = await BrokerProtocolHandler.init_from_connect(
                 reader, writer, self.plugins_manager
             )
-        except AMQTTException as exc:
+        except AMQTTException:
             self.logger.warning(
-                "[MQTT-3.1.0-1] %s: Can't read first packet an CONNECT: %s"
-                % (format_client_message(address=remote_address, port=remote_port), exc)
+                "[MQTT-3.1.0-1] %s: Can't read first packet an CONNECT"
+                % format_client_message(address=remote_address, port=remote_port),
+                exc_info=True,
             )
             # await writer.close()
             self.logger.debug("Connection closed")
             return
-        except MQTTException as me:
+        except MQTTException:
             self.logger.error(
-                "Invalid connection from %s : %s"
-                % (format_client_message(address=remote_address, port=remote_port), me)
+                "Invalid connection from %s"
+                % format_client_message(address=remote_address, port=remote_port),
+                exc_info=True,
             )
             await writer.close()
             self.logger.debug("Connection closed")
@@ -674,8 +676,8 @@ async def _stop_handler(self, handler):
         """
         try:
             await handler.stop()
-        except Exception as e:
-            self.logger.error(e)
+        except Exception:
+            self.logger.error("Failed to stop handler", exc_info=True)
 
     async def authenticate(self, session: Session, listener):
         """

amqtt/client.py

@@ -236,7 +236,7 @@ async def reconnect(self, cleansession=None):
             except asyncio.CancelledError:
                 raise
             except Exception as e:
-                self.logger.warning("Reconnection attempt failed: %r" % e)
+                self.logger.warning("Reconnection attempt failed", exc_info=True)
                 if reconnect_retries >= 0 and nb_attempt > reconnect_retries:
                     self.logger.error(
                         "Maximum number of connection attempts reached. Reconnection aborted"
@@ -487,7 +487,7 @@ async def _connect_coro(self):
                 "connection failed: invalid websocket handshake", ihs
             )
         except (ProtocolHandlerException, ConnectionError, OSError) as e:
-            self.logger.warning("MQTT connection failed: %r" % e)
+            self.logger.warning("MQTT connection failed", exc_info=True)
             self.session.transitions.disconnect()
             raise ConnectException(e)
 

amqtt/mqtt/protocol/client_handler.py

@@ -88,8 +88,8 @@ def handle_write_timeout(self):
             if not self._ping_task:
                 self.logger.debug("Scheduling Ping")
                 self._ping_task = asyncio.ensure_future(self.mqtt_ping())
-        except Exception as e:
-            self.logger.debug("Exception ignored in ping task: %r" % e)
+        except Exception:
+            self.logger.debug("Exception ignored in ping task", exc_info=True)
 
     def handle_read_timeout(self):
         pass

amqtt/mqtt/protocol/handler.py

@@ -150,8 +150,8 @@ async def stop(self):
         self.logger.debug("closing writer")
         try:
             await self.writer.close()
-        except Exception as e:
-            self.logger.debug("Handler writer close failed: %s" % e)
+        except Exception:
+            self.logger.debug("Handler writer close failed", exc_info=True)
 
     def _stop_waiters(self):
         self.logger.debug("Stopping %d puback waiters" % len(self._puback_waiters))
@@ -523,8 +523,8 @@ async def _send_packet(self, packet):
             await self.handle_connection_closed()
         except asyncio.CancelledError:
             raise
-        except Exception as e:
-            self.logger.warning("Unhandled exception: %s" % e)
+        except Exception:
+            self.logger.warning("Unhandled exception", exc_info=True)
             raise
 
     async def mqtt_deliver_next_message(self):

amqtt/plugins/manager.py

@@ -73,10 +73,12 @@ def _load_plugin(self, ep: pkg_resources.EntryPoint):
             plugin_context.logger = self.logger.getChild(ep.name)
             obj = plugin(plugin_context)
             return Plugin(ep.name, ep, obj)
-        except ImportError as ie:
-            self.logger.warning(f"Plugin {ep!r} import failed: {ie}")
-        except pkg_resources.UnknownExtra as ue:
-            self.logger.warning(f"Plugin {ep!r} dependencies resolution failed: {ue}")
+        except ImportError:
+            self.logger.warning(f"Plugin {ep!r} import failed", exc_info=True)
+        except pkg_resources.UnknownExtra:
+            self.logger.warning(
+                f"Plugin {ep!r} dependencies resolution failed", exc_info=True
+            )
 
     def get_plugin(self, name):
         """

amqtt/plugins/persistence.py

@@ -28,9 +28,9 @@ def init_db(self):
                 self.conn = sqlite3.connect(self.db_file)
                 self.cursor = self.conn.cursor()
                 self.context.logger.info("Database file '%s' opened" % self.db_file)
-            except Exception as e:
+            except Exception:
                 self.context.logger.error(
-                    f"Error while initializing database '{self.db_file}' : {e}"
+                    f"Error while initializing database '{self.db_file}'", exc_info=True
                 )
         if self.cursor:
             self.cursor.execute(
@@ -46,8 +46,10 @@ async def save_session(self, session):
                     (session.client_id, dump),
                 )
                 self.conn.commit()
-            except Exception as e:
-                self.context.logger.error(f"Failed saving session '{session}': {e}")
+            except Exception:
+                self.context.logger.error(
+                    f"Failed saving session '{session}'", exc_info=True
+                )
 
     async def find_session(self, client_id):
         if self.cursor:

amqtt/scripts/sub_script.py

@@ -104,8 +104,8 @@ async def do_sub(client, arguments):
         await client.disconnect()
     except KeyboardInterrupt:
         await client.disconnect()
-    except ConnectException as ce:
-        logger.fatal("connection to '%s' failed: %r" % (arguments["--url"], ce))
+    except ConnectException:
+        logger.fatal("connection to '%s' failed" % (arguments["--url"]), exc_info=True)
     except asyncio.CancelledError:
         logger.fatal("Publish canceled due to previous error")
 

amqtt/utils.py

@@ -41,6 +41,6 @@ def read_yaml_config(config_file: str) -> dict:
     try:
         with open(config_file) as stream:
             config = yaml.full_load(stream)
-    except yaml.YAMLError as exc:
-        logger.error("Invalid config_file %s: %r", config_file, exc)
+    except yaml.YAMLError:
+        logger.error("Invalid config_file %s", config_file, exc_info=True)
     return config

docs/references/mqttclient.rst

@@ -38,8 +38,8 @@ The example below shows how to write a simple MQTT client which subscribes a top
                 print("%d:  %s => %s" % (i, packet.variable_header.topic_name, str(packet.payload.data)))
             await C.unsubscribe(['$SYS/broker/uptime', '$SYS/broker/load/#'])
             await C.disconnect()
-        except ClientException as ce:
-            logger.error("Client exception: %s" % ce)
+        except ClientException:
+            logger.error("Client exception", exc_info=True)
 
     if __name__ == '__main__':
         formatter = "[%(asctime)s] %(name)s {%(filename)s:%(lineno)d} %(levelname)s - %(message)s"
@@ -93,8 +93,8 @@ This example also shows to method for publishing message asynchronously.
             #print(message)
             logger.info("messages published")
             await C.disconnect()
-        except ConnectException as ce:
-            logger.error("Connection failed: %s" % ce)
+        except ConnectException:
+            logger.error("Connection failed", exc_info=True)
             asyncio.get_event_loop().stop()
 
 

samples/client_publish.py

@@ -45,7 +45,7 @@ async def test_coro2():
         logger.info("messages published")
         await C.disconnect()
     except ConnectException as ce:
-        logger.error("Connection failed: %s" % ce)
+        logger.error("Connection failed", exc_info=True)
         asyncio.get_event_loop().stop()
 
 

samples/client_publish_acl.py

@@ -26,7 +26,7 @@ async def test_coro():
         logger.info("messages published")
         await C.disconnect()
     except ConnectException as ce:
-        logger.error("Connection failed: %s" % ce)
+        logger.error("Connection failed", exc_info=True)
         asyncio.get_event_loop().stop()
 
 

samples/client_subscribe.py

@@ -36,8 +36,8 @@ async def uptime_coro():
         await C.unsubscribe(["$SYS/broker/uptime", "$SYS/broker/load/#"])
         logger.info("UnSubscribed")
         await C.disconnect()
-    except ClientException as ce:
-        logger.error("Client exception: %s" % ce)
+    except ClientException:
+        logger.error("Client exception", exc_info=True)
 
 
 if __name__ == "__main__":

samples/client_subscribe_acl.py

@@ -40,8 +40,8 @@ async def uptime_coro():
         await C.unsubscribe(["$SYS/broker/uptime", "$SYS/broker/load/#"])
         logger.info("UnSubscribed")
         await C.disconnect()
-    except ClientException as ce:
-        logger.error("Client exception: %s" % ce)
+    except ClientException:
+        logger.error("Client exception", exc_info=True)
 
 
 if __name__ == "__main__":