From 060f52c0ef17d1dd771d07088ccdda96469a9c2d Mon Sep 17 00:00:00 2001 From: Goffi Date: Fri, 10 Mar 2023 17:01:09 +0100 Subject: [PATCH] core (xmpp): improve pluging timing log by using highest `profileConnected` time: previously the first `profileConnected` time was used, however it may not be the highest (if `profileConnecting` is high but not `profileConnected`). --- sat/core/xmpp.py | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/sat/core/xmpp.py b/sat/core/xmpp.py index 53338f4a..5a59881a 100644 --- a/sat/core/xmpp.py +++ b/sat/core/xmpp.py @@ -297,6 +297,9 @@ class SatXMPPEntity(core_types.SatXMPPEntity): list_d = defer.DeferredList(conn_cb_list) def logPluginResults(results): + if not results: + log.info("no plugin loaded") + return all_succeed = all([success for success, result in results]) if not all_succeed: log.error(_("Plugins initialisation error")) @@ -304,12 +307,13 @@ class SatXMPPEntity(core_types.SatXMPPEntity): if not success: plugin_name = plugin_conn_cb[idx][0]._info["import_name"] log.error(f"error (plugin {plugin_name}): {result}") + + log.debug(f"Plugin loading time for {profile!r} (longer to shorter):\n") plugins_by_timer = sorted( connection_timer, key=lambda p: connection_timer[p]["total"], reverse=True ) - log.debug(f"Plugin loading time for {profile!r} (longer to shorter):\n") # total is the addition of all connecting and connected, doesn't really # reflect the real loading time as connected are launched in a # DeferredList @@ -318,7 +322,7 @@ class SatXMPPEntity(core_types.SatXMPPEntity): # longuest connected (connected happen in parallel, thus the longuest is # roughly the total time for connected) total_real = 0 - total_real_first_connected = False + total_real = max(t.get("connected", 0) for t in connection_timer.values()) for plugin in plugins_by_timer: name = plugin._info["import_name"] @@ -334,10 +338,6 @@ class SatXMPPEntity(core_types.SatXMPPEntity): connected = f"{timer['connected']:.2f}s" except KeyError: connected = "n/a" - else: - if not total_real_first_connected: - total_real += timer['connected'] - total_real_first_connected = True log.debug( f" - {name}: total={timer['total']:.2f}s " f"connecting={connecting} connected={connected}"