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
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
|
Our scripts all use logger_options for common command line verbosity
settings. These command line options change what log levels are output
by our logging handler.
>>> def test(*args, **kw):
... import os
... import sys
... import subprocess
... from lp.services.config import config
... if 'env' in kw:
... # We want to make sure that the subprocess will have the
... # benefit of all of the dependency paths inserted by the
... # buildout. This is already set up in our environment's
... # PYTHONPATH, so use it.
... kw['env']['PYTHONPATH'] = os.environ['PYTHONPATH']
... test_script_path = os.path.join(
... config.root, 'lib', 'lp', 'services',
... 'scripts', 'tests', 'loglevels.py')
... cmd = [sys.executable, test_script_path] + list(args)
... proc = subprocess.Popen(
... cmd, stdin=subprocess.PIPE,
... stdout=subprocess.PIPE, stderr=subprocess.PIPE, **kw)
... out, err = proc.communicate()
... assert out == "", "Output to stdout"
... print err
The default is to output INFO messages and above.
When run from the test runner, there are no timestamps.
>>> test()
ERROR This is an error
WARNING This is a warning
INFO This is info
When run in other contexts, timestamps are displayed. They
take up a lot of screen space, but we find them critical when
diagnosing problems as we can tell when a script was blocked or
taking too long, and can reference other timestamped log files
such as Apache, Librarian or PostgreSQL logs.
>>> test(env={'LPCONFIG': 'development'})
1985-12-21 13:45:55 ERROR This is an error
1985-12-21 13:45:55 WARNING This is a warning
1985-12-21 13:45:55 INFO This is info
The -q or --quiet argument reduces verbosity.
>>> test("--quiet")
ERROR This is an error
WARNING This is a warning
>>> test("--quiet", "-q")
ERROR This is an error
The -v argument increases verbosity.
>>> test("-v")
ERROR This is an error
WARNING This is a warning
INFO This is info
DEBUG This is debug
More -v arguments increase verbosity more.
>>> test("-vv", "--verbose", "--verbose")
ERROR This is an error
WARNING This is a warning
INFO This is info
DEBUG This is debug
DEBUG2 This is debug2
DEBUG3 This is debug3
DEBUG4 This is debug4
Combining -q and -v arguments is handled as you would expect.
>>> args = ["-q"] * 5 + ["-v"] * 10 + ["--quiet"] * 3 + ["-v"]
>>> test(*args)
ERROR This is an error
WARNING This is a warning
INFO This is info
DEBUG This is debug
DEBUG2 This is debug2
DEBUG3 This is debug3
We have 10 debug levels. DEBUG2 to DEBUG9 are custom, defined in
lp.services.log.loglevels. All available loglevels are exported from
this module, including the stadard Python ones. You can see that
FATAL is an alias for CRITICAL, and DEBUG1 is an alias for DEBUG.
>>> from lp.services.log import loglevels
>>> levels = [
... loglevels.FATAL, loglevels.CRITICAL, loglevels.ERROR,
... loglevels.WARNING, loglevels.INFO, loglevels.DEBUG,
... loglevels.DEBUG1, loglevels.DEBUG2, loglevels.DEBUG3,
... loglevels.DEBUG4, loglevels.DEBUG5, loglevels.DEBUG6,
... loglevels.DEBUG7, loglevels.DEBUG8, loglevels.DEBUG9]
>>> import logging
>>> for level in levels:
... print "%2d %s" % (level, logging.getLevelName(level))
50 CRITICAL
50 CRITICAL
40 ERROR
30 WARNING
20 INFO
10 DEBUG
10 DEBUG
9 DEBUG2
8 DEBUG3
7 DEBUG4
6 DEBUG5
5 DEBUG6
4 DEBUG7
3 DEBUG8
2 DEBUG9
>>> test(*["-v"] * 20)
ERROR This is an error
WARNING This is a warning
INFO This is info
DEBUG This is debug
DEBUG2 This is debug2
DEBUG3 This is debug3
DEBUG4 This is debug4
DEBUG5 This is debug5
DEBUG6 This is debug6
DEBUG7 This is debug7
DEBUG8 This is debug8
DEBUG9 This is debug9
|