From fe3cf5ffd257ad66cfebc2c8d93171e964a9d36c Mon Sep 17 00:00:00 2001
From: dgtlmoon <dgtlmoon@gmail.com>
Date: Mon, 29 Jan 2024 11:21:21 +0100
Subject: [PATCH] Logging - Adding extra debug logging to change detection
 (#2136)

---
 changedetectionio/processors/restock_diff.py   | 8 +++++---
 changedetectionio/processors/text_json_diff.py | 6 ++++--
 changedetectionio/update_worker.py             | 6 +++---
 3 files changed, 12 insertions(+), 8 deletions(-)

diff --git a/changedetectionio/processors/restock_diff.py b/changedetectionio/processors/restock_diff.py
index a590f73d..e692e7cb 100644
--- a/changedetectionio/processors/restock_diff.py
+++ b/changedetectionio/processors/restock_diff.py
@@ -1,8 +1,9 @@
 
-import hashlib
-import urllib3
 from . import difference_detection_processor
 from copy import deepcopy
+from loguru import logger
+import hashlib
+import urllib3
 
 urllib3.disable_warnings(urllib3.exceptions.InsecureRequestWarning)
 
@@ -43,11 +44,13 @@ class perform_site_check(difference_detection_processor):
             fetched_md5 = hashlib.md5(self.fetcher.instock_data.encode('utf-8')).hexdigest()
             # 'Possibly in stock' comes from stock-not-in-stock.js when no string found above the fold.
             update_obj["in_stock"] = True if self.fetcher.instock_data == 'Possibly in stock' else False
+            logger.debug(f"Watch UUID {uuid} restock check returned '{self.fetcher.instock_data}' from JS scraper.")
         else:
             raise UnableToExtractRestockData(status_code=self.fetcher.status_code)
 
         # The main thing that all this at the moment comes down to :)
         changed_detected = False
+        logger.debug(f"Watch UUID {uuid} restock check - Previous MD5: {watch.get('previous_md5')}, Fetched MD5 {fetched_md5}")
 
         if watch.get('previous_md5') and watch.get('previous_md5') != fetched_md5:
             # Yes if we only care about it going to instock, AND we are in stock
@@ -60,5 +63,4 @@ class perform_site_check(difference_detection_processor):
 
         # Always record the new checksum
         update_obj["previous_md5"] = fetched_md5
-
         return changed_detected, update_obj, self.fetcher.instock_data.encode('utf-8').strip()
diff --git a/changedetectionio/processors/text_json_diff.py b/changedetectionio/processors/text_json_diff.py
index 94fea913..305cfe17 100644
--- a/changedetectionio/processors/text_json_diff.py
+++ b/changedetectionio/processors/text_json_diff.py
@@ -6,11 +6,11 @@ import os
 import re
 import urllib3
 
+from . import difference_detection_processor
+from ..html_tools import PERL_STYLE_REGEX, cdata_in_document_to_text
 from changedetectionio import content_fetcher, html_tools
 from changedetectionio.blueprint.price_data_follower import PRICE_DATA_TRACK_ACCEPT, PRICE_DATA_TRACK_REJECT
 from copy import deepcopy
-from . import difference_detection_processor
-from ..html_tools import PERL_STYLE_REGEX, cdata_in_document_to_text
 from loguru import logger
 
 urllib3.disable_warnings(urllib3.exceptions.InsecureRequestWarning)
@@ -335,6 +335,8 @@ class perform_site_check(difference_detection_processor):
                 if not watch['title'] or not len(watch['title']):
                     update_obj['title'] = html_tools.extract_element(find='title', html_content=self.fetcher.content)
 
+        logger.debug(f"Watch UUID {uuid} content check - Previous MD5: {watch.get('previous_md5')}, Fetched MD5 {fetched_md5}")
+
         if changed_detected:
             if watch.get('check_unique_lines', False):
                 has_unique_lines = watch.lines_contain_something_unique_compared_to_history(lines=stripped_text_from_html.splitlines())
diff --git a/changedetectionio/update_worker.py b/changedetectionio/update_worker.py
index 538a8a32..bff2c34a 100644
--- a/changedetectionio/update_worker.py
+++ b/changedetectionio/update_worker.py
@@ -471,13 +471,13 @@ class update_worker(threading.Thread):
 
                             # A change was detected
                             if changed_detected:
-                                logger.debug(f">> Change detected in UUID {uuid} - {watch['url']}")
-
                                 # Notifications should only trigger on the second time (first time, we gather the initial snapshot)
                                 if watch.history_n >= 2:
+                                    logger.info(f"Change detected in UUID {uuid} - {watch['url']}")
                                     if not self.datastore.data['watching'][uuid].get('notification_muted'):
                                         self.send_content_changed_notification(watch_uuid=uuid)
-
+                                else:
+                                    logger.info(f"Change triggered in UUID {uuid} due to first history saving (no notifications sent) - {watch['url']}")
 
                         except Exception as e:
                             # Catch everything possible here, so that if a worker crashes, we don't lose it until restart!