1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
|
Why Eliot?
==========
.. epigraph::
Suppose we turn from outside estimates of a man, to wonder, with keener
interest, what is the report of his own consciousness about his doings or
capacity: with what hindrances he is carrying on his daily labors; what
fading of hopes, or what deeper fixity of self-delusion the years are
marking off within him; and with what spirit he wrestles against universal
pressure, which will one day be too heavy for him, and bring his heart to
its final pause.
— George Eliot, *Middlemarch*
The log messages generated by a piece of software ought tell a story: what, where, when, even why and how if you’re lucky.
But most logging systems omit the all-important *why*.
You know that some things happened, but not how they relate to each other.
The problem: What caused this to happen?
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Most log messages in your program are going to involve actions:
Not long after that dinner-party she had become Mrs. Casaubon, and was on her way to Rome.
A marriage has a beginning and eventually an end. The end may be successful, presuming “until death do us part” is a form of success, or a failure. The same is true of all actions, much like function calls in Python are started and eventually return a result or throw an exception. Actions may of course span multiple function calls or extended periods of time.
Actions also generate other actions: a marriage leads to a trip to Rome, the trip to Rome might lead to a visit to the Vatican Museum, and so on. Other unrelated actions are occurring at the same time, resulting in a forest of actions, with root actions that grow a tree of child actions.
You might want to trace an action from beginning to end, e.g. to measure how long it took to run. You might want to know what high-level action caused a particular unexpected low-level action. You might want to know what actions a specific entity was involved with.
None of these are possible in most logging systems since they have no concept of actions.
The solution: Eliot
^^^^^^^^^^^^^^^^^^^
Eliot is designed to solve these problems: the basic logging abstraction is the action.
An “action” is something with a start and an end; the end can be successful or it can fail due to an exception. Log messages, as well as log actions, know the log action whose context they are running in. The result is a tree of actions.
In the following example we have one top-level action (the honeymoon), which leads to other action (travel):
.. literalinclude:: ../../examples/rometrip_actions.py
Actions provide a Python context manager. When the action starts, a start message is logged.
If the block finishes successfully a success message is logged for the action; if an exception is thrown a failure message is logged for the action with the exception type and contents.
By default the messages are machine-parseable JSON, but for human consumption a visualization is better.
Here’s how the log messages generated by the new code look, as summarized by the `eliot-tree <https://warehouse.python.org/project/eliot-tree/>`_ tool:
.. code-block:: console
f9dcc74f-ecda-4543-9e9a-1bb062d199f0
+-- honeymoon@1/started
|-- people: ['Mrs. Casaubon', 'Mr. Casaubon']
+-- visited@2,1/started
|-- place: Rome, Italy
+-- visited@2,2,1/started
|-- place: Vatican Museum
+-- visited@2,2,2,1/started
|-- place: Statue #1
+-- visited@2,2,2,2/succeeded
+-- visited@2,2,3,1/started
|-- place: Statue #2
+-- visited@2,2,3,2/succeeded
+-- visited@2,2,4/succeeded
+-- visited@2,3/succeeded
+-- honeymoon@3/succeeded
No longer isolated fragments of meaning, our log messages are now a story. Log events have context, you can tell where they came from and what they led to without guesswork.
Was looking at a statue the result of the honeymoon? It most definitely was.
|
