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
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
|
# Copyright 2009 Canonical Ltd. This software is licensed under the
# GNU Affero General Public License version 3 (see the file LICENSE).
# pylint: disable-msg=W0702
"""Integration between the normal Launchpad logging and Twisted's."""
__metaclass__ = type
__all__ = [
'LaunchpadLogFile',
'OOPSLoggingObserver',
'log_oops_from_failure',
'set_up_logging_for_script',
'set_up_oops_reporting',
'set_up_tacfile_logging',
]
import bz2
import glob
import logging
import os
import signal
import sys
from twisted.python import (
log,
logfile,
)
from twisted.python.logfile import DailyLogFile
from twisted.web import xmlrpc
from zope.interface import implements
from canonical.launchpad.scripts import logger
from canonical.launchpad.webapp import errorlog
from canonical.librarian.utils import copy_and_close
class OOPSLoggingObserver(log.PythonLoggingObserver):
"""A version of `PythonLoggingObserver` that logs OOPSes for errors."""
# XXX: JonathanLange 2008-12-23 bug=314959: As best as I can tell, this
# ought to be a log *handler*, not a feature of the bridge from
# Twisted->Python logging. Ask Michael about this.
def emit(self, eventDict):
"""See `PythonLoggingObserver.emit`."""
if eventDict.get('isError', False) and 'failure' in eventDict:
try:
failure = eventDict['failure']
request = log_oops_from_failure(failure)
self.logger.info(
"Logged OOPS id %s: %s: %s",
request.oopsid, failure.type.__name__, failure.value)
except:
self.logger.exception("Error reporting OOPS:")
else:
log.PythonLoggingObserver.emit(self, eventDict)
def log_oops_from_failure(failure, URL=None, **args):
request = errorlog.ScriptRequest(args.items(), URL=URL)
errorlog.globalErrorUtility.raising(
(failure.type, failure.value, failure.getTraceback()),
request)
return request
def set_up_logging_for_script(options, name):
"""Create a `Logger` object and configure twisted to use it.
This also configures oops reporting to use the section named
'name'."""
logger_object = logger(options, name)
set_up_oops_reporting(name, name, mangle_stdout=True)
return logger_object
def set_up_tacfile_logging(name, level):
"""Create a `Logger` object for use in tac files.
This is preferable to use over `set_up_logging_for_script` for .tac
files since there's no options to pass through. The logger object
is connected to Twisted's log and returned.
:param name: The logger instance name.
:param level: The log level to use, eg. logging.INFO or logging.DEBUG
"""
logger = logging.getLogger(name)
channel = logging.StreamHandler(log.StdioOnnaStick())
channel.setLevel(level)
channel.setFormatter(logging.Formatter('%(message)s'))
logger.addHandler(channel)
logger.setLevel(level)
return logger
def set_up_oops_reporting(configuration, name, mangle_stdout=True):
"""Set up OOPS reporting by starting the Twisted logger with an observer.
:param configuration: The name of the config section to use for oops
reporting.
:param name: The name of the logger to use for oops reporting.
:param mangle_stdout: If True, send stdout and stderr to the logger.
Defaults to False.
"""
errorlog.globalErrorUtility.configure(configuration)
log.startLoggingWithObserver(
OOPSLoggingObserver(loggerName=name).emit, mangle_stdout)
class LaunchpadLogFile(DailyLogFile):
"""Extending `DailyLogFile` to serve Launchpad purposes.
Additionally to the original daily log file rotation it also allows
call sites to control the number of rotated logfiles kept around and
when to start compressing them.
"""
maxRotatedFiles = 5
compressLast = 3
def __init__(self, name, directory, defaultMode=None,
maxRotatedFiles=None, compressLast=None):
DailyLogFile.__init__(self, name, directory, defaultMode)
if maxRotatedFiles is not None:
self.maxRotatedFiles = int(maxRotatedFiles)
if compressLast is not None:
self.compressLast = int(compressLast)
assert self.compressLast <= self.maxRotatedFiles, (
"Only %d rotate files are kept, cannot compress %d"
% (self.maxRotatedFiles, self.compressLast))
def _compressFile(self, path):
"""Compress the file in the given path using bzip2.
The compressed file will be in the same path and old file
will be removed.
:return: the path to the compressed file.
"""
bz2_path = '%s.bz2' % path
copy_and_close(open(path), bz2.BZ2File(bz2_path, mode='w'))
os.remove(path)
return bz2_path
def rotate(self):
"""Rotate the current logfile.
Also remove extra entries and compress the last ones.
"""
# Rotate the log daily.
DailyLogFile.rotate(self)
# Remove 'extra' rotated log files.
logs = self.listLogs()
for log_path in logs[self.maxRotatedFiles:]:
os.remove(log_path)
# Refresh the list of existing rotated logs
logs = self.listLogs()
# Skip compressing if there are no files to be compressed.
if len(logs) <= self.compressLast:
return
# Compress last log files.
for log_path in logs[-self.compressLast:]:
# Skip already compressed files.
if log_path.endswith('bz2'):
continue
self._compressFile(log_path)
def listLogs(self):
"""Return the list of rotate log files, newest first."""
return sorted(glob.glob("%s.*" % self.path), reverse=True)
class _QuietQueryFactory(xmlrpc._QueryFactory):
"""Override noisy to false to avoid useless log spam."""
noisy = False
class LoggingProxy(xmlrpc.Proxy):
"""A proxy that logs requests and the corresponding responses."""
queryFactory = _QuietQueryFactory
def __init__(self, url, logger, level=logging.INFO):
"""Contstruct a `LoggingProxy`.
:param url: The URL to which to post method calls.
:param logger: The logger to log requests and responses to.
:param level: The log level at which to log requests and responses.
"""
xmlrpc.Proxy.__init__(self, url)
self.logger = logger
self.level = level
self.request_count = 0
def callRemote(self, method, *args):
"""See `xmlrpc.Proxy.callRemote`.
In addition to the superclass' behavior, we log the call and its
result.
"""
request = self.request_count
self.request_count += 1
self.logger.log(
self.level, 'Sending request [%d]: %s%s', request, method, args)
def _logResult(result):
self.logger.log(
self.level, 'Reply to request [%d]: %s', request, result)
return result
deferred = xmlrpc.Proxy.callRemote(self, method, *args)
return deferred.addBoth(_logResult)
class RotatableFileLogObserver:
"""A log observer that uses a log file and reopens it on SIGUSR1."""
implements(log.ILogObserver)
def __init__(self, logfilepath):
"""Set up the logfile and possible signal handler.
Installs the signal handler for SIGUSR1 to make the process re-open
the log file.
:param logfilepath: The path to the logfile. If None, stdout is used
for logging and no signal handler will be installed.
"""
if logfilepath is None:
logFile = sys.stdout
else:
logFile = logfile.LogFile.fromFullPath(
logfilepath, rotateLength=None)
# Override if signal is set to None or SIG_DFL (0)
if not signal.getsignal(signal.SIGUSR1):
def signalHandler(signal, frame):
from twisted.internet import reactor
reactor.callFromThread(logFile.reopen)
signal.signal(signal.SIGUSR1, signalHandler)
self.observer = log.FileLogObserver(logFile)
def __call__(self, eventDict):
self.observer.emit(eventDict)
|