Skip to content

Cancel the running watchdog timer when it is started again - #150

Merged
mezz64 merged 2 commits into
masterfrom
watchdog-orphan-timer
Nov 12, 2026
Merged

mezz64 merged 2 commits into
masterfrom
watchdog-orphan-timer

Conversation

@mezz64

@mezz64 mezz64 commented Nov 6, 2026 •

Copy link
Copy Markdown
Owner

Fixes #149.

Problem

Watchdog.start() replaced its timer without cancelling the one already running. When a device ends the alert stream normally, alert_stream() reconnects right away and starts the watchdog again. The previous timer was orphaned: pet() and stop() could no longer reach it, so it fired 300 s later and reset a healthy stream. The packet in flight was dropped and the stream was down for 10 s. The reporter's NVR (iDS-7608NXI-I2/8P/X) ended the stream 20 times in one hour, and each time a forced reset followed exactly 300 s later.

Changes

  • Watchdog.start() cancels the running timer before starting a new one. pet() is now just start().
  • Each timer carries a token, and an expiry is ignored unless it comes from the current timer. Timer.cancel() cannot stop a timer that has already fired, so without this, a timer replaced or stopped at the moment it expired could still reset the new connection.
  • A lock covers start(), stop() and the expiry check, which run on the stream thread and timer threads. The handler itself is called outside the lock, so a slow handler cannot hold up pet() and stop(), and the handler may call them itself (HikCamera.watchdog_handler() calls stop()).
  • alert_stream() logs at debug level when the device ends the stream. These reconnects were completely silent before.

Tests

  • New test/test_watchdog.py: restarting replaces the running timer, stop after a restart cancels every timer, pet postpones expiry, expiries from replaced or stopped timers are ignored, the handler can call stop() without deadlocking, and a slow handler does not block pet() and stop().
  • StreamReliabilityTestCase: two connections that the device ends normally leave every watchdog timer cancelled.

The new tests fail against the previous watchdog.py and pass with this change. The full suite passes (238 tests, 1 skipped). The timing-based watchdog tests passed 15 runs in a row.

🤖 Generated with Claude Code

Watchdog.start() replaced its timer without cancelling the old one. When
a device ends the alert stream normally, alert_stream() reconnects and
starts the watchdog again, so the previous timer was orphaned: pet() and
stop() could no longer reach it, and 300s later it reset a healthy
stream, dropping the packet in flight and taking the stream down for
10s.

start() now cancels the running timer first. Each timer also carries a
token, and an expiry is ignored unless it comes from the current timer,
since cancel() cannot stop a timer that has already fired. A reentrant
lock covers start, stop and expiry, which run on different threads.

alert_stream() now logs at debug level when the device ends the stream.

Fixes #149

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@baylanger

Copy link
Copy Markdown
Contributor

The handler HikCamera passes is instant, but Watchdog is a
public class and any handler that waits would stall the stream.

A slow handler can held up pet(), start() and stop() on the stream
thread until it returned.

Is this a better approach?

diff --git a/pyhik/watchdog.py b/pyhik/watchdog.py
index 3d2efb1..3697d37 100644
--- a/pyhik/watchdog.py
+++ b/pyhik/watchdog.py
@@ -6,7 +6,7 @@ Copyright (c) 2017-2018 John Mihalic <https://github.com/mezz64>
 Licensed under the MIT license.
 """
 
-from threading import RLock, Timer
+from threading import Lock, Timer
 
 
 class Watchdog(object):
@@ -21,8 +21,8 @@ class Watchdog(object):
         # replaced or stopped can tell it is stale.
         self._token = None
         # start(), pet() and stop() run on the stream thread while expiries
-        # run on timer threads. Reentrant because the handler may call stop().
-        self._lock = RLock()
+        # run on timer threads.
+        self._lock = Lock()
         return
 
     def start(self):
@@ -65,4 +65,6 @@ class Watchdog(object):
                 return
             self._timer = None
             self._token = None
-            self.handler()
+        # Outside the lock; a slow handler cannot hold up pet() and stop(),
+        # and the handler may call them.
+        self.handler()
diff --git a/test/test_watchdog.py b/test/test_watchdog.py
index 67f0b9d..711ac16 100644
--- a/test/test_watchdog.py
+++ b/test/test_watchdog.py
@@ -81,6 +81,28 @@ class WatchdogTestCase(unittest.TestCase):
         self.watchdog.start()
         self.assertTrue(returned.wait(TIMEOUT * 10))
 
+    def test_slow_handler_does_not_block_pet_and_stop(self):
+        entered = threading.Event()
+        release = threading.Event()
+
+        def handler():
+            entered.set()
+            release.wait(TIMEOUT * 20)
+
+        self.addCleanup(release.set)
+        self.watchdog.handler = handler
+        self.watchdog.start()
+        self.assertTrue(entered.wait(TIMEOUT * 10))
+        returned = threading.Event()
+
+        def pet_then_stop():
+            self.watchdog.pet()
+            self.watchdog.stop()
+            returned.set()
+
+        threading.Thread(target=pet_then_stop, daemon=True).start()
+        self.assertTrue(returned.wait(TIMEOUT * 5))
+
 
 if __name__ == '__main__':
     unittest.main()
-- 
2.43.0

Comment thread test/test_watchdog.py Outdated
def test_pet_postpones_expiry(self):
self.watchdog.start()
for _ in range(3):
time.sleep(TIMEOUT / 2)

@baylanger baylanger Nov 6, 2026 •

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

TIMEOUT / 2 leaves a small margin of 0.1s before the 0.2s timer fires... a slow CI could make the test fail by chance, perhaps changing to TIMEOUT / 4 which leaves 0.15s makes sense but ... maybe CI runner are never "overloaded" ?!

A slow handler held the lock, so pet(), start() and stop() on the stream
thread waited until it returned. Watchdog is a public class, so it should
not impose that on handlers it does not control. The stale-expiry check
and the clearing of the current timer stay under the lock; only the
handler call moves out. With the handler no longer running under the
lock, a plain Lock is enough.

Also give test_pet_postpones_expiry more margin on a slow runner.

Suggested by baylanger.

Co-Authored-By: Pierre Belanger <baylanger@users.noreply.github.com>
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@mezz64

mezz64 commented Nov 7, 2026 •

Copy link
Copy Markdown
Owner Author

Thanks @baylanger, both good catches. Pushed in 8fdc1dc:

  • The handler is now called outside the lock, as you suggested, with your test. The stale-expiry check and clearing the current timer stay under the lock, so an expiry from a replaced or stopped timer is still ignored. Once the lock is released, a pet() can still arrive just before the handler runs, but by then the timer really did expire, so that's a genuine timeout and not a stale one. With the handler out of the lock, a plain Lock is enough.
  • test_pet_postpones_expiry now sleeps TIMEOUT / 4 between pets, which leaves 0.15 s of slack. The three pets still add up to less than one timeout.

@mezz64
mezz64 merged commit 6cf31eb into master Nov 12, 2026
4 checks passed
@mezz64
mezz64 deleted the watchdog-orphan-timer branch November 12, 2026 03:06
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Watchdog timer is not stopped when the alert stream ends normally, so an orphaned timer resets the stream 300 s later

2 participants