Skip to content

Commit 7502a50

Browse files
committed
Fix #59 (comment) aside from extra technical work
1 parent 64d6852 commit 7502a50

9 files changed

Lines changed: 67 additions & 22 deletions

docs/explanation.md

Lines changed: 18 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -32,7 +32,7 @@ Every record has an attached severity level, which can be used to flag how impor
3232

3333
![log_level_overview](img/loglevels.png)
3434

35-
More levels can be defined as required, see Python's logging manual.
35+
It's worth noting that the severity levels are just enums in Python, with `CRITICAL` being 50, with increments of 10 down to 0 for `NOTSET`. More levels can be defined as required, see Python's [logging manual](https://docs.python.org/3/library/logging.html#logging-levels).
3636

3737
Each logging instance can have an attached severity level. If it has one, then only records that have the same severity level or higher will be transmitted.
3838

@@ -72,11 +72,24 @@ By default, loggers inherit certain properties from the parent:
7272
- severity level of the logger
7373
- handlers (and all attached properties, including severity level and filters on handlers)
7474

75+
76+
A good model to think about while developing is shown below, where its thought of that the loggers 'get' the same handlers as their ancestors. Note one exception: they _do not_ inherit filters attached directly to the parent logger itself.
7577
![inheritance](img/inheritance.png)
7678

77-
Note one exception: they _do not_ inherit filters attached directly to the parent logger itself.
7879

79-
A useful diagram is the [logging flow in the official Python 3 docs](https://docs.python.org/3/howto/logging.html#logging-flow).
80+
Behind the scenes, what actually happens is that the log record gets passed to the ancestor loggers; this is beneficial as it doesn't duplicate the two handles and instead passes the record around. See the [logging flow in the official Python3 docs](https://docs.python.org/3/howto/logging.html#logging-flow).
81+
82+
83+
84+
#### The root logger
85+
86+
In the native Python logging framework the highest possible logger is the (usually unnamed) root logger. For example, calling `logging.getLogger("top")` will usually yield you a logger called `{root}."top"`. Calling `logging.getLogger()` gets you the `{root}` logger.
87+
88+
As the root logger is the highest logger which every logger inherits from, modifying this logger will have a _global_ effect on all your loggers, which is almost always undesirable.
89+
90+
**Importantly, changing the root logger will affect the logging instances in other repositories too! This can lead to some undesirable behaviours, such as [this](https://github.com/DUNE-DAQ/drunc/blob/df51ce36cffe08efab6bd2a7a47554554deed22b/src/drunc/utils/utils.py#L64-L71).
91+
92+
This information is not actionable in and of itself, however this provides context on some of the [best practices](./how-to/best-practices.md) that have been laid out.
8093

8194
---
8295

@@ -109,6 +122,8 @@ You can think of streams as different "channels" where each has its own set of h
109122

110123
This is why routing via `extra={"handlers": [...]}` matters — it tells the logger which stream/handlers to use for each record.
111124

125+
For a hands on explanation of these, please read the [how-to guide on how to use handlers and filters](./how-to/use-handlers.md)
126+
112127
---
113128

114129
## Further reading

docs/how-to/add-handlers-at-runtime.md

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,9 @@
11
# How to add handlers at runtime
22

3-
You can configure handlers in two phases:
3+
Loggers and their respective handlers can be configured in two ways.
44

5-
1. Build a logger first with `get_daq_logger(...)`.
6-
2. Add more handlers/filters later, based on runtime context.
5+
1. Build a logger first with `get_daq_logger(...)`. This is covered in the [getting started tutorial](../tutorial.md)/.
6+
2. Add more handlers/filters later, based on runtime context. This is covered in this page.
77

88
This is useful in long-running services where extra outputs (for example ERS Kafka) should only be attached after additional configuration becomes available.
99

@@ -32,6 +32,8 @@ log.info("Now routes to rich + stdout by default")
3232

3333
## Suppress by default with `fallback_handler={HandlerType.Unknown}`
3434

35+
This feature takes heavy advantage of the `extra` feature of Python logging. Please read the documentation on how `extra` is used, [found here](https://dune-daq.github.io/daqpytools/dev/explanation/).
36+
3537
You can make newly-added handlers opt-in only by setting fallback handlers to `HandlerType.Unknown`. This means records without explicit `extra["handlers"]` will not be emitted by those handlers.
3638

3739
```python
@@ -56,6 +58,8 @@ log.critical(
5658
)
5759
```
5860

61+
For a more in depth discussion on this feature, please see the development docs.
62+
5963
---
6064

6165
## Passing arguments to handlers and filters via `**kwargs`

docs/how-to/best-practices.md

Lines changed: 6 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -8,11 +8,9 @@ The docs so far give a nice overview of how the logging tools work, but now you
88

99
## Use of the root logger
1010

11-
**Always** set up a named pseudo-root logger in your application as close to initialisation of your application as possible. Use the daqpytools implementation `setup_root_logger` to do so.
12-
13-
For context, in the native Python logging framework the highest possible logger is the (usually unnamed) root logger. For example, calling `logging.getLogger("top")` will usually yield you a logger called `{root}."top"`. Calling `logging.getLogger()` gets you the `{root}` logger.
11+
For background information surrounding this tip, please see the explanation on the Python root logger found [here](../explanation.md).
1412

15-
As the root logger is the highest logger which every logger inherits from, modifying this logger will have a _global_ effect on all your loggers, which is almost always undesirable.
13+
**Always** set up a named pseudo-root logger in your application as close to initialisation of your application as possible. Use the daqpytools implementation `setup_root_logger` to do so.
1614

1715
To keep things safe and compartmentalisable, a pseudo-root logger should be defined very early on, and should contain no handlers. This has benefits of compartmentalising publishing, and making things clearer in the logs due to more traceable names.
1816

@@ -36,11 +34,13 @@ As shown here, all loggers are initialised via `{pseudo_root_logger}.{parent}.{c
3634

3735
_Ideally_, loggers should only be defined once. While they _are_ singleton objects and there are simple ways to call an already defined logger, preference should be made to use inheritance to call 'new' loggers to keep things traceable.
3836

39-
A good place to define parent-level loggers with handlers (c.f `drunc.process_manager`) is the module's `__init__` file. Subsequent new loggers can be defined in the various files of that Python module. For example, in the `process_manager/utils.py`, a new logger called `drunc.process_manager.utils` can be defined and used for the duration of that file, where it automatically inherits the handlers defined from the parent-level logger.
37+
A good place to define parent-level loggers with handlers (c.f. `drunc.process_manager`) is the module's `__init__` file. Subsequent new loggers can be defined in the various files of that Python module. For example, in the `process_manager/utils.py`, a new logger called `drunc.process_manager.utils` can be defined and used for the duration of that file, where it automatically inherits the handlers defined from the parent-level logger.
4038

4139
## Calling and configuring loggers
4240

43-
Use `get_daq_logger` to initialise it once.
41+
Once the pseudo-root logger is defined, you can use `get_daq_logger` to initialise it once.
42+
43+
A useful tip for package managers is to define a function that prepends a prefix to actually inherit from the pseudo-root logger to ensure that inheritance is followed. See [here](https://github.com/DUNE-DAQ/drunc/blob/df51ce36cffe08efab6bd2a7a47554554deed22b/src/drunc/utils/utils.py#L52-L61) for an example.
4444

4545
Following the previous tip, if you feel the need to get an already-initialised logger with `get_daq_logger`, consider making a child.
4646

docs/how-to/configure-ers.md

Lines changed: 16 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,10 +2,25 @@
22

33
This page covers how to attach and use ERS (error reporting system) handlers on a logger.
44

5-
For background on ERS streams and routing, see [Concepts](../explanation.md). For the `LogHandlerConf` routing API, see [Routing messages to specific handlers](./route-messages.md).
5+
For background on ERS streams and routing, see [Concepts](../explanation.md). For the `LogHandlerConf` routing API, see [Routing messages to specific handlers](./route-messages.md). For the definition of the handler itself as well as how it can be used, see [How to use handlers and filters](https://dune-daq.github.io/daqpytools/dev/explanation/).
66

77
---
88

9+
## Configuring ERS handlers onto a new logger (by construction)
10+
11+
Use the `ers_kafka_session` variable to put in the relevant session name in `get_daq_logger`. There are several attributes that you can use to customise the ERS handler as well, such as changing the ERS application name as displayed on the ERS dashboards, exampled below. Please see the [API reference](https://dune-daq.github.io/daqpytools/APIref/handlers/protobufstream/) for full details on what can be passed in.
12+
13+
```python
14+
from daqpytools.logging import get_daq_logger,
15+
main_logger: logging.Logger = get_daq_logger(
16+
logger_name="logger_name",
17+
log_level="INFO",
18+
use_parent_handlers=True,
19+
ers_kafka_session="session_name,
20+
ers_app_name="Custom App Name", # Can be none!
21+
)
22+
```
23+
924
## Configuring ERS handlers on an existing logger
1025

1126
Use `setup_daq_ers_logger` to attach ERS-derived handlers to an existing logger based on environment configuration.

docs/how-to/route-messages.md

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,7 @@ For background on *why* routing works this way, see [Concepts](../explanation.md
66

77
---
88

9-
## Choosing handlers with HandlerTypes
9+
## Choosing handlers with HandlerTypes and the extra keyword
1010

1111
You can route individual records to specific handlers by using `extra={"handlers": [...]}`:
1212

@@ -26,7 +26,7 @@ Note: Asking for a handler type that isn't attached is a no-op. Using `HandlerTy
2626

2727
## Using LogHandlerConf for structured routing
2828

29-
`LogHandlerConf` is a configuration dataclass that encapsulates the handler setup for different streams. It handles ERS environment variable parsing and creates routing metadata bundles that you attach to records via `extra`.
29+
`LogHandlerConf` is a configuration dataclass that encapsulates the handler setup for different streams. It can handle ERS environment variable parsing and creates routing metadata bundles that you attach to records via `extra`.
3030

3131
### Understanding LogHandlerConf
3232

docs/how-to/use-handlers.md

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -28,8 +28,8 @@ As the name suggests, the file handler is used to transmit messages directly to
2828

2929
Stream handlers are used to transmit messages directly to the terminal without any color formatting. This is of great use for the logs of the controllers in drunc, which has its own method of capturing logs via a capture of the terminal output and a pipe to the relevant log file.
3030

31-
Note that stream handling consists of two handlers, one writing to `stdout` and one to `stderr`. The `stderr` stream emits only for records at `ERROR` or above.
32-
31+
Note that stream handling consists of two handlers in daqpytools, one writing to `stdout` and one to `stderr`. The `stderr` stream is configured to emit only for records at `ERROR` or above.
32+
3333
![streams_demo](../img/demo_streams.png)
3434

3535
## ERS Kafka handler
@@ -100,17 +100,17 @@ main_logger: logging.Logger = get_daq_logger(
100100
throttle=True
101101
)
102102

103-
emit_err = lambda i: main_logger.info(
103+
emit_log_record = lambda i: main_logger.info(
104104
f"Throttle test {i}",
105105
extra={"handlers": [HandlerType.Rich, HandlerType.Throttle]},
106106
)
107107

108108
for i in range(50):
109-
emit_err(i)
109+
emit_log_record(i)
110110
main_logger.warning("Sleeping for 30 seconds")
111111
time.sleep(30)
112112
for i in range(1000):
113-
emit_err(i)
113+
emit_log_record(i)
114114
```
115115

116116
Which will behave as expected.

docs/tutorial.md

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,12 +29,14 @@ test_logger = get_daq_logger(
2929
)
3030
```
3131

32-
For now, **please see the docstring of `get_daq_logger` to see what stuff you can have and what to initialise with.**
32+
Please see the API reference of `get_daq_logger` [here](https://dune-daq.github.io/daqpytools/APIref/get_daq_logger/), or alternatively the code itself [here](https://github.com/DUNE-DAQ/daqpytools/blob/develop/src/daqpytools/logging/logger.py), to see what options exist in initialising `get_daq_logger`.
3333

3434
This gives you a named logger with a single Rich handler attached, emitting at `INFO` level and above. Loggers in daqpytools are singletons — calling `get_daq_logger` with the same name twice will return the same instance, so it's safe to call this once at module level and reuse it throughout your code.
3535

3636
## Step 2: Emit your first messages
3737

38+
Emitting refers to the act of processing the log record and sending it out to its intended destination! You can emit your messages to the terminal, to a file, via a RESTapi, and so on. For this tutorial, we are simply emitting a message to the terminal.
39+
3840
```python
3941
test_logger.info("Hello, world!")
4042

docs_dev/explanation.md

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -85,16 +85,25 @@ This is extensible: you can add new `StreamType` values and teach the strategy d
8585
Defined in `specs.py`, there are two types:
8686

8787
**`HandlerSpec`** describes how to build a handler:
88+
8889
- `alias`: The `HandlerType` key
90+
8991
- `handler_class`: The runtime handler class (used to detect existing instances)
92+
9093
- `factory`: A callable that builds the handler from configuration
94+
9195
- `fallback_types`: Which `HandlerType` values this handler represents for routing purposes
96+
9297
- `target_stream`: Optional (for stream-specific handlers like stdout vs stderr)
9398

9499
**`FilterSpec`** describes how to build a logger-level filter:
100+
95101
- `alias`: The activation `HandlerType` token
102+
96103
- `filter_class`: The runtime filter class
104+
97105
- `factory`: A callable that builds the filter
106+
98107
- `fallback_types`: Default handler types for the filter
99108

100109
Specs are the "source of truth" for what a handler or filter is. When setup code needs to build something, it looks up the spec in a registry.

docs_dev/readme_toplevel.md

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,6 @@
11
# Logging in DUNE-DAQ — Documentation
22

3-
Welcome to the logging documentation for daqpytools (as of 5.6.0).
3+
Welcome to the logging documentation for daqpytools (as of fddaq-v5.6.0).
44

55
This documentation is split into two sections depending on your role:
66

0 commit comments

Comments
 (0)