log.py 10 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323
  1. import logging
  2. import logging.config # needed when logging_config doesn't start with logging.config
  3. import warnings
  4. from copy import copy
  5. from django.conf import settings
  6. from django.core import mail
  7. from django.core.exceptions import ImproperlyConfigured
  8. from django.core.management.color import color_style
  9. from django.utils.deprecation import RemovedInDjango70Warning, django_file_prefixes
  10. from django.utils.module_loading import import_string
  11. request_logger = logging.getLogger("django.request")
  12. # Default logging for Django. This sends an email to the site admins on every
  13. # HTTP 500 error. Depending on DEBUG, all other log records are either sent to
  14. # the console (DEBUG=True) or discarded (DEBUG=False) by means of the
  15. # require_debug_true filter. This configuration is quoted in
  16. # docs/ref/logging.txt; please amend it there if edited here.
  17. DEFAULT_LOGGING = {
  18. "version": 1,
  19. "disable_existing_loggers": False,
  20. "filters": {
  21. "require_debug_false": {
  22. "()": "django.utils.log.RequireDebugFalse",
  23. },
  24. "require_debug_true": {
  25. "()": "django.utils.log.RequireDebugTrue",
  26. },
  27. },
  28. "formatters": {
  29. "django.server": {
  30. "()": "django.utils.log.ServerFormatter",
  31. "format": "[{server_time}] {message}",
  32. "style": "{",
  33. }
  34. },
  35. "handlers": {
  36. "console": {
  37. "level": "INFO",
  38. "filters": ["require_debug_true"],
  39. "class": "logging.StreamHandler",
  40. },
  41. "django.server": {
  42. "level": "INFO",
  43. "class": "logging.StreamHandler",
  44. "formatter": "django.server",
  45. },
  46. "mail_admins": {
  47. "level": "ERROR",
  48. "filters": ["require_debug_false"],
  49. "class": "django.utils.log.AdminEmailHandler",
  50. },
  51. },
  52. "loggers": {
  53. "django": {
  54. "handlers": ["console", "mail_admins"],
  55. "level": "INFO",
  56. },
  57. "django.server": {
  58. "handlers": ["django.server"],
  59. "level": "INFO",
  60. "propagate": False,
  61. },
  62. },
  63. }
  64. def configure_logging(logging_config, logging_settings):
  65. if logging_config:
  66. # First find the logging configuration function ...
  67. logging_config_func = import_string(logging_config)
  68. logging.config.dictConfig(DEFAULT_LOGGING)
  69. # ... then invoke it with the logging settings
  70. if logging_settings:
  71. logging_config_func(logging_settings)
  72. class AdminEmailHandler(logging.Handler):
  73. """An exception log handler that emails log entries to site admins.
  74. If the request is passed as the first argument to the log record,
  75. request data will be provided in the email report.
  76. """
  77. def __init__(
  78. self, include_html=False, email_backend=None, reporter_class=None, using=None
  79. ):
  80. super().__init__()
  81. # RemovedInDjango70Warning: email_backend arg and connection error.
  82. if email_backend:
  83. if using:
  84. raise ImproperlyConfigured(
  85. "The 'email_backend' argument is not compatible with 'using'."
  86. )
  87. if mail.mailers._is_configured:
  88. raise ImproperlyConfigured(
  89. "The 'email_backend' argument is not valid when "
  90. "settings.MAILERS is defined."
  91. )
  92. warnings.warn(
  93. "The 'email_backend' argument is deprecated. Use 'using' instead.",
  94. RemovedInDjango70Warning,
  95. skip_file_prefixes=django_file_prefixes(),
  96. )
  97. if hasattr(self, "connection"):
  98. raise AttributeError(
  99. "The undocumented AdminEmailHandler.connection() method is no longer "
  100. "used."
  101. )
  102. self.include_html = include_html
  103. self.email_backend = email_backend
  104. self.using = using
  105. self.reporter_class = import_string(
  106. reporter_class or settings.DEFAULT_EXCEPTION_REPORTER
  107. )
  108. def emit(self, record):
  109. # Early return when no email will be sent.
  110. if (
  111. not settings.ADMINS
  112. # Method not overridden.
  113. and self.send_mail.__func__ is AdminEmailHandler.send_mail
  114. ):
  115. return
  116. try:
  117. request = record.request
  118. subject = "%s (%s IP): %s" % (
  119. record.levelname,
  120. (
  121. "internal"
  122. if request.META.get("REMOTE_ADDR") in settings.INTERNAL_IPS
  123. else "EXTERNAL"
  124. ),
  125. record.getMessage(),
  126. )
  127. except Exception:
  128. subject = "%s: %s" % (record.levelname, record.getMessage())
  129. request = None
  130. subject = self.format_subject(subject)
  131. # Since we add a nicely formatted traceback on our own, create a copy
  132. # of the log record without the exception data.
  133. no_exc_record = copy(record)
  134. no_exc_record.exc_info = None
  135. no_exc_record.exc_text = None
  136. if record.exc_info:
  137. exc_info = record.exc_info
  138. else:
  139. exc_info = (None, record.getMessage(), None)
  140. reporter = self.reporter_class(request, is_email=True, *exc_info)
  141. message = "%s\n\n%s" % (
  142. self.format(no_exc_record),
  143. reporter.get_traceback_text(),
  144. )
  145. html_message = reporter.get_traceback_html() if self.include_html else None
  146. self.send_mail(subject, message, html_message=html_message)
  147. def send_mail(self, subject, message, *args, **kwargs):
  148. # RemovedInDjango70Warning.
  149. if not mail.mailers._is_configured:
  150. connection = mail.get_connection(
  151. backend=self.email_backend, fail_silently=True
  152. )
  153. mail.mail_admins(subject, message, *args, connection=connection, **kwargs)
  154. return
  155. try:
  156. mail.mail_admins(subject, message, *args, using=self.using, **kwargs)
  157. except mail.MailerDoesNotExist:
  158. pass
  159. def format_subject(self, subject):
  160. """
  161. Escape CR and LF characters.
  162. """
  163. return subject.replace("\n", "\\n").replace("\r", "\\r")
  164. class CallbackFilter(logging.Filter):
  165. """
  166. A logging filter that checks the return value of a given callable (which
  167. takes the record-to-be-logged as its only parameter) to decide whether to
  168. log a record.
  169. """
  170. def __init__(self, callback):
  171. self.callback = callback
  172. def filter(self, record):
  173. if self.callback(record):
  174. return 1
  175. return 0
  176. class RequireDebugFalse(logging.Filter):
  177. def filter(self, record):
  178. return not settings.DEBUG
  179. class RequireDebugTrue(logging.Filter):
  180. def filter(self, record):
  181. return settings.DEBUG
  182. class ServerFormatter(logging.Formatter):
  183. default_time_format = "%d/%b/%Y %H:%M:%S"
  184. def __init__(self, *args, **kwargs):
  185. self.style = color_style()
  186. super().__init__(*args, **kwargs)
  187. def format(self, record):
  188. msg = record.msg
  189. status_code = getattr(record, "status_code", None)
  190. if status_code:
  191. if 200 <= status_code < 300:
  192. # Put 2XX first, since it should be the common case
  193. msg = self.style.HTTP_SUCCESS(msg)
  194. elif 100 <= status_code < 200:
  195. msg = self.style.HTTP_INFO(msg)
  196. elif status_code == 304:
  197. msg = self.style.HTTP_NOT_MODIFIED(msg)
  198. elif 300 <= status_code < 400:
  199. msg = self.style.HTTP_REDIRECT(msg)
  200. elif status_code == 404:
  201. msg = self.style.HTTP_NOT_FOUND(msg)
  202. elif 400 <= status_code < 500:
  203. msg = self.style.HTTP_BAD_REQUEST(msg)
  204. else:
  205. # Any 5XX, or any other status code
  206. msg = self.style.HTTP_SERVER_ERROR(msg)
  207. if self.uses_server_time() and not hasattr(record, "server_time"):
  208. record.server_time = self.formatTime(record, self.datefmt)
  209. record.msg = msg
  210. return super().format(record)
  211. def uses_server_time(self):
  212. return self._fmt.find("{server_time}") >= 0
  213. def log_message(
  214. logger,
  215. message,
  216. *args,
  217. level=None,
  218. status_code=None,
  219. request=None,
  220. exception=None,
  221. **extra,
  222. ):
  223. """Log `message` using `logger` based on `status_code` and logger `level`.
  224. Pass `request`, `status_code` (if defined) and any provided `extra` as such
  225. to the logging method,
  226. Arguments from `args` will be escaped to avoid potential log injections.
  227. """
  228. extra = {"request": request, **extra}
  229. if status_code is not None:
  230. extra["status_code"] = status_code
  231. if level is None:
  232. if status_code >= 500:
  233. level = "error"
  234. elif status_code >= 400:
  235. level = "warning"
  236. escaped_args = tuple(
  237. a.encode("unicode_escape").decode("ascii") if isinstance(a, str) else a
  238. for a in args
  239. )
  240. getattr(logger, level or "info")(
  241. message,
  242. *escaped_args,
  243. extra=extra,
  244. exc_info=exception,
  245. )
  246. def log_response(
  247. message,
  248. *args,
  249. response=None,
  250. request=None,
  251. logger=request_logger,
  252. level=None,
  253. exception=None,
  254. ):
  255. """
  256. Log errors based on HttpResponse status.
  257. Log 5xx responses as errors and 4xx responses as warnings (unless a level
  258. is given as a keyword argument). The HttpResponse status_code and the
  259. request are passed to the logger's extra parameter.
  260. """
  261. # Check if the response has already been logged. Multiple requests to log
  262. # the same response can be received in some cases, e.g., when the
  263. # response is the result of an exception and is logged when the exception
  264. # is caught, to record the exception.
  265. if getattr(response, "_has_been_logged", False):
  266. return
  267. log_message(
  268. logger,
  269. message,
  270. *args,
  271. level=level,
  272. status_code=response.status_code,
  273. request=request,
  274. exception=exception,
  275. )
  276. response._has_been_logged = True