glogging.py 15 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464
  1. # -*- coding: utf-8 -
  2. #
  3. # This file is part of gunicorn released under the MIT license.
  4. # See the NOTICE for more information.
  5. import base64
  6. import binascii
  7. import time
  8. import logging
  9. logging.Logger.manager.emittedNoHandlerWarning = 1 # noqa
  10. from logging.config import dictConfig
  11. from logging.config import fileConfig
  12. import os
  13. import socket
  14. import sys
  15. import threading
  16. import traceback
  17. from gunicorn import util
  18. # syslog facility codes
  19. SYSLOG_FACILITIES = {
  20. "auth": 4,
  21. "authpriv": 10,
  22. "cron": 9,
  23. "daemon": 3,
  24. "ftp": 11,
  25. "kern": 0,
  26. "lpr": 6,
  27. "mail": 2,
  28. "news": 7,
  29. "security": 4, # DEPRECATED
  30. "syslog": 5,
  31. "user": 1,
  32. "uucp": 8,
  33. "local0": 16,
  34. "local1": 17,
  35. "local2": 18,
  36. "local3": 19,
  37. "local4": 20,
  38. "local5": 21,
  39. "local6": 22,
  40. "local7": 23
  41. }
  42. CONFIG_DEFAULTS = dict(
  43. version=1,
  44. disable_existing_loggers=False,
  45. root={"level": "INFO", "handlers": ["console"]},
  46. loggers={
  47. "gunicorn.error": {
  48. "level": "INFO",
  49. "handlers": ["error_console"],
  50. "propagate": True,
  51. "qualname": "gunicorn.error"
  52. },
  53. "gunicorn.access": {
  54. "level": "INFO",
  55. "handlers": ["console"],
  56. "propagate": True,
  57. "qualname": "gunicorn.access"
  58. }
  59. },
  60. handlers={
  61. "console": {
  62. "class": "logging.StreamHandler",
  63. "formatter": "generic",
  64. "stream": "ext://sys.stdout"
  65. },
  66. "error_console": {
  67. "class": "logging.StreamHandler",
  68. "formatter": "generic",
  69. "stream": "ext://sys.stderr"
  70. },
  71. },
  72. formatters={
  73. "generic": {
  74. "format": "%(asctime)s [%(process)d] [%(levelname)s] %(message)s",
  75. "datefmt": "[%Y-%m-%d %H:%M:%S %z]",
  76. "class": "logging.Formatter"
  77. }
  78. }
  79. )
  80. def loggers():
  81. """ get list of all loggers """
  82. root = logging.root
  83. existing = root.manager.loggerDict.keys()
  84. return [logging.getLogger(name) for name in existing]
  85. class SafeAtoms(dict):
  86. def __init__(self, atoms):
  87. dict.__init__(self)
  88. for key, value in atoms.items():
  89. if isinstance(value, str):
  90. self[key] = value.replace('"', '\\"')
  91. else:
  92. self[key] = value
  93. def __getitem__(self, k):
  94. if k.startswith("{"):
  95. kl = k.lower()
  96. if kl in self:
  97. return super().__getitem__(kl)
  98. else:
  99. return "-"
  100. if k in self:
  101. return super().__getitem__(k)
  102. else:
  103. return '-'
  104. def parse_syslog_address(addr):
  105. # unix domain socket type depends on backend
  106. # SysLogHandler will try both when given None
  107. if addr.startswith("unix://"):
  108. sock_type = None
  109. # set socket type only if explicitly requested
  110. parts = addr.split("#", 1)
  111. if len(parts) == 2:
  112. addr = parts[0]
  113. if parts[1] == "dgram":
  114. sock_type = socket.SOCK_DGRAM
  115. return (sock_type, addr.split("unix://")[1])
  116. if addr.startswith("udp://"):
  117. addr = addr.split("udp://")[1]
  118. socktype = socket.SOCK_DGRAM
  119. elif addr.startswith("tcp://"):
  120. addr = addr.split("tcp://")[1]
  121. socktype = socket.SOCK_STREAM
  122. else:
  123. raise RuntimeError("invalid syslog address")
  124. if '[' in addr and ']' in addr:
  125. host = addr.split(']')[0][1:].lower()
  126. elif ':' in addr:
  127. host = addr.split(':')[0].lower()
  128. elif addr == "":
  129. host = "localhost"
  130. else:
  131. host = addr.lower()
  132. addr = addr.split(']')[-1]
  133. if ":" in addr:
  134. port = addr.split(':', 1)[1]
  135. if not port.isdigit():
  136. raise RuntimeError("%r is not a valid port number." % port)
  137. port = int(port)
  138. else:
  139. port = 514
  140. return (socktype, (host, port))
  141. class Logger(object):
  142. LOG_LEVELS = {
  143. "critical": logging.CRITICAL,
  144. "error": logging.ERROR,
  145. "warning": logging.WARNING,
  146. "info": logging.INFO,
  147. "debug": logging.DEBUG
  148. }
  149. loglevel = logging.INFO
  150. error_fmt = r"%(asctime)s [%(process)d] [%(levelname)s] %(message)s"
  151. datefmt = r"[%Y-%m-%d %H:%M:%S %z]"
  152. access_fmt = "%(message)s"
  153. syslog_fmt = "[%(process)d] %(message)s"
  154. atoms_wrapper_class = SafeAtoms
  155. def __init__(self, cfg):
  156. self.error_log = logging.getLogger("gunicorn.error")
  157. self.error_log.propagate = False
  158. self.access_log = logging.getLogger("gunicorn.access")
  159. self.access_log.propagate = False
  160. self.error_handlers = []
  161. self.access_handlers = []
  162. self.logfile = None
  163. self.lock = threading.Lock()
  164. self.cfg = cfg
  165. self.setup(cfg)
  166. def setup(self, cfg):
  167. self.loglevel = self.LOG_LEVELS.get(cfg.loglevel.lower(), logging.INFO)
  168. self.error_log.setLevel(self.loglevel)
  169. self.access_log.setLevel(logging.INFO)
  170. # set gunicorn.error handler
  171. if self.cfg.capture_output and cfg.errorlog != "-":
  172. for stream in sys.stdout, sys.stderr:
  173. stream.flush()
  174. self.logfile = open(cfg.errorlog, 'a+')
  175. os.dup2(self.logfile.fileno(), sys.stdout.fileno())
  176. os.dup2(self.logfile.fileno(), sys.stderr.fileno())
  177. self._set_handler(self.error_log, cfg.errorlog,
  178. logging.Formatter(self.error_fmt, self.datefmt))
  179. # set gunicorn.access handler
  180. if cfg.accesslog is not None:
  181. self._set_handler(
  182. self.access_log, cfg.accesslog,
  183. fmt=logging.Formatter(self.access_fmt), stream=sys.stdout
  184. )
  185. # set syslog handler
  186. if cfg.syslog:
  187. self._set_syslog_handler(
  188. self.error_log, cfg, self.syslog_fmt, "error"
  189. )
  190. if not cfg.disable_redirect_access_to_syslog:
  191. self._set_syslog_handler(
  192. self.access_log, cfg, self.syslog_fmt, "access"
  193. )
  194. if cfg.logconfig_dict:
  195. config = CONFIG_DEFAULTS.copy()
  196. config.update(cfg.logconfig_dict)
  197. try:
  198. dictConfig(config)
  199. except (
  200. AttributeError,
  201. ImportError,
  202. ValueError,
  203. TypeError
  204. ) as exc:
  205. raise RuntimeError(str(exc))
  206. elif cfg.logconfig:
  207. if os.path.exists(cfg.logconfig):
  208. defaults = CONFIG_DEFAULTS.copy()
  209. defaults['__file__'] = cfg.logconfig
  210. defaults['here'] = os.path.dirname(cfg.logconfig)
  211. fileConfig(cfg.logconfig, defaults=defaults,
  212. disable_existing_loggers=False)
  213. else:
  214. msg = "Error: log config '%s' not found"
  215. raise RuntimeError(msg % cfg.logconfig)
  216. def critical(self, msg, *args, **kwargs):
  217. self.error_log.critical(msg, *args, **kwargs)
  218. def error(self, msg, *args, **kwargs):
  219. self.error_log.error(msg, *args, **kwargs)
  220. def warning(self, msg, *args, **kwargs):
  221. self.error_log.warning(msg, *args, **kwargs)
  222. def info(self, msg, *args, **kwargs):
  223. self.error_log.info(msg, *args, **kwargs)
  224. def debug(self, msg, *args, **kwargs):
  225. self.error_log.debug(msg, *args, **kwargs)
  226. def exception(self, msg, *args, **kwargs):
  227. self.error_log.exception(msg, *args, **kwargs)
  228. def log(self, lvl, msg, *args, **kwargs):
  229. if isinstance(lvl, str):
  230. lvl = self.LOG_LEVELS.get(lvl.lower(), logging.INFO)
  231. self.error_log.log(lvl, msg, *args, **kwargs)
  232. def atoms(self, resp, req, environ, request_time):
  233. """ Gets atoms for log formating.
  234. """
  235. status = resp.status
  236. if isinstance(status, str):
  237. status = status.split(None, 1)[0]
  238. atoms = {
  239. 'h': environ.get('REMOTE_ADDR', '-'),
  240. 'l': '-',
  241. 'u': self._get_user(environ) or '-',
  242. 't': self.now(),
  243. 'r': "%s %s %s" % (environ['REQUEST_METHOD'],
  244. environ['RAW_URI'],
  245. environ["SERVER_PROTOCOL"]),
  246. 's': status,
  247. 'm': environ.get('REQUEST_METHOD'),
  248. 'U': environ.get('PATH_INFO'),
  249. 'q': environ.get('QUERY_STRING'),
  250. 'H': environ.get('SERVER_PROTOCOL'),
  251. 'b': getattr(resp, 'sent', None) is not None and str(resp.sent) or '-',
  252. 'B': getattr(resp, 'sent', None),
  253. 'f': environ.get('HTTP_REFERER', '-'),
  254. 'a': environ.get('HTTP_USER_AGENT', '-'),
  255. 'T': request_time.seconds,
  256. 'D': (request_time.seconds * 1000000) + request_time.microseconds,
  257. 'M': (request_time.seconds * 1000) + int(request_time.microseconds/1000),
  258. 'L': "%d.%06d" % (request_time.seconds, request_time.microseconds),
  259. 'p': "<%s>" % os.getpid()
  260. }
  261. # add request headers
  262. if hasattr(req, 'headers'):
  263. req_headers = req.headers
  264. else:
  265. req_headers = req
  266. if hasattr(req_headers, "items"):
  267. req_headers = req_headers.items()
  268. atoms.update({"{%s}i" % k.lower(): v for k, v in req_headers})
  269. resp_headers = resp.headers
  270. if hasattr(resp_headers, "items"):
  271. resp_headers = resp_headers.items()
  272. # add response headers
  273. atoms.update({"{%s}o" % k.lower(): v for k, v in resp_headers})
  274. # add environ variables
  275. environ_variables = environ.items()
  276. atoms.update({"{%s}e" % k.lower(): v for k, v in environ_variables})
  277. return atoms
  278. def access(self, resp, req, environ, request_time):
  279. """ See http://httpd.apache.org/docs/2.0/logs.html#combined
  280. for format details
  281. """
  282. if not (self.cfg.accesslog or self.cfg.logconfig or
  283. self.cfg.logconfig_dict or
  284. (self.cfg.syslog and not self.cfg.disable_redirect_access_to_syslog)):
  285. return
  286. # wrap atoms:
  287. # - make sure atoms will be test case insensitively
  288. # - if atom doesn't exist replace it by '-'
  289. safe_atoms = self.atoms_wrapper_class(
  290. self.atoms(resp, req, environ, request_time)
  291. )
  292. try:
  293. self.access_log.info(self.cfg.access_log_format, safe_atoms)
  294. except Exception:
  295. self.error(traceback.format_exc())
  296. def now(self):
  297. """ return date in Apache Common Log Format """
  298. return time.strftime('[%d/%b/%Y:%H:%M:%S %z]')
  299. def reopen_files(self):
  300. if self.cfg.capture_output and self.cfg.errorlog != "-":
  301. for stream in sys.stdout, sys.stderr:
  302. stream.flush()
  303. with self.lock:
  304. if self.logfile is not None:
  305. self.logfile.close()
  306. self.logfile = open(self.cfg.errorlog, 'a+')
  307. os.dup2(self.logfile.fileno(), sys.stdout.fileno())
  308. os.dup2(self.logfile.fileno(), sys.stderr.fileno())
  309. for log in loggers():
  310. for handler in log.handlers:
  311. if isinstance(handler, logging.FileHandler):
  312. handler.acquire()
  313. try:
  314. if handler.stream:
  315. handler.close()
  316. handler.stream = handler._open()
  317. finally:
  318. handler.release()
  319. def close_on_exec(self):
  320. for log in loggers():
  321. for handler in log.handlers:
  322. if isinstance(handler, logging.FileHandler):
  323. handler.acquire()
  324. try:
  325. if handler.stream:
  326. util.close_on_exec(handler.stream.fileno())
  327. finally:
  328. handler.release()
  329. def _get_gunicorn_handler(self, log):
  330. for h in log.handlers:
  331. if getattr(h, "_gunicorn", False):
  332. return h
  333. def _set_handler(self, log, output, fmt, stream=None):
  334. # remove previous gunicorn log handler
  335. h = self._get_gunicorn_handler(log)
  336. if h:
  337. log.handlers.remove(h)
  338. if output is not None:
  339. if output == "-":
  340. h = logging.StreamHandler(stream)
  341. else:
  342. util.check_is_writeable(output)
  343. h = logging.FileHandler(output)
  344. # make sure the user can reopen the file
  345. try:
  346. os.chown(h.baseFilename, self.cfg.user, self.cfg.group)
  347. except OSError:
  348. # it's probably OK there, we assume the user has given
  349. # /dev/null as a parameter.
  350. pass
  351. h.setFormatter(fmt)
  352. h._gunicorn = True
  353. log.addHandler(h)
  354. def _set_syslog_handler(self, log, cfg, fmt, name):
  355. # setup format
  356. prefix = cfg.syslog_prefix or cfg.proc_name.replace(":", ".")
  357. prefix = "gunicorn.%s.%s" % (prefix, name)
  358. # set format
  359. fmt = logging.Formatter(r"%s: %s" % (prefix, fmt))
  360. # syslog facility
  361. try:
  362. facility = SYSLOG_FACILITIES[cfg.syslog_facility.lower()]
  363. except KeyError:
  364. raise RuntimeError("unknown facility name")
  365. # parse syslog address
  366. socktype, addr = parse_syslog_address(cfg.syslog_addr)
  367. # finally setup the syslog handler
  368. h = logging.handlers.SysLogHandler(address=addr,
  369. facility=facility, socktype=socktype)
  370. h.setFormatter(fmt)
  371. h._gunicorn = True
  372. log.addHandler(h)
  373. def _get_user(self, environ):
  374. user = None
  375. http_auth = environ.get("HTTP_AUTHORIZATION")
  376. if http_auth and http_auth.lower().startswith('basic'):
  377. auth = http_auth.split(" ", 1)
  378. if len(auth) == 2:
  379. try:
  380. # b64decode doesn't accept unicode in Python < 3.3
  381. # so we need to convert it to a byte string
  382. auth = base64.b64decode(auth[1].strip().encode('utf-8'))
  383. # b64decode returns a byte string
  384. auth = auth.decode('utf-8')
  385. auth = auth.split(":", 1)
  386. except (TypeError, binascii.Error, UnicodeDecodeError) as exc:
  387. self.debug("Couldn't get username: %s", exc)
  388. return user
  389. if len(auth) == 2:
  390. user = auth[0]
  391. return user