Package cherrypy :: Module _cplogging
[hide private]
[frames] | no frames]

Source Code for Module cherrypy._cplogging

  1  """ 
  2  Simple config 
  3  ============= 
  4   
  5  Although CherryPy uses the :mod:`Python logging module <logging>`, it does so 
  6  behind the scenes so that simple logging is simple, but complicated logging 
  7  is still possible. "Simple" logging means that you can log to the screen 
  8  (i.e. console/stdout) or to a file, and that you can easily have separate 
  9  error and access log files. 
 10   
 11  Here are the simplified logging settings. You use these by adding lines to 
 12  your config file or dict. You should set these at either the global level or 
 13  per application (see next), but generally not both. 
 14   
 15   * ``log.screen``: Set this to True to have both "error" and "access" messages 
 16     printed to stdout. 
 17   * ``log.access_file``: Set this to an absolute filename where you want 
 18     "access" messages written. 
 19   * ``log.error_file``: Set this to an absolute filename where you want "error" 
 20     messages written. 
 21   
 22  Many events are automatically logged; to log your own application events, call 
 23  :func:`cherrypy.log`. 
 24   
 25  Architecture 
 26  ============ 
 27   
 28  Separate scopes 
 29  --------------- 
 30   
 31  CherryPy provides log managers at both the global and application layers. 
 32  This means you can have one set of logging rules for your entire site, 
 33  and another set of rules specific to each application. The global log 
 34  manager is found at :func:`cherrypy.log`, and the log manager for each 
 35  application is found at :attr:`app.log<cherrypy._cptree.Application.log>`. 
 36  If you're inside a request, the latter is reachable from 
 37  ``cherrypy.request.app.log``; if you're outside a request, you'll have to 
 38  obtain a reference to the ``app``: either the return value of 
 39  :func:`tree.mount()<cherrypy._cptree.Tree.mount>` or, if you used 
 40  :func:`quickstart()<cherrypy.quickstart>` instead, via 
 41  ``cherrypy.tree.apps['/']``. 
 42   
 43  By default, the global logs are named "cherrypy.error" and "cherrypy.access", 
 44  and the application logs are named "cherrypy.error.2378745" and 
 45  "cherrypy.access.2378745" (the number is the id of the Application object). 
 46  This means that the application logs "bubble up" to the site logs, so if your 
 47  application has no log handlers, the site-level handlers will still log the 
 48  messages. 
 49   
 50  Errors vs. Access 
 51  ----------------- 
 52   
 53  Each log manager handles both "access" messages (one per HTTP request) and 
 54  "error" messages (everything else). Note that the "error" log is not just for 
 55  errors! The format of access messages is highly formalized, but the error log 
 56  isn't--it receives messages from a variety of sources (including full error 
 57  tracebacks, if enabled). 
 58   
 59  If you are logging the access log and error log to the same source, then there 
 60  is a possibility that a specially crafted error message may replicate an access 
 61  log message as described in CWE-117.  In this case it is the application 
 62  developer's responsibility to manually escape data before using CherryPy's log() 
 63  functionality, or they may create an application that is vulnerable to CWE-117. 
 64  This would be achieved by using a custom handler escape any special characters, 
 65  and attached as described below. 
 66   
 67  Custom Handlers 
 68  =============== 
 69   
 70  The simple settings above work by manipulating Python's standard :mod:`logging` 
 71  module. So when you need something more complex, the full power of the standard 
 72  module is yours to exploit. You can borrow or create custom handlers, formats, 
 73  filters, and much more. Here's an example that skips the standard FileHandler 
 74  and uses a RotatingFileHandler instead: 
 75   
 76  :: 
 77   
 78      #python 
 79      log = app.log 
 80   
 81      # Remove the default FileHandlers if present. 
 82      log.error_file = "" 
 83      log.access_file = "" 
 84   
 85      maxBytes = getattr(log, "rot_maxBytes", 10000000) 
 86      backupCount = getattr(log, "rot_backupCount", 1000) 
 87   
 88      # Make a new RotatingFileHandler for the error log. 
 89      fname = getattr(log, "rot_error_file", "error.log") 
 90      h = handlers.RotatingFileHandler(fname, 'a', maxBytes, backupCount) 
 91      h.setLevel(DEBUG) 
 92      h.setFormatter(_cplogging.logfmt) 
 93      log.error_log.addHandler(h) 
 94   
 95      # Make a new RotatingFileHandler for the access log. 
 96      fname = getattr(log, "rot_access_file", "access.log") 
 97      h = handlers.RotatingFileHandler(fname, 'a', maxBytes, backupCount) 
 98      h.setLevel(DEBUG) 
 99      h.setFormatter(_cplogging.logfmt) 
100      log.access_log.addHandler(h) 
101   
102   
103  The ``rot_*`` attributes are pulled straight from the application log object. 
104  Since "log.*" config entries simply set attributes on the log object, you can 
105  add custom attributes to your heart's content. Note that these handlers are 
106  used ''instead'' of the default, simple handlers outlined above (so don't set 
107  the "log.error_file" config entry, for example). 
108  """ 
109   
110  import datetime 
111  import logging 
112  # Silence the no-handlers "warning" (stderr write!) in stdlib logging 
113  logging.Logger.manager.emittedNoHandlerWarning = 1 
114  logfmt = logging.Formatter("%(message)s") 
115  import os 
116  import sys 
117   
118  import cherrypy 
119  from cherrypy import _cperror 
120  from cherrypy._cpcompat import ntob, py3k 
121   
122   
123 -class NullHandler(logging.Handler):
124 125 """A no-op logging handler to silence the logging.lastResort handler.""" 126
127 - def handle(self, record):
128 pass
129
130 - def emit(self, record):
131 pass
132
133 - def createLock(self):
134 self.lock = None
135 136
137 -class LogManager(object):
138 139 """An object to assist both simple and advanced logging. 140 141 ``cherrypy.log`` is an instance of this class. 142 """ 143 144 appid = None 145 """The id() of the Application object which owns this log manager. If this 146 is a global log manager, appid is None.""" 147 148 error_log = None 149 """The actual :class:`logging.Logger` instance for error messages.""" 150 151 access_log = None 152 """The actual :class:`logging.Logger` instance for access messages.""" 153 154 if py3k: 155 access_log_format = \ 156 '{h} {l} {u} {t} "{r}" {s} {b} "{f}" "{a}"' 157 else: 158 access_log_format = \ 159 '%(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s"' 160 161 logger_root = None 162 """The "top-level" logger name. 163 164 This string will be used as the first segment in the Logger names. 165 The default is "cherrypy", for example, in which case the Logger names 166 will be of the form:: 167 168 cherrypy.error.<appid> 169 cherrypy.access.<appid> 170 """ 171
172 - def __init__(self, appid=None, logger_root="cherrypy"):
173 self.logger_root = logger_root 174 self.appid = appid 175 if appid is None: 176 self.error_log = logging.getLogger("%s.error" % logger_root) 177 self.access_log = logging.getLogger("%s.access" % logger_root) 178 else: 179 self.error_log = logging.getLogger( 180 "%s.error.%s" % (logger_root, appid)) 181 self.access_log = logging.getLogger( 182 "%s.access.%s" % (logger_root, appid)) 183 self.error_log.setLevel(logging.INFO) 184 self.access_log.setLevel(logging.INFO) 185 186 # Silence the no-handlers "warning" (stderr write!) in stdlib logging 187 self.error_log.addHandler(NullHandler()) 188 self.access_log.addHandler(NullHandler()) 189 190 cherrypy.engine.subscribe('graceful', self.reopen_files)
191
192 - def reopen_files(self):
193 """Close and reopen all file handlers.""" 194 for log in (self.error_log, self.access_log): 195 for h in log.handlers: 196 if isinstance(h, logging.FileHandler): 197 h.acquire() 198 h.stream.close() 199 h.stream = open(h.baseFilename, h.mode) 200 h.release()
201
202 - def error(self, msg='', context='', severity=logging.INFO, 203 traceback=False):
204 """Write the given ``msg`` to the error log. 205 206 This is not just for errors! Applications may call this at any time 207 to log application-specific information. 208 209 If ``traceback`` is True, the traceback of the current exception 210 (if any) will be appended to ``msg``. 211 """ 212 if traceback: 213 msg += _cperror.format_exc() 214 self.error_log.log(severity, ' '.join((self.time(), context, msg)))
215
216 - def __call__(self, *args, **kwargs):
217 """An alias for ``error``.""" 218 return self.error(*args, **kwargs)
219
220 - def access(self):
221 """Write to the access log (in Apache/NCSA Combined Log format). 222 223 See the 224 `apache documentation <http://httpd.apache.org/docs/current/logs.html#combined>`_ 225 for format details. 226 227 CherryPy calls this automatically for you. Note there are no arguments; 228 it collects the data itself from 229 :class:`cherrypy.request<cherrypy._cprequest.Request>`. 230 231 Like Apache started doing in 2.0.46, non-printable and other special 232 characters in %r (and we expand that to all parts) are escaped using 233 \\xhh sequences, where hh stands for the hexadecimal representation 234 of the raw byte. Exceptions from this rule are " and \\, which are 235 escaped by prepending a backslash, and all whitespace characters, 236 which are written in their C-style notation (\\n, \\t, etc). 237 """ 238 request = cherrypy.serving.request 239 remote = request.remote 240 response = cherrypy.serving.response 241 outheaders = response.headers 242 inheaders = request.headers 243 if response.output_status is None: 244 status = "-" 245 else: 246 status = response.output_status.split(ntob(" "), 1)[0] 247 if py3k: 248 status = status.decode('ISO-8859-1') 249 250 atoms = {'h': remote.name or remote.ip, 251 'l': '-', 252 'u': getattr(request, "login", None) or "-", 253 't': self.time(), 254 'r': request.request_line, 255 's': status, 256 'b': dict.get(outheaders, 'Content-Length', '') or "-", 257 'f': dict.get(inheaders, 'Referer', ''), 258 'a': dict.get(inheaders, 'User-Agent', ''), 259 } 260 if py3k: 261 for k, v in atoms.items(): 262 if not isinstance(v, str): 263 v = str(v) 264 v = v.replace('"', '\\"').encode('utf8') 265 # Fortunately, repr(str) escapes unprintable chars, \n, \t, etc 266 # and backslash for us. All we have to do is strip the quotes. 267 v = repr(v)[2:-1] 268 269 # in python 3.0 the repr of bytes (as returned by encode) 270 # uses double \'s. But then the logger escapes them yet, again 271 # resulting in quadruple slashes. Remove the extra one here. 272 v = v.replace('\\\\', '\\') 273 274 # Escape double-quote. 275 atoms[k] = v 276 277 try: 278 self.access_log.log( 279 logging.INFO, self.access_log_format.format(**atoms)) 280 except: 281 self(traceback=True) 282 else: 283 for k, v in atoms.items(): 284 if isinstance(v, unicode): 285 v = v.encode('utf8') 286 elif not isinstance(v, str): 287 v = str(v) 288 # Fortunately, repr(str) escapes unprintable chars, \n, \t, etc 289 # and backslash for us. All we have to do is strip the quotes. 290 v = repr(v)[1:-1] 291 # Escape double-quote. 292 atoms[k] = v.replace('"', '\\"') 293 294 try: 295 self.access_log.log( 296 logging.INFO, self.access_log_format % atoms) 297 except: 298 self(traceback=True)
299
300 - def time(self):
301 """Return now() in Apache Common Log Format (no timezone).""" 302 now = datetime.datetime.now() 303 monthnames = ['jan', 'feb', 'mar', 'apr', 'may', 'jun', 304 'jul', 'aug', 'sep', 'oct', 'nov', 'dec'] 305 month = monthnames[now.month - 1].capitalize() 306 return ('[%02d/%s/%04d:%02d:%02d:%02d]' % 307 (now.day, month, now.year, now.hour, now.minute, now.second))
308
309 - def _get_builtin_handler(self, log, key):
310 for h in log.handlers: 311 if getattr(h, "_cpbuiltin", None) == key: 312 return h
313 314 # ------------------------- Screen handlers ------------------------- #
315 - def _set_screen_handler(self, log, enable, stream=None):
316 h = self._get_builtin_handler(log, "screen") 317 if enable: 318 if not h: 319 if stream is None: 320 stream = sys.stderr 321 h = logging.StreamHandler(stream) 322 h.setFormatter(logfmt) 323 h._cpbuiltin = "screen" 324 log.addHandler(h) 325 elif h: 326 log.handlers.remove(h)
327
328 - def _get_screen(self):
329 h = self._get_builtin_handler 330 has_h = h(self.error_log, "screen") or h(self.access_log, "screen") 331 return bool(has_h)
332
333 - def _set_screen(self, newvalue):
334 self._set_screen_handler(self.error_log, newvalue, stream=sys.stderr) 335 self._set_screen_handler(self.access_log, newvalue, stream=sys.stdout)
336 screen = property(_get_screen, _set_screen, 337 doc="""Turn stderr/stdout logging on or off. 338 339 If you set this to True, it'll add the appropriate StreamHandler for 340 you. If you set it to False, it will remove the handler. 341 """) 342 343 # -------------------------- File handlers -------------------------- # 344
345 - def _add_builtin_file_handler(self, log, fname):
346 h = logging.FileHandler(fname) 347 h.setFormatter(logfmt) 348 h._cpbuiltin = "file" 349 log.addHandler(h)
350
351 - def _set_file_handler(self, log, filename):
352 h = self._get_builtin_handler(log, "file") 353 if filename: 354 if h: 355 if h.baseFilename != os.path.abspath(filename): 356 h.close() 357 log.handlers.remove(h) 358 self._add_builtin_file_handler(log, filename) 359 else: 360 self._add_builtin_file_handler(log, filename) 361 else: 362 if h: 363 h.close() 364 log.handlers.remove(h)
365
366 - def _get_error_file(self):
367 h = self._get_builtin_handler(self.error_log, "file") 368 if h: 369 return h.baseFilename 370 return ''
371
372 - def _set_error_file(self, newvalue):
373 self._set_file_handler(self.error_log, newvalue)
374 error_file = property(_get_error_file, _set_error_file, 375 doc="""The filename for self.error_log. 376 377 If you set this to a string, it'll add the appropriate FileHandler for 378 you. If you set it to ``None`` or ``''``, it will remove the handler. 379 """) 380
381 - def _get_access_file(self):
382 h = self._get_builtin_handler(self.access_log, "file") 383 if h: 384 return h.baseFilename 385 return ''
386
387 - def _set_access_file(self, newvalue):
388 self._set_file_handler(self.access_log, newvalue)
389 access_file = property(_get_access_file, _set_access_file, 390 doc="""The filename for self.access_log. 391 392 If you set this to a string, it'll add the appropriate FileHandler for 393 you. If you set it to ``None`` or ``''``, it will remove the handler. 394 """) 395 396 # ------------------------- WSGI handlers ------------------------- # 397
398 - def _set_wsgi_handler(self, log, enable):
399 h = self._get_builtin_handler(log, "wsgi") 400 if enable: 401 if not h: 402 h = WSGIErrorHandler() 403 h.setFormatter(logfmt) 404 h._cpbuiltin = "wsgi" 405 log.addHandler(h) 406 elif h: 407 log.handlers.remove(h)
408
409 - def _get_wsgi(self):
410 return bool(self._get_builtin_handler(self.error_log, "wsgi"))
411
412 - def _set_wsgi(self, newvalue):
413 self._set_wsgi_handler(self.error_log, newvalue)
414 wsgi = property(_get_wsgi, _set_wsgi, 415 doc="""Write errors to wsgi.errors. 416 417 If you set this to True, it'll add the appropriate 418 :class:`WSGIErrorHandler<cherrypy._cplogging.WSGIErrorHandler>` for you 419 (which writes errors to ``wsgi.errors``). 420 If you set it to False, it will remove the handler. 421 """)
422 423
424 -class WSGIErrorHandler(logging.Handler):
425 426 "A handler class which writes logging records to environ['wsgi.errors']." 427
428 - def flush(self):
429 """Flushes the stream.""" 430 try: 431 stream = cherrypy.serving.request.wsgi_environ.get('wsgi.errors') 432 except (AttributeError, KeyError): 433 pass 434 else: 435 stream.flush()
436
437 - def emit(self, record):
438 """Emit a record.""" 439 try: 440 stream = cherrypy.serving.request.wsgi_environ.get('wsgi.errors') 441 except (AttributeError, KeyError): 442 pass 443 else: 444 try: 445 msg = self.format(record) 446 fs = "%s\n" 447 import types 448 # if no unicode support... 449 if not hasattr(types, "UnicodeType"): 450 stream.write(fs % msg) 451 else: 452 try: 453 stream.write(fs % msg) 454 except UnicodeError: 455 stream.write(fs % msg.encode("UTF-8")) 456 self.flush() 457 except: 458 self.handleError(record)
459