Skip to content

Commit dbb46bc

Browse files
committed
monitor: Fix bug. README imrovements.
1 parent 0e866f3 commit dbb46bc

File tree

6 files changed

+173
-76
lines changed

6 files changed

+173
-76
lines changed

v3/as_demos/monitor/README.md

Lines changed: 44 additions & 44 deletions
Original file line numberDiff line numberDiff line change
@@ -18,13 +18,9 @@ when the blocking period exceeds a threshold. The threshold can be a fixed time
1818
or the current maximum blocking period. A logic analyser enables the state at
1919
the time of the transient event to be examined.
2020

21-
The following image shows the `quick_test.py` code being monitored at the point
22-
when a task hogs the CPU. The top line 00 shows the "hog detect" trigger. Line
23-
01 shows the fast running `hog_detect` task which cannot run at the time of the
24-
trigger because another task is hogging the CPU. Lines 02 and 04 show the `foo`
25-
and `bar` tasks. Line 03 shows the `hog` task and line 05 is a trigger issued
26-
by `hog()` when it starts monopolising the CPU. The Pico issues the "hog
27-
detect" trigger 100ms after hogging starts.
21+
This image shows the detection of CPU hogging. A trigger pulse is generated
22+
100ms after hogging caused the scheduler to be unable to schedule tasks. It is
23+
discussed in more detail in [section 6](./README.md#6-test-and-demo-scripts).
2824

2925
![Image](./monitor.jpg)
3026

@@ -37,8 +33,8 @@ to demonstrate that this never exceeded 5ms.
3733
## 1.1 Concepts
3834

3935
Communication with the Pico may be by UART or SPI, and is uni-directional from
40-
DUT to Pico. If a UART is used only one GPIO pin is needed. SPI requires three
41-
- `mosi`, `sck` and `cs/`.
36+
DUT to Pico. If a UART is used only one GPIO pin is needed. SPI requires three,
37+
namely `mosi`, `sck` and `cs/`.
4238

4339
The Pico runs the following:
4440
```python
@@ -189,8 +185,7 @@ crashed, was interrupted or failed.
189185

190186
Re-using idents would lead to confusing behaviour. If an ident is out of range
191187
or is assigned to more than one coroutine an error message is printed and
192-
execution terminates. See [section 7.3](./README.md#73-validation) for a
193-
special case where validation must be defeated.
188+
execution terminates.
194189

195190
# 3. Monitoring uasyncio code
196191

@@ -210,6 +205,9 @@ The decorator positional args are as follows:
210205
task to be independently monitored (default 1).
211206
3. `verbose=True` If `False` suppress the warning which is printed on the DUT
212207
if the instance count exceeds `max_instances`.
208+
4. `looping=False` Set `True` if the decorator is called repeatedly e.g.
209+
decorating a nested function or method. The `True` value ensures validation of
210+
the ident occurs once only when the decorator first runs.
213211

214212
Whenever the coroutine runs, a pin on the Pico will go high, and when the code
215213
terminates it will go low. This enables the behaviour of the system to be
@@ -261,13 +259,13 @@ import monitor
261259
asyncio.create_task(monitor.hog_detect())
262260
# code omitted
263261
```
264-
To aid in detecting the gaps in execution, the Pico code implements a timer.
265-
This is retriggered by activity on `ident=0`. If it times out, a brief high
266-
going pulse is produced on GPIO 28, along with the console message "Hog". The
267-
pulse can be used to trigger a scope or logic analyser. The duration of the
268-
timer may be adjusted. Other modes of hog detection are also supported, notably
269-
producing a trigger pulse only when the prior maximum was exceeded. See
270-
[section 4](./README.md~4-the-pico-code).
262+
To aid in detecting the gaps in execution, in its default mode the Pico code
263+
implements a timer. This is retriggered by activity on `ident=0`. If it times
264+
out, a brief high going pulse is produced on GPIO 28, along with the console
265+
message "Hog". The pulse can be used to trigger a scope or logic analyser. The
266+
duration of the timer may be adjusted. Other modes of hog detection are also
267+
supported, notably producing a trigger pulse only when the prior maximum was
268+
exceeded. See [section 5](./README.md#5-Pico).
271269

272270
# 4. Monitoring arbitrary code
273271

@@ -292,13 +290,17 @@ duration of every call to `sync_func()`:
292290
def sync_func():
293291
pass
294292
```
293+
Decorator args:
294+
1. `ident`
295+
2. `looping=False` Set `True` if the decorator is called repeatedly e.g. in a
296+
nested function or method. The `True` value ensures validation of the ident
297+
occurs once only when the decorator first runs.
295298

296299
## 4.2 The mon_call context manager
297300

298301
This may be used to monitor a function only when called from specific points in
299-
the code. Validation of idents is looser here because a context manager is
300-
often used in a looping construct: it seems impractical to distinguish this
301-
case from that where two context managers are instantiated with the same ID.
302+
the code. Since context managers may be used in a looping construct the ident
303+
is only checked for conflicts when the CM is first instantiated.
302304

303305
Usage:
304306
```python
@@ -319,8 +321,7 @@ is created by passing the ident. If the instance is run with no args a brief
319321
(~80μs) pulse will occur on the Pico pin. If `True` is passed, the pin will go
320322
high until `False` is passed.
321323

322-
The closure should be instantiated once only. If instantiated in a loop the
323-
ident will fail the check on re-use.
324+
The closure should be instantiated once only in the outermost scope.
324325
```python
325326
trig = monitor.trigger(10) # Associate trig with ident 10.
326327

@@ -335,10 +336,10 @@ def bar():
335336
## 4.4 Timing of code segments
336337

337338
It can be useful to time the execution of a specific block of code especially
338-
if the time varies. It is possible to cause a message to be printed and a
339-
trigger pulse to be generated whenever the execution time exceeds the prior
340-
maximum. The scope or logic analyser may be triggered by this pulse allowing
341-
the state of other parts of the system to be checked.
339+
if the duration varies in real time. It is possible to cause a message to be
340+
printed and a trigger pulse to be generated whenever the execution time exceeds
341+
the prior maximum. A scope or logic analyser may be triggered by this pulse
342+
allowing the state of other components of the system to be checked.
342343

343344
This is done by re-purposing ident 0 as follows:
344345
```python
@@ -467,13 +468,21 @@ from monitor_pico import run, WIDTH
467468
run((20, WIDTH)) # Ignore widths < 20ms.
468469
```
469470
Assuming that ident 0 is used as described in
470-
[section 4.4](./README.md#44-timing-of-code-segments) a trigger pulse on GPIO28
471+
[section 5.5](./README.md#55-timing-of-code-segments) a trigger pulse on GPIO28
471472
will occur each time the time taken exceeds both 20ms and its prior maximum. A
472473
message with the actual width is also printed whenever this occurs.
473474

474475
# 6. Test and demo scripts
475476

476-
`quick_test.py` Primarily tests deliberate CPU hogging. Discussed in section 1.
477+
The following image shows the `quick_test.py` code being monitored at the point
478+
when a task hogs the CPU. The top line 00 shows the "hog detect" trigger. Line
479+
01 shows the fast running `hog_detect` task which cannot run at the time of the
480+
trigger because another task is hogging the CPU. Lines 02 and 04 show the `foo`
481+
and `bar` tasks. Line 03 shows the `hog` task and line 05 is a trigger issued
482+
by `hog()` when it starts monopolising the CPU. The Pico issues the "hog
483+
detect" trigger 100ms after hogging starts.
484+
485+
![Image](./monitor.jpg)
477486

478487
`full_test.py` Tests task timeout and cancellation, also the handling of
479488
multiple task instances. If the Pico is run with `run((1, MAX))` it reveals
@@ -508,6 +517,8 @@ in `hog_detect` show the periods of deliberate CPU hogging.
508517
`syn_time.py` Demonstrates timing of a specific code segment with a trigger
509518
pulse being generated every time the period exceeds its prior maximum.
510519

520+
![Image](./tests/syn_time.jpg)
521+
511522
# 7. Internals
512523

513524
## 7.1 Performance and design notes
@@ -573,21 +584,7 @@ In the following, `thresh` is the time passed to `run()` in `period[0]`.
573584
* `MAX` Trigger occurs if period exceeds `thresh` and also exceeds the prior
574585
maximum.
575586

576-
This project was inspired by
577-
[this GitHub thread](https://github.com/micropython/micropython/issues/7456).
578-
579-
## 7.3 Validation
580-
581-
The `monitor` module attempts to protect against inadvertent multiple use of an
582-
`ident`. There are use patterns which are incompatible with this, notably where
583-
a decorated function or coroutine is instantiated in a looping construct. To
584-
cater for such cases validation can be defeated. This is done by issuing:
585-
```python
586-
import monitor
587-
monitor.validation(False)
588-
```
589-
590-
## 7.4 ESP8266 note
587+
## 7.3 ESP8266 note
591588

592589
ESP8266 applications can be monitored using the transmit-only UART 1.
593590

@@ -610,3 +607,6 @@ device under test is on the right, linked to the Pico board by means of a UART.
610607
![Image](./monitor_hw.JPG)
611608

612609
I can supply a schematic and PCB details if anyone is interested.
610+
611+
This project was inspired by
612+
[this GitHub thread](https://github.com/micropython/micropython/issues/7456).

v3/as_demos/monitor/monitor.py

Lines changed: 28 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -45,33 +45,34 @@ def clear_sm(): # Set Pico SM to its initial state
4545
_quit("set_device: invalid args.")
4646

4747

48-
# Justification for validation even when decorating a method
4948
# /mnt/qnap2/data/Projects/Python/AssortedTechniques/decorators
5049
_available = set(range(0, 22)) # Valid idents are 0..21
51-
_do_validate = True
52-
53-
54-
def _validate(ident, num=1):
55-
if _do_validate:
56-
if ident >= 0 and ident + num < 22:
57-
try:
58-
for x in range(ident, ident + num):
50+
# Looping: some idents may be repeatedly instantiated. This can occur
51+
# if decorator is run in looping code. A CM is likely to be used in a
52+
# loop. In these cases only validate on first use.
53+
_loopers = set()
54+
55+
56+
def _validate(ident, num=1, looping=False):
57+
if ident >= 0 and ident + num < 22:
58+
try:
59+
for x in range(ident, ident + num):
60+
if looping:
61+
if x not in _loopers:
62+
_available.remove(x)
63+
_loopers.add(x)
64+
else:
5965
_available.remove(x)
60-
except KeyError:
61-
_quit("error - ident {:02d} already allocated.".format(x))
62-
else:
63-
_quit("error - ident {:02d} out of range.".format(ident))
64-
65-
66-
def validation(do=True):
67-
global _do_validate
68-
_do_validate = do
66+
except KeyError:
67+
_quit("error - ident {:02d} already allocated.".format(x))
68+
else:
69+
_quit("error - ident {:02d} out of range.".format(ident))
6970

7071

7172
# asynchronous monitor
72-
def asyn(n, max_instances=1, verbose=True):
73+
def asyn(n, max_instances=1, verbose=True, looping=False):
7374
def decorator(coro):
74-
_validate(n, max_instances)
75+
_validate(n, max_instances, looping)
7576
instance = 0
7677

7778
async def wrapped_coro(*args, **kwargs):
@@ -114,11 +115,11 @@ async def hog_detect(s=(b"\x40", b"\x60")):
114115

115116

116117
# Monitor a synchronous function definition
117-
def sync(n):
118+
def sync(ident, looping=False):
118119
def decorator(func):
119-
_validate(n)
120-
vstart = int.to_bytes(0x40 + n, 1, "big")
121-
vend = int.to_bytes(0x60 + n, 1, "big")
120+
_validate(ident, 1, looping)
121+
vstart = int.to_bytes(0x40 + ident, 1, "big")
122+
vend = int.to_bytes(0x60 + ident, 1, "big")
122123

123124
def wrapped_func(*args, **kwargs):
124125
_write(vstart)
@@ -133,12 +134,9 @@ def wrapped_func(*args, **kwargs):
133134

134135
# Monitor a function call
135136
class mon_call:
136-
_cm_idents = set() # Idents used by this CM
137-
138137
def __init__(self, n):
139-
if n not in self._cm_idents: # ID can't clash with other objects
140-
_validate(n) # but could have two CM's with same ident
141-
self._cm_idents.add(n)
138+
# looping: a CM may be instantiated many times
139+
_validate(n, 1, True)
142140
self.vstart = int.to_bytes(0x40 + n, 1, "big")
143141
self.vend = int.to_bytes(0x60 + n, 1, "big")
144142

@@ -152,7 +150,7 @@ def __exit__(self, type, value, traceback):
152150

153151

154152
# Either cause pico ident n to produce a brief (~80μs) pulse or turn it
155-
# on or off on demand.
153+
# on or off on demand. No looping: docs suggest instantiating at start.
156154
def trigger(n):
157155
_validate(n)
158156
on = int.to_bytes(0x40 + n, 1, "big")

v3/as_demos/monitor/tests/looping.py

Lines changed: 58 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,58 @@
1+
# syn_test.py
2+
# Tests the monitoring synchronous code and of an async method.
3+
4+
# Copyright (c) 2021 Peter Hinch
5+
# Released under the MIT License (MIT) - see LICENSE file
6+
7+
import uasyncio as asyncio
8+
import time
9+
from machine import Pin, UART, SPI
10+
import monitor
11+
12+
# Define interface to use
13+
monitor.set_device(UART(2, 1_000_000)) # UART must be 1MHz
14+
# monitor.set_device(SPI(2, baudrate=5_000_000), Pin('X1', Pin.OUT)) # SPI suggest >= 1MHz
15+
trig = monitor.trigger(5)
16+
17+
18+
class Foo:
19+
def __init__(self):
20+
pass
21+
22+
@monitor.asyn(1, 2) # ident 1/2 high
23+
async def pause(self):
24+
while True:
25+
trig()
26+
self.wait1() # ident 3 10ms pulse
27+
await asyncio.sleep_ms(100)
28+
with monitor.mon_call(4): # ident 4 10ms pulse
29+
self.wait2()
30+
await asyncio.sleep_ms(100)
31+
# ident 1/2 low
32+
33+
async def bar(self):
34+
@monitor.asyn(3, looping = True)
35+
async def wait1():
36+
await asyncio.sleep_ms(100)
37+
@monitor.sync(4, True)
38+
def wait2():
39+
time.sleep_ms(10)
40+
trig()
41+
await wait1()
42+
trig()
43+
wait2()
44+
45+
46+
async def main():
47+
monitor.init()
48+
asyncio.create_task(monitor.hog_detect()) # Make 10ms waitx gaps visible
49+
foo = Foo()
50+
while True:
51+
await foo.bar()
52+
await asyncio.sleep_ms(100)
53+
await foo.pause()
54+
55+
try:
56+
asyncio.run(main())
57+
finally:
58+
asyncio.new_event_loop()

v3/as_demos/monitor/tests/syn_test.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@
1212
# Define interface to use
1313
monitor.set_device(UART(2, 1_000_000)) # UART must be 1MHz
1414
# monitor.set_device(SPI(2, baudrate=5_000_000), Pin('X1', Pin.OUT)) # SPI suggest >= 1MHz
15+
trig = monitor.trigger(5)
1516

1617

1718
class Foo:
@@ -27,7 +28,7 @@ async def pause(self):
2728
await asyncio.sleep_ms(100)
2829
# ident 1/2 low
2930

30-
@monitor.sync(3) # Decorator so ident not reserved
31+
@monitor.sync(3)
3132
def wait1(self):
3233
time.sleep_ms(10)
3334

@@ -39,7 +40,6 @@ async def main():
3940
asyncio.create_task(monitor.hog_detect()) # Make 10ms waitx gaps visible
4041
foo1 = Foo()
4142
foo2 = Foo()
42-
trig = monitor.trigger(5)
4343
while True:
4444
trig() # Mark start with pulse on ident 5
4545
# Create two instances of .pause separated by 50ms
73.1 KB
Loading

v3/as_demos/monitor/tests/syn_time.py

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,41 @@
1+
# syn_time.py
2+
# Tests the monitoring synchronous code.
3+
# Can run with run((1, monitor.WIDTH)) to check max width detection.
4+
5+
# Copyright (c) 2021 Peter Hinch
6+
# Released under the MIT License (MIT) - see LICENSE file
7+
8+
import uasyncio as asyncio
9+
import time
10+
from machine import Pin, UART, SPI
11+
import monitor
12+
13+
# Define interface to use
14+
monitor.set_device(UART(2, 1_000_000)) # UART must be 1MHz
15+
# monitor.set_device(SPI(2, baudrate=5_000_000), Pin('X1', Pin.OUT)) # SPI suggest >= 1MHz
16+
17+
trig0 = monitor.trigger(0)
18+
twait = 20
19+
20+
async def test():
21+
while True:
22+
await asyncio.sleep_ms(100)
23+
trig0(True)
24+
await asyncio.sleep_ms(twait)
25+
trig0(False)
26+
27+
async def lengthen():
28+
global twait
29+
while twait < 200:
30+
twait += 1
31+
await asyncio.sleep(1)
32+
33+
async def main():
34+
monitor.init()
35+
asyncio.create_task(lengthen())
36+
await test()
37+
38+
try:
39+
asyncio.run(main())
40+
finally:
41+
asyncio.new_event_loop()

0 commit comments

Comments
 (0)