From 6ef4f0a59ccbbf78fc2a2e1a10af046562990ca7 Mon Sep 17 00:00:00 2001
From: Adam Miller <adam@archive.org>
Date: Wed, 15 Jan 2025 16:00:23 -0800
Subject: [PATCH] feat: additional behavior checking logging to inform future
 logic changes

---
 brozzler/browser.py | 25 ++++++++++++++++++++++++-
 1 file changed, 24 insertions(+), 1 deletion(-)

diff --git a/brozzler/browser.py b/brozzler/browser.py
index b3d9436..e64352a 100644
--- a/brozzler/browser.py
+++ b/brozzler/browser.py
@@ -788,6 +788,8 @@ class Browser:
 
         check_interval = min(timeout, 7)
         start = time.time()
+        valid_behavior_checks = 0
+        invalid_behavior_checks = 0
         while True:
             elapsed = time.time() - start
             if elapsed > timeout:
@@ -807,6 +809,16 @@ class Browser:
                     lambda: self.websock_thread.received_result(msg_id), timeout=5
                 )
                 msg = self.websock_thread.pop_result(msg_id)
+                if (
+                    msg
+                    and "result" in msg["result"]
+                    and type(msg["result"]["result"]["value"]) is bool
+                    and not msg["result"]["result"]["value"]
+                ):
+                    # valid behavior response while still running
+                    # {'id': 8, 'result': {'result': {'type': 'boolean', 'value': False}}}
+                    valid_behavior_checks += 1
+
                 if (
                     msg
                     and "result" in msg
@@ -818,8 +830,19 @@ class Browser:
                     and type(msg["result"]["result"]["value"]) == bool
                     and msg["result"]["result"]["value"]
                 ):
-                    self.logger.info("behavior decided it has finished")
+                    # valid behavior response when finished
+                    # {'id': 9, 'result': {'result': {'type': 'boolean', 'value': True}}}
+                    elapsed = time.time() - start
+                    self.logger.info(
+                        "behavior decided it has finished after %.1fs and %s valid checks, "
+                        "and %s invalid checks",
+                        elapsed,
+                        valid_behavior_checks,
+                        invalid_behavior_checks,
+                    )
                     return
+                invalid_behavior_checks += 1
+
             except BrowsingTimeout:
                 pass