You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
If you don't have a reference to an action, or you're worried the function will sometimes be called outside the context of any action at all, you can use ``log_message``:
29
27
30
-
classYourClass(object):
31
-
defrun(self):
32
-
# Create a message with two fields, "key" and "value":
33
-
msg = Message.new(key=123, value=u"hello")
34
-
# Write the message:
35
-
msg.write()
36
-
37
-
38
-
Message binding
39
-
---------------
28
+
.. code-block:: python
40
29
41
-
You can also create a new ``Message`` from an existing one by binding new values.
42
-
New values will override ones on the base ``Message``, but ``bind()`` does not mutate the original ``Message``.
30
+
from eliot import log_message
43
31
44
-
.. code-block:: python
32
+
defrun(x):
33
+
log_message(message_type="in_run", xfield=x)
45
34
46
-
# This message has fields key=123, value=u"hello"
47
-
msg = Message.new(key=123, value=u"hello")
48
-
# And this one has fields key=123, value=u"other", extra=456
49
-
msg2 = msg.bind(value=u"other", extra=456)
35
+
The main downside to using this function is that it's a little slower, since it needs to handle the case where there is no action in context.
Copy file name to clipboardExpand all lines: docs/source/introduction.rst
+17-74Lines changed: 17 additions & 74 deletions
Display the source diff
Display the rich diff
Original file line number
Diff line number
Diff line change
@@ -13,30 +13,12 @@ Why Eliot?
13
13
14
14
— George Eliot, *Middlemarch*
15
15
16
-
The log messages generated by a piece of software tell a story: what, where, when, even why and how if you’re lucky. The readers of this story are more often than not other programs: monitoring systems, performance tools, or just filtering the messages down to something a human can actually comprehend. Unfortunately the output of most logging systems is ill-suited to being read by programs. Even worse, most logging systems omit critical information that both humans and their programs need.
16
+
The log messages generated by a piece of software ought tell a story: what, where, when, even why and how if you’re lucky.
17
+
But most logging systems omit the all-important *why*.
18
+
You know that some things happened, but not how they relate to each other.
17
19
18
-
Problem #1: Text is hard to search
19
-
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
20
-
21
-
Let’s say you want to find all the log messages about a specific person. A first pass of log messages might look like this:
22
-
23
-
Sir James Chettam was going to dine at the Grange to-day with another gentleman whom the girls had never seen, and about whom Dorothea felt some venerating expectation.
24
-
…
25
-
If Miss Brooke ever attained perfect meekness, it would not be for lack of inward fire.
26
-
27
-
You could do a text search for log messages containing the text “Dorothea”, but this is likely to fail for some types of searches. You might want to searching for actions involving dinner, but then you would need to search for “dine” and “dinner” and perhaps other words well. A library like `structlog`_ that can generate structured log messages will solve this first problem. You could define a “person” field in your messages and then you can search for all messages where ``person == "Dorothea"`` as well as other structured queries.
28
-
29
-
.. _structlog: https://structlog.readthedocs.org/
30
-
31
-
32
-
Problem #2: Referring to Entities
33
-
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
34
-
35
-
Every time a log message is written out you need to decide how to refer to the objects being logged. In the messages we saw above “Dorothea” and “Miss Brooke” are in fact different identifiers for the same person. Having structured messages doesn’t help us find all messages about a specific entity if the object is referred to inconsistently. What you need is infrastructure for converting specific kinds of objects in your code to fields in your structured log messages. Then you can just say “log a message that refers to this Person” and that reusable code will make sure the correct identifier is generated.
36
-
37
-
38
-
Problem #3: Actions
39
-
^^^^^^^^^^^^^^^^^^^
20
+
The problem: What caused this to happen?
21
+
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
40
22
41
23
Most log messages in your program are going to involve actions:
42
24
@@ -46,74 +28,33 @@ A marriage has a beginning and eventually an end. The end may be successful, pre
46
28
47
29
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.
48
30
49
-
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 to begin with.
50
-
51
-
52
-
Problem #4: Cross-Process Actions
53
-
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
31
+
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.
54
32
55
-
A story may involve many characters in many places at many times.
56
-
The novelist has the power to present the internal consciousness of not just one character but many: their ways of thinking, their different perceptions of reality.
33
+
None of these are possible in most logging systems since they have no concept of actions.
57
34
58
-
Similarly, actions in a distributed system may span multiple processes.
59
-
An incoming request to one server may cause a ripple of effects reaching many other processes; the logs from a single process in isolation are insufficient to understand what happened and why.
60
35
61
-
62
-
The Solution: Eliot
36
+
The solution: Eliot
63
37
^^^^^^^^^^^^^^^^^^^
64
-
Eliot is designed to solve all of these problems.
65
-
For simplicity's sake this example focuses on problems 1 and 3; problem 2 is covered by the :ref:`type system <type system>` and problem 4 by :ref:`cross-process actions <cross process tasks>`.
Here’s how the log messages generated by the code look, as summarized by the `eliot-tree <https://warehouse.python.org/project/eliot-tree/>`_ tool:
70
-
71
-
.. code::
72
-
73
-
68c12428-5d60-49f5-a269-3fb681938f98
74
-
+-- honeymoon@1
75
-
|-- people: [u'Mrs. Casaubon', u'Mr. Casaubon']
76
-
77
-
361298ae-b6b7-439a-bc9b-ffde68b7860d
78
-
+-- visited@1
79
-
|-- people: [u'Mrs. Casaubon', u'Mr. Casaubon']
80
-
|-- place: Rome, Italy
81
38
82
-
7fe1615c-e442-4bca-b667-7bb435ac6cb8
83
-
+-- visited@1
84
-
|-- people: [u'Mrs. Casaubon', u'Mr. Casaubon']
85
-
|-- place: Vatican Museum
39
+
Eliot is designed to solve these problems: the basic logging abstraction is the action.
86
40
87
-
c746230c-627e-4ff9-9173-135568df976c
88
-
+-- visited@1
89
-
|-- people: [u'Mrs. Casaubon', u'Mr. Casaubon']
90
-
|-- place: Statue #1
91
-
92
-
5482ec10-36c6-4194-964f-074e325b9329
93
-
+-- visited@1
94
-
|-- people: [u'Mrs. Casaubon', u'Mr. Casaubon']
95
-
|-- place: Statue #2
96
-
97
-
We can see different messages are related insofar as they refer to the same person, or the same thing… but we can’t trace the relationship in terms of actions. Was looking at a statue the result of visiting Rome? There’s no way we can tell from the log messages. We could manually log start and finish messages but that won’t suffice when we have many interleaved actions involving the same objects. Which of twenty parallel HTTP request tried to insert a row into the database? Chronological messages simply cannot tell us that.
98
-
99
-
The solution is to introduce two new concepts: actions and tasks. 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. A “task” is a top-level action, a basic entry point into the program which drives other actions. The task is therefore the root of the tree of actions. For example, an HTTP request received by a web server might be a task.
100
-
101
-
In our example we have one task (the honeymoon), an action (travel). We will leave looking as a normal log message because it always succeeds, and no other log message will ever need to run its context. Here’s how our code looks now:
41
+
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.
102
42
43
+
In the following example we have one top-level action (the honeymoon), which leads to other action (travel):
Actions provide a Python context manager. When the action or task starts a start message is logged.
47
+
Actions provide a Python context manager. When the action starts, a start message is logged.
107
48
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.
108
-
Not shown here but supported by the API is the ability to add fields to the success messages for an action. A similar API supports Twisted’s Deferreds.
109
49
50
+
By default the messages are machine-parseable JSON, but for human consumption a visualization is better.
110
51
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:
111
52
112
53
.. code-block:: console
113
54
114
55
f9dcc74f-ecda-4543-9e9a-1bb062d199f0
115
56
+-- honeymoon@1/started
116
-
|-- people: [u'Mrs. Casaubon', u'Mr. Casaubon']
57
+
|-- people: ['Mrs. Casaubon', 'Mr. Casaubon']
117
58
+-- visited@2,1/started
118
59
|-- place: Rome, Italy
119
60
+-- visited@2,2,1/started
@@ -128,4 +69,6 @@ Here’s how the log messages generated by the new code look, as summarized by t
128
69
+-- visited@2,3/succeeded
129
70
+-- honeymoon@3/succeeded
130
71
131
-
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.
72
+
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.
73
+
74
+
Was looking at a statue the result of the honeymoon? It most definitely was.
Copy file name to clipboardExpand all lines: docs/source/news.rst
+1Lines changed: 1 addition & 0 deletions
Display the source diff
Display the rich diff
Original file line number
Diff line number
Diff line change
@@ -6,6 +6,7 @@ What's New
6
6
7
7
Features:
8
8
9
+
* ``Message.log()`` has been replaced by top-level function ``log_message()``. Or if you're in the context of action ``ctx``, you can call ``ctx.log()``. See :ref:`messages` for details.
9
10
* Python 3.8 is now supported.
10
11
* The ``eliot-prettyprint`` command line tool now supports a more compact format by using the ``--compact`` argument.
11
12
* The ``eliot-prettyprint`` command line tool now supports outputting in local timezones using the ``--local-timezone`` argument.
0 commit comments