Skip to content

Commit 89e921c

Browse files
GDYendellGDYendell
authored
Add logging to tutorial (#269)
1 parent 2d72f41 commit 89e921c

File tree

3 files changed

+347
-1
lines changed

3 files changed

+347
-1
lines changed

‎docs/snippets/static14.py‎

Lines changed: 127 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,127 @@
1+
import asyncio
2+
import enum
3+
import json
4+
from dataclasses import KW_ONLY, dataclass
5+
from pathlib import Path
6+
from typing import TypeVar
7+
8+
from fastcs.attribute_io import AttributeIO
9+
from fastcs.attribute_io_ref import AttributeIORef
10+
from fastcs.attributes import AttrR, AttrRW, AttrW
11+
from fastcs.connections import IPConnection, IPConnectionSettings
12+
from fastcs.controller import Controller
13+
from fastcs.datatypes import Enum, Float, Int, String
14+
from fastcs.launch import FastCS
15+
from fastcs.logging import bind_logger, configure_logging
16+
from fastcs.transport.epics.ca.transport import EpicsCATransport
17+
from fastcs.transport.epics.options import EpicsGUIOptions, EpicsIOCOptions
18+
from fastcs.wrappers import command, scan
19+
20+
logger = bind_logger(__name__)
21+
22+
NumberT = TypeVar("NumberT", int, float)
23+
24+
25+
@dataclass
26+
class TemperatureControllerAttributeIORef(AttributeIORef):
27+
name: str
28+
_: KW_ONLY
29+
update_period: float | None = 0.2
30+
31+
32+
class TemperatureControllerAttributeIO(
33+
AttributeIO[NumberT, TemperatureControllerAttributeIORef]
34+
):
35+
def __init__(self, connection: IPConnection, suffix: str = ""):
36+
super().__init__()
37+
38+
self.logger = bind_logger(__class__.__name__)
39+
40+
self._connection = connection
41+
self._suffix = suffix
42+
43+
async def update(self, attr: AttrR[NumberT, TemperatureControllerAttributeIORef]):
44+
query = f"{attr.io_ref.name}{self._suffix}?"
45+
response = await self._connection.send_query(f"{query}\r\n")
46+
value = response.strip("\r\n")
47+
await attr.update(attr.dtype(value))
48+
49+
async def send(
50+
self, attr: AttrW[NumberT, TemperatureControllerAttributeIORef], value: NumberT
51+
) -> None:
52+
command = f"{attr.io_ref.name}{self._suffix}={attr.dtype(value)}"
53+
54+
self.logger.info("Sending attribute value", command=command, attribute=attr)
55+
56+
await self._connection.send_command(f"{command}\r\n")
57+
58+
59+
class OnOffEnum(enum.StrEnum):
60+
Off = "0"
61+
On = "1"
62+
63+
64+
class TemperatureRampController(Controller):
65+
start = AttrRW(Int(), io_ref=TemperatureControllerAttributeIORef(name="S"))
66+
end = AttrRW(Int(), io_ref=TemperatureControllerAttributeIORef(name="E"))
67+
enabled = AttrRW(Enum(OnOffEnum), io_ref=TemperatureControllerAttributeIORef("N"))
68+
target = AttrR(Float(), io_ref=TemperatureControllerAttributeIORef("T"))
69+
actual = AttrR(Float(), io_ref=TemperatureControllerAttributeIORef("A"))
70+
voltage = AttrR(Float())
71+
72+
def __init__(self, index: int, connection: IPConnection) -> None:
73+
suffix = f"{index:02d}"
74+
super().__init__(
75+
f"Ramp{suffix}", ios=[TemperatureControllerAttributeIO(connection, suffix)]
76+
)
77+
78+
79+
class TemperatureController(Controller):
80+
device_id = AttrR(String(), io_ref=TemperatureControllerAttributeIORef("ID"))
81+
power = AttrR(Float(), io_ref=TemperatureControllerAttributeIORef("P"))
82+
ramp_rate = AttrRW(Float(), io_ref=TemperatureControllerAttributeIORef("R"))
83+
84+
def __init__(self, ramp_count: int, settings: IPConnectionSettings):
85+
self._ip_settings = settings
86+
self._connection = IPConnection()
87+
88+
super().__init__(ios=[TemperatureControllerAttributeIO(self._connection)])
89+
90+
self._ramp_controllers: list[TemperatureRampController] = []
91+
for index in range(1, ramp_count + 1):
92+
controller = TemperatureRampController(index, self._connection)
93+
self._ramp_controllers.append(controller)
94+
self.add_sub_controller(f"R{index}", controller)
95+
96+
async def connect(self):
97+
await self._connection.connect(self._ip_settings)
98+
99+
@scan(0.1)
100+
async def update_voltages(self):
101+
voltages = json.loads(
102+
(await self._connection.send_query("V?\r\n")).strip("\r\n")
103+
)
104+
for index, controller in enumerate(self._ramp_controllers):
105+
await controller.voltage.update(float(voltages[index]))
106+
107+
@command()
108+
async def disable_all(self) -> None:
109+
self.log_event("Disabling all ramps")
110+
for rc in self._ramp_controllers:
111+
await rc.enabled.put(OnOffEnum.Off, sync_setpoint=True)
112+
# TODO: The requests all get concatenated and the sim doesn't handle it
113+
await asyncio.sleep(0.1)
114+
115+
116+
configure_logging()
117+
118+
gui_options = EpicsGUIOptions(
119+
output_path=Path(".") / "demo.bob", title="Demo Temperature Controller"
120+
)
121+
epics_ca = EpicsCATransport(gui=gui_options, epicsca=EpicsIOCOptions(pv_prefix="DEMO"))
122+
connection_settings = IPConnectionSettings("localhost", 25565)
123+
logger.info("Configuring connection settings", connection_settings=connection_settings)
124+
fastcs = FastCS(TemperatureController(4, connection_settings), [epics_ca])
125+
126+
if __name__ == "__main__":
127+
fastcs.run()

‎docs/snippets/static15.py‎

Lines changed: 130 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,130 @@
1+
import asyncio
2+
import enum
3+
import json
4+
from dataclasses import KW_ONLY, dataclass
5+
from pathlib import Path
6+
from typing import TypeVar
7+
8+
from fastcs.attribute_io import AttributeIO
9+
from fastcs.attribute_io_ref import AttributeIORef
10+
from fastcs.attributes import AttrR, AttrRW, AttrW
11+
from fastcs.connections import IPConnection, IPConnectionSettings
12+
from fastcs.controller import Controller
13+
from fastcs.datatypes import Enum, Float, Int, String
14+
from fastcs.launch import FastCS
15+
from fastcs.logging import LogLevel, bind_logger, configure_logging
16+
from fastcs.transport.epics.ca.transport import EpicsCATransport
17+
from fastcs.transport.epics.options import EpicsGUIOptions, EpicsIOCOptions
18+
from fastcs.wrappers import command, scan
19+
20+
logger = bind_logger(__name__)
21+
22+
NumberT = TypeVar("NumberT", int, float)
23+
24+
25+
@dataclass
26+
class TemperatureControllerAttributeIORef(AttributeIORef):
27+
name: str
28+
_: KW_ONLY
29+
update_period: float | None = 0.2
30+
31+
32+
class TemperatureControllerAttributeIO(
33+
AttributeIO[NumberT, TemperatureControllerAttributeIORef]
34+
):
35+
def __init__(self, connection: IPConnection, suffix: str = ""):
36+
super().__init__()
37+
38+
self.logger = bind_logger(__class__.__name__)
39+
40+
self._connection = connection
41+
self._suffix = suffix
42+
43+
async def update(self, attr: AttrR[NumberT, TemperatureControllerAttributeIORef]):
44+
query = f"{attr.io_ref.name}{self._suffix}?"
45+
response = await self._connection.send_query(f"{query}\r\n")
46+
value = response.strip("\r\n")
47+
48+
self.log_event("Query for attribute", query=query, response=value, topic=attr)
49+
50+
await attr.update(attr.dtype(value))
51+
52+
async def send(
53+
self, attr: AttrW[NumberT, TemperatureControllerAttributeIORef], value: NumberT
54+
) -> None:
55+
command = f"{attr.io_ref.name}{self._suffix}={attr.dtype(value)}"
56+
57+
self.logger.info("Sending attribute value", command=command, attribute=attr)
58+
59+
await self._connection.send_command(f"{command}\r\n")
60+
61+
62+
class OnOffEnum(enum.StrEnum):
63+
Off = "0"
64+
On = "1"
65+
66+
67+
class TemperatureRampController(Controller):
68+
start = AttrRW(Int(), io_ref=TemperatureControllerAttributeIORef(name="S"))
69+
end = AttrRW(Int(), io_ref=TemperatureControllerAttributeIORef(name="E"))
70+
enabled = AttrRW(Enum(OnOffEnum), io_ref=TemperatureControllerAttributeIORef("N"))
71+
target = AttrR(Float(), io_ref=TemperatureControllerAttributeIORef("T"))
72+
actual = AttrR(Float(), io_ref=TemperatureControllerAttributeIORef("A"))
73+
voltage = AttrR(Float())
74+
75+
def __init__(self, index: int, connection: IPConnection) -> None:
76+
suffix = f"{index:02d}"
77+
super().__init__(
78+
f"Ramp{suffix}", ios=[TemperatureControllerAttributeIO(connection, suffix)]
79+
)
80+
81+
82+
class TemperatureController(Controller):
83+
device_id = AttrR(String(), io_ref=TemperatureControllerAttributeIORef("ID"))
84+
power = AttrR(Float(), io_ref=TemperatureControllerAttributeIORef("P"))
85+
ramp_rate = AttrRW(Float(), io_ref=TemperatureControllerAttributeIORef("R"))
86+
87+
def __init__(self, ramp_count: int, settings: IPConnectionSettings):
88+
self._ip_settings = settings
89+
self._connection = IPConnection()
90+
91+
super().__init__(ios=[TemperatureControllerAttributeIO(self._connection)])
92+
93+
self._ramp_controllers: list[TemperatureRampController] = []
94+
for index in range(1, ramp_count + 1):
95+
controller = TemperatureRampController(index, self._connection)
96+
self._ramp_controllers.append(controller)
97+
self.add_sub_controller(f"R{index}", controller)
98+
99+
async def connect(self):
100+
await self._connection.connect(self._ip_settings)
101+
102+
@scan(0.1)
103+
async def update_voltages(self):
104+
voltages = json.loads(
105+
(await self._connection.send_query("V?\r\n")).strip("\r\n")
106+
)
107+
for index, controller in enumerate(self._ramp_controllers):
108+
await controller.voltage.update(float(voltages[index]))
109+
110+
@command()
111+
async def disable_all(self) -> None:
112+
self.log_event("Disabling all ramps")
113+
for rc in self._ramp_controllers:
114+
await rc.enabled.put(OnOffEnum.Off, sync_setpoint=True)
115+
# TODO: The requests all get concatenated and the sim doesn't handle it
116+
await asyncio.sleep(0.1)
117+
118+
119+
configure_logging(LogLevel.TRACE)
120+
121+
gui_options = EpicsGUIOptions(
122+
output_path=Path(".") / "demo.bob", title="Demo Temperature Controller"
123+
)
124+
epics_ca = EpicsCATransport(gui=gui_options, epicsca=EpicsIOCOptions(pv_prefix="DEMO"))
125+
connection_settings = IPConnectionSettings("localhost", 25565)
126+
logger.info("Configuring connection settings", connection_settings=connection_settings)
127+
fastcs = FastCS(TemperatureController(4, connection_settings), [epics_ca])
128+
129+
if __name__ == "__main__":
130+
fastcs.run()

‎docs/tutorials/static-drivers.md‎

Lines changed: 90 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -214,7 +214,7 @@ because the value is actually a string, but for `P` the value is a float, so the
214214
`update` methods needs to explicitly cast to the correct type. It can use
215215
`Attribute.dtype` to call the builtin for its datatype - e.g. `int`, `float`, `str`,
216216
etc.
217-
::::
217+
:::
218218

219219
:::{admonition} Code 8
220220
:class: dropdown, hint
@@ -405,6 +405,95 @@ New : DEMO:DisableAll
405405
DEMO:R1:Enabled_RBV Off
406406
```
407407

408+
## Logging
409+
410+
FastCS has convenient logging support to provide status and metrics from the
411+
application. To enable logging from the core framework call `configure_logging` with no
412+
arguments (the default logging level is INFO). To log messages from a driver, either
413+
import the singleton `logger` directly, or to provide more context to the message, call
414+
`bind_logger` with a name (usually either the name of the module or the name of the
415+
class).
416+
417+
Create a module-level logger to log status of the application start up. Create a class
418+
logger for `TemperatureControllerAttributeIO` to log the commands it sends.
419+
420+
::::{admonition} Code 14
421+
:class: dropdown, hint
422+
423+
:::{literalinclude} /snippets/static14.py
424+
:emphasize-lines: 15,20-21,53-55,116,123
425+
:::
426+
427+
::::
428+
429+
Try setting a PV and check the console for the log message it prints.
430+
431+
```
432+
[2025-11-18 11:26:41.065+0000 I] Sending attribute value [TemperatureControllerAttributeIO] command=E01=70, attribute=AttrRW(path=R1.end, datatype=Int, io_ref=TemperatureControllerAttributeIORef(update_period=0.2, name='E'))
433+
```
434+
435+
A similar log message could be added for the update method of the IO, but this would be
436+
very verbose. For this use case FastCS provides the `Tracer` class, which is inherited
437+
by `AttributeIO`, among other core FastCS classes. This adds a enables logging `TRACE`
438+
level log messages that are disabled by default, but can be enabled at runtime.
439+
440+
Update the `send` method of the IO to log a message showing the query that was sent and
441+
the response from the device. Update the `configure_logging` call to pass
442+
`LogLevel.TRACE` as the log level, so that when tracing is enabled the messages are
443+
visible.
444+
445+
::::{admonition} Code 15
446+
:class: dropdown, hint
447+
448+
:::{literalinclude} /snippets/static15.py
449+
:emphasize-lines: 15,47-49,119
450+
:::
451+
452+
::::
453+
454+
Enable tracing on the `power` attribute by calling `enable_tracing` and then enable a
455+
ramp so that the value updates. Check the console to see the messages. Call `disable_tracing` to disable the log messages for `power.
456+
457+
```
458+
In [1]: controller.power.enable_tracing()
459+
[2025-11-18 11:11:12.060+0000 T] Query for attribute [TemperatureControllerAttributeIO] query=P?, response=0.0
460+
[2025-11-18 11:11:12.060+0000 T] Attribute set [AttrR] attribute=AttrR(path=power, datatype=Float, io_ref=TemperatureControllerAttributeIORef(update_period=0.2, name='P')), value=0.0
461+
[2025-11-18 11:11:12.060+0000 T] PV set from attribute [fastcs.transport.epics.ca.ioc] pv=DEMO:Power, value=0.0
462+
[2025-11-18 11:11:12.194+0000 I] PV put: DEMO:R1:Enabled = 1 [fastcs.transport.epics.ca.ioc] pv=DEMO:R1:Enabled, value=1
463+
[2025-11-18 11:11:12.195+0000 I] Sending attribute value [TemperatureControllerAttributeIO] command=N01=1, attribute=AttrRW(path=R1.enabled, datatype=Enum, io_ref=TemperatureControllerAttributeIORef(update_period=0.2, name='N'))
464+
[2025-11-18 11:11:12.261+0000 T] Update attribute [AttrR]
465+
[2025-11-18 11:11:12.262+0000 T] Query for attribute [TemperatureControllerAttributeIO] query=P?, response=29.040181873093132
466+
[2025-11-18 11:11:12.262+0000 T] Attribute set [AttrR] attribute=AttrR(path=power, datatype=Float, io_ref=TemperatureControllerAttributeIORef(update_period=0.2, name='P')), value=29.040181873093132
467+
[2025-11-18 11:11:12.262+0000 T] PV set from attribute [fastcs.transport.epics.ca.ioc] pv=DEMO:Power, value=29.04
468+
[2025-11-18 11:11:12.463+0000 T] Update attribute [AttrR]
469+
[2025-11-18 11:11:12.464+0000 T] Query for attribute [TemperatureControllerAttributeIO] query=P?, response=30.452524641833854
470+
[2025-11-18 11:11:12.464+0000 T] Attribute set [AttrR] attribute=AttrR(path=power, datatype=Float, io_ref=TemperatureControllerAttributeIORef(update_period=0.2, name='P')), value=30.452524641833854
471+
[2025-11-18 11:11:12.465+0000 T] PV set from attribute [fastcs.transport.epics.ca.ioc] pv=DEMO:Power, value=30.45
472+
In [2]: controller.power.disable_tracing()
473+
```
474+
475+
These log messages includes other trace loggers that log messages with `power` as the
476+
`topic`, so they also appear automatically, so the log messages show changes to the
477+
attribute throughout the stack: the query to the device and its response, the value the
478+
attribute is set to, and the value that the PV in the EPICS CA transport is set to.
479+
480+
481+
:::{note}
482+
The `Tracer` can also be used as a module-level instance for use in free functions.
483+
484+
```python
485+
from fastcs.tracer import Tracer
486+
487+
tracer = Tracer(__name__)
488+
489+
def handle_attribute(attr):
490+
tracer.log_event("Handling attribute", topic=attr)
491+
```
492+
493+
These messages can then be enabled by calling `enable_tracing` on the module-level
494+
`Tracer`, or more likely on a specific attribute.
495+
:::
496+
408497
## Summary
409498

410499
This demonstrates some of the simple use cases for a statically defined FastCS driver.

0 commit comments

Comments
 (0)