monitor: Fixes and improvements to synchronous monitoring.

Author: peterhinch

v3/as_demos/monitor/README.md

@@ -184,7 +184,8 @@ timer may be adjusted. Other modes of hog detection are also supported. See
 
 Re-using idents would lead to confusing behaviour. If an ident is out of range
 or is assigned to more than one coroutine an error message is printed and
-execution terminates.
+execution terminates. See [section 7](./README.md#7-validation) for a special
+case where validation must be defeated.
 
 # 2. Monitoring synchronous code
 
@@ -193,17 +194,10 @@ timing of synchronous code, or simply to create a trigger pulse at one or more
 known points in the code. The following are provided:  
  * A `sync` decorator for synchronous functions or methods: like `async` it
  monitors every call to the function.
- * A `trigger` function which issues a brief pulse on the Pico.
  * A `mon_call` context manager enables function monitoring to be restricted to
  specific calls.
-
-Idents used by `trigger` or `mon_call` must be reserved: this is because these
-may occur in a looping construct. This enables the validation to protect
-against inadvertent multiple usage of an ident. The `monitor.reserve()`
-function can reserve one or more idents:
-```python
-monitor.reserve(4, 9, 10)
-```
+ * A `trigger` function which issues a brief pulse on the Pico or can set and
+ clear the pin on demand.
 
 ## 2.1 The sync decorator
 
@@ -215,15 +209,16 @@ duration of every call to `sync_func()`:
 def sync_func():
     pass
 ```
-Note that idents used by decorators must not be reserved.
 
 ## 2.2 The mon_call context manager
 
 This may be used to monitor a function only when called from specific points in
-the code.
-```python
-monitor.reserve(22)
+the code. Validation of idents is looser here because a context manager is
+often used in a looping construct: it seems impractical to distinguish this
+case from that where two context managers are instantiated with the same ID.
 
+Usage:
+```python
 def another_sync_func():
     pass
 
@@ -236,14 +231,23 @@ It is advisable not to use the context manager with a function having the
 
 ## 2.3 The trigger timing marker
 
-A call to `monitor.trigger(n)` may be inserted anywhere in synchronous or
-asynchronous code. When this runs, a brief (~80μs) pulse will occur on the Pico
-pin with ident `n`. As per `mon_call`,  ident `n` must be reserved.
+The `trigger` closure is intended for timing blocks of code. A closure instance
+is created by passing the ident. If the instance is run with no args a brief
+(~80μs) pulse will occur on the Pico pin. If `True` is passed, the pin will go
+high until `False` is passed.
+
+The closure should be instantiated once only. If instantiated in a loop the
+ident will fail the check on re-use.
 ```python
-monitor.reserve(10)
+trig = monitor.trigger(10)  # Associate trig with ident 10.
 
 def foo():
-    monitor.trigger(10)  # Pulse ident 10, GPIO 13
+    trig()  # Pulse ident 10, GPIO 13
+
+def bar():
+    trig(True)  # set pin high
+    # code omitted
+    trig(False)  # set pin low
 ```
 
 # 3. Pico Pin mapping
@@ -443,7 +447,7 @@ the pin goes high and the instance count is incremented. If it is lowercase the
 instance count is decremented: if it becomes 0 the pin goes low.
 
 The `init` function on the host sends `b"z"` to the Pico. This sets each pin
-int `pins` low and clears its instance counter (the program under test may have
+in `pins` low and clears its instance counter (the program under test may have
 previously failed, leaving instance counters non-zero). The Pico also clears
 variables used to measure hogging. In the case of SPI communication, before
 sending the `b"z"`, a 0 character is sent with `cs/` high. The Pico implements
@@ -465,3 +469,22 @@ In the following, `thresh` is the time passed to `run()` in `period[0]`.
 This project was inspired by
 [this GitHub thread](https://github.com/micropython/micropython/issues/7456).
 
+# 7. Validation
+
+The `monitor` module attempts to protect against inadvertent multiple use of an
+`ident`. There are use patterns which are incompatible with this, notably where
+a decorated function or coroutine is instantiated in a looping construct. To
+cater for such cases validation can be defeated. This is done by issuing:
+```python
+import monitor
+monitor.validation(False)
+```
+
+# 8. A hardware implementation
+
+The device under test is on the right, linked to the Pico board by means of a
+UART.
+
+![Image](./monitor_hw.jpg)
+
+I can supply a schematic and PCB details if anyone is interested.

v3/as_demos/monitor/monitor.py

@@ -44,36 +44,25 @@ def clear_sm():  # Set Pico SM to its initial state
     else:
         _quit("set_device: invalid args.")
 
-
 # Justification for validation even when decorating a method
 # /mnt/qnap2/data/Projects/Python/AssortedTechniques/decorators
 _available = set(range(0, 22))  # Valid idents are 0..21
-_reserved = set()  # Idents reserved for synchronous monitoring
-
+_do_validate = True
 
 def _validate(ident, num=1):
-    if ident >= 0 and ident + num < 22:
-        try:
-            for x in range(ident, ident + num):
-                _available.remove(x)
-        except KeyError:
-            _quit("error - ident {:02d} already allocated.".format(x))
-    else:
-        _quit("error - ident {:02d} out of range.".format(ident))
-
-
-# Reserve ID's to be used for synchronous monitoring
-def reserve(*ids):
-    for ident in ids:
-        _validate(ident)
-        _reserved.add(ident)
-
-
-# Check whether a synchronous ident was reserved
-def _check(ident):
-    if ident not in _reserved:
-        _quit("error: synchronous ident {:02d} was not reserved.".format(ident))
+    if _do_validate:
+        if ident >= 0 and ident + num < 22:
+            try:
+                for x in range(ident, ident + num):
+                    _available.remove(x)
+            except KeyError:
+                _quit("error - ident {:02d} already allocated.".format(x))
+        else:
+            _quit("error - ident {:02d} out of range.".format(ident))
 
+def validation(do=True):
+    global _do_validate
+    _do_validate = do
 
 # asynchronous monitor
 def asyn(n, max_instances=1, verbose=True):
@@ -104,22 +93,19 @@ async def wrapped_coro(*args, **kwargs):
 
     return decorator
 
-
 # If SPI, clears the state machine in case prior test resulted in the DUT
 # crashing. It does this by sending a byte with CS\ False (high).
 def init():
     _ifrst()  # Reset interface. Does nothing if UART.
     _write(b"z")  # Clear Pico's instance counters etc.
 
-
 # Optionally run this to show up periods of blocking behaviour
 async def hog_detect(s=(b"\x40", b"\x60")):
     while True:
         for v in s:
             _write(v)
             await asyncio.sleep_ms(0)
 
-
 # Monitor a synchronous function definition
 def sync(n):
     def decorator(func):
@@ -137,12 +123,14 @@ def wrapped_func(*args, **kwargs):
 
     return decorator
 
-
-# Runtime monitoring: can't validate because code may be looping.
-# Monitor a synchronous function call
+# Monitor a function call
 class mon_call:
+    _cm_idents = set()  # Idents used by this CM
+
     def __init__(self, n):
-        _check(n)
+        if n not in self._cm_idents:  # ID can't clash with other objects
+            _validate(n)  # but could have two CM's with same ident
+            self._cm_idents.add(n)
         self.vstart = int.to_bytes(0x40 + n, 1, "big")
         self.vend = int.to_bytes(0x60 + n, 1, "big")
 
@@ -154,10 +142,17 @@ def __exit__(self, type, value, traceback):
         _write(self.vend)
         return False  # Don't silence exceptions
 
-
-# Cause pico ident n to produce a brief (~80μs) pulse
+# Either cause pico ident n to produce a brief (~80μs) pulse or turn it
+# on or off on demand.
 def trigger(n):
-    _check(n)
-    _write(int.to_bytes(0x40 + n, 1, "big"))
-    sleep_us(20)
-    _write(int.to_bytes(0x60 + n, 1, "big"))
+    _validate(n)
+    on = int.to_bytes(0x40 + n, 1, "big")
+    off = int.to_bytes(0x60 + n, 1, "big")
+    def wrapped(state=None):
+        if state is None:
+            _write(on)
+            sleep_us(20)
+            _write(off)
+        else:
+            _write(on if state else off)
+    return wrapped

v3/as_demos/monitor/monitor_hw.JPG

@@ -83,10 +83,13 @@ def _cb(_):
 SOON = const(0)
 LATE = const(1)
 MAX = const(2)
+WIDTH = const(3)
 # Modes. Pulses and reports only occur if an outage exceeds the threshold.
 # SOON: pulse early when timer times out. Report at outage end.
 # LATE: pulse when outage ends. Report at outage end.
 # MAX: pulse when outage exceeds prior maximum. Report only in that instance.
+# WIDTH: for measuring time between arbitrary points in code. When duration
+# between 0x40 and 0x60 exceeds previosu max, pulse and report.
 
 # native reduced latency to 10μs but killed the hog detector: timer never timed out.
 # Also locked up Pico so ctrl-c did not interrupt.
@@ -121,23 +124,33 @@ def read():
 
     vb and print("Awaiting communication.")
     h_max = 0  # Max hog duration (ms)
-    h_start = 0  # Absolute hog start time
+    h_start = -1  # Absolute hog start time: invalidate.
     while True:
         if x := read():  # Get an initial 0 on UART
+            tarr = ticks_ms()  # Arrival time
             if x == 0x7A:  # Init: program under test has restarted
                 vb and print("Got communication.")
                 h_max = 0  # Restart timing
-                h_start = 0
+                h_start = -1
                 for pin in pins:
                     pin[0](0)  # Clear pin
                     pin[1] = 0  # and instance counter
                 continue
-            if x == 0x40:  # hog_detect task has started.
-                t = ticks_ms()  # Arrival time
+            if mode == WIDTH:
+                if x == 0x40:  # Leading edge on ident 0
+                    h_start = tarr
+                elif x == 0x60 and h_start != -1:  # Trailing edge
+                    dt = ticks_diff(tarr, h_start)
+                    if dt > h_max:
+                        h_max = dt
+                        print(f"Max width {dt}ms")
+                        pin_t(1)
+                        pin_t(0)
+            elif x == 0x40:  # hog_detect task has started.
                 if mode == SOON:  # Pulse on absence of activity
                     tim.init(period=t_ms, mode=Timer.ONE_SHOT, callback=_cb)
-                if h_start:  # There was a prior trigger
-                    dt = ticks_diff(t, h_start)
+                if h_start != -1:  # There was a prior trigger
+                    dt = ticks_diff(tarr, h_start)
                     if dt > t_ms:  # Delay exceeds threshold
                         if mode != MAX:
                             print(f"Hog {dt}ms")
@@ -150,10 +163,11 @@ def read():
                             if mode == MAX:
                                 pin_t(1)
                                 pin_t(0)
-                h_start = t
+                h_start = tarr
             p = pins[x & 0x1F]  # Key: 0x40 (ord('@')) is pin ID 0
             if x & 0x20:  # Going down
-                p[1] -= 1
+                if p[1] > 0:  # Might have restarted this script with a running client.
+                    p[1] -= 1  # or might have sent trig(False) before True.
                 if not p[1]:  # Instance count is zero
                     p[0](0)
             else:

v3/as_demos/monitor/monitor_pico.py

@@ -9,7 +9,7 @@
 from machine import Pin, UART, SPI
 import monitor
 
-monitor.reserve(4)
+trig = monitor.trigger(4)
 # Define interface to use
 monitor.set_device(UART(2, 1_000_000))  # UART must be 1MHz
 #monitor.set_device(SPI(2, baudrate=5_000_000), Pin('X1', Pin.OUT))  # SPI suggest >= 1MHz
@@ -24,7 +24,7 @@ async def main():
     monitor.init()
     asyncio.create_task(monitor.hog_detect())  # Watch for gc dropouts on ID0
     while True:
-        monitor.trigger(4)
+        trig()
         try:
             await asyncio.wait_for_ms(forever(), 100)  # 100ms pulse on ID1
         except asyncio.TimeoutError:  # Mandatory error trapping

v3/as_demos/monitor/tests/full_test.py

@@ -11,7 +11,7 @@
 
 # Pin on host: modify for other platforms
 test_pin = Pin('X6', Pin.OUT)
-monitor.reserve(2)
+trig = monitor.trigger(2)
 
 # Define interface to use
 monitor.set_device(UART(2, 1_000_000))  # UART must be 1MHz
@@ -21,7 +21,7 @@
 async def pulse(pin):
     pin(1)  # Pulse pin
     pin(0)
-    monitor.trigger(2)  # Pulse Pico pin ident 2
+    trig()  # Pulse Pico pin ident 2
     await asyncio.sleep_ms(30)
 
 async def main():

v3/as_demos/monitor/tests/latency.py

@@ -13,7 +13,7 @@
 monitor.set_device(UART(2, 1_000_000))  # UART must be 1MHz
 # monitor.set_device(SPI(2, baudrate=5_000_000), Pin('X1', Pin.OUT))  # SPI suggest >= 1MHz
 
-monitor.reserve(4)  # ident for trigger
+trig = monitor.trigger(4)
 
 @monitor.asyn(1)
 async def foo(t):
@@ -22,7 +22,7 @@ async def foo(t):
 @monitor.asyn(2)
 async def hog():
     await asyncio.sleep(5)
-    monitor.trigger(4)  # Hog start
+    trig()  # Hog start
     time.sleep_ms(500)
 
 @monitor.asyn(3)

v3/as_demos/monitor/tests/quick_test.py

@@ -13,8 +13,6 @@
 monitor.set_device(UART(2, 1_000_000))  # UART must be 1MHz
 # monitor.set_device(SPI(2, baudrate=5_000_000), Pin('X1', Pin.OUT))  # SPI suggest >= 1MHz
 
-monitor.reserve(4, 5)  # Reserve trigger and mon_call idents only
-
 
 class Foo:
     def __init__(self):
@@ -41,8 +39,9 @@ async def main():
     asyncio.create_task(monitor.hog_detect())  # Make 10ms waitx gaps visible
     foo1 = Foo()
     foo2 = Foo()
+    trig = monitor.trigger(5)
     while True:
-        monitor.trigger(5)  # Mark start with pulse on ident 5
+        trig()  # Mark start with pulse on ident 5
         # Create two instances of .pause separated by 50ms
         asyncio.create_task(foo1.pause())
         await asyncio.sleep_ms(50)