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

Add exception stack traces to logging #106

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
24 changes: 13 additions & 11 deletions amqtt/broker.py
Expand Up @@ -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)

Expand Down Expand Up @@ -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)

Expand All @@ -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
Expand Down Expand Up @@ -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")
Expand Down Expand Up @@ -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):
"""
Expand Down
4 changes: 2 additions & 2 deletions amqtt/client.py
Expand Up @@ -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"
Expand Down Expand Up @@ -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)

Expand Down
4 changes: 2 additions & 2 deletions amqtt/mqtt/protocol/client_handler.py
Expand Up @@ -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
Expand Down
8 changes: 4 additions & 4 deletions amqtt/mqtt/protocol/handler.py
Expand Up @@ -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))
Expand Down Expand Up @@ -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):
Expand Down
10 changes: 6 additions & 4 deletions amqtt/plugins/manager.py
Expand Up @@ -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):
"""
Expand Down
10 changes: 6 additions & 4 deletions amqtt/plugins/persistence.py
Expand Up @@ -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(
Expand All @@ -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:
Expand Down
4 changes: 2 additions & 2 deletions amqtt/scripts/sub_script.py
Expand Up @@ -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")

Expand Down
4 changes: 2 additions & 2 deletions amqtt/utils.py
Expand Up @@ -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
8 changes: 4 additions & 4 deletions docs/references/mqttclient.rst
Expand Up @@ -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"
Expand Down Expand Up @@ -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()


Expand Down
4 changes: 2 additions & 2 deletions samples/client_publish.py
Expand Up @@ -44,8 +44,8 @@ async def test_coro2():
await C.publish("a/b", b"TEST MESSAGE WITH QOS_2", qos=0x02)
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()


Expand Down
4 changes: 2 additions & 2 deletions samples/client_publish_acl.py
Expand Up @@ -25,8 +25,8 @@ async def test_coro():
await C.publish("calendar/amqtt/releases", b"NEW RELEASE", qos=0x01)
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()


Expand Down
4 changes: 2 additions & 2 deletions samples/client_subscribe.py
Expand Up @@ -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)
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
logger.error("Client exception", exc_info=True)
logger.exception("Client exception")

As you suggested in #105 the exception shortcut is nice 👍 This could be an opportunity to move to it.



if __name__ == "__main__":
Expand Down
4 changes: 2 additions & 2 deletions samples/client_subscribe_acl.py
Expand Up @@ -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__":
Expand Down