From 3a9f79b7565dcd743b5acc0cddb105bde33a4807 Mon Sep 17 00:00:00 2001 From: dgtlmoon Date: Mon, 29 Jan 2024 12:55:08 +0100 Subject: [PATCH] Notification - logging - adding performance information for processing time of notifications #327 --- changedetectionio/notification.py | 5 +++++ changedetectionio/update_worker.py | 7 +++++-- 2 files changed, 10 insertions(+), 2 deletions(-) diff --git a/changedetectionio/notification.py b/changedetectionio/notification.py index 7d143d5b..b2046004 100644 --- a/changedetectionio/notification.py +++ b/changedetectionio/notification.py @@ -116,6 +116,9 @@ def apprise_custom_api_call_wrapper(body, title, notify_type, *args, **kwargs): def process_notification(n_object, datastore): + now = time.time() + if n_object.get('notification_timestamp'): + logger.trace(f"Time since queued {now-n_object['notification_timestamp']:.3f}s") # Insert variables into the notification content notification_parameters = create_notification_parameters(n_object, datastore) @@ -133,6 +136,8 @@ def process_notification(n_object, datastore): # Initially text or whatever n_format = datastore.data['settings']['application'].get('notification_format', valid_notification_formats[default_notification_format]) + logger.trace(f"Complete notification body including Jinja and placeholders calculated in {time.time() - now:.3f}s") + # https://github.com/caronc/apprise/wiki/Development_LogCapture # Anything higher than or equal to WARNING (which covers things like Connection errors) # raise it as an exception diff --git a/changedetectionio/update_worker.py b/changedetectionio/update_worker.py index bff2c34a..469ee6ca 100644 --- a/changedetectionio/update_worker.py +++ b/changedetectionio/update_worker.py @@ -31,6 +31,8 @@ class update_worker(threading.Thread): dates = [] trigger_text = '' + now = time.time() + if watch: watch_history = watch.history dates = list(watch_history.keys()) @@ -72,13 +74,14 @@ class update_worker(threading.Thread): 'diff_full': diff.render_diff(prev_snapshot, current_snapshot, include_equal=True, line_feed_sep=line_feed_sep), 'diff_patch': diff.render_diff(prev_snapshot, current_snapshot, line_feed_sep=line_feed_sep, patch_format=True), 'diff_removed': diff.render_diff(prev_snapshot, current_snapshot, include_added=False, line_feed_sep=line_feed_sep), + 'notification_timestamp': now, 'screenshot': watch.get_screenshot() if watch and watch.get('notification_screenshot') else None, 'triggered_text': triggered_text, 'uuid': watch.get('uuid') if watch else None, 'watch_url': watch.get('url') if watch else None, }) - - logger.debug(">> SENDING NOTIFICATION") + logger.trace(f"Main rendered notification placeholders (diff_added etc) calculated in {time.time()-now:.3f}s") + logger.debug("Queued notification for sending") notification_q.put(n_object) # Prefer - Individual watch settings > Tag settings > Global settings (in that order)