log.py 3.8 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109
  1. """Log utilities."""
  2. # -----------------------------------------------------------------------------
  3. # Copyright (c) Jupyter Development Team
  4. #
  5. # Distributed under the terms of the BSD License. The full license is in
  6. # the file LICENSE, distributed as part of this software.
  7. # -----------------------------------------------------------------------------
  8. import json
  9. from urllib.parse import urlparse, urlunparse
  10. from tornado.log import access_log
  11. from .auth import User
  12. from .prometheus.log_functions import prometheus_log_method
  13. # url params to be scrubbed if seen
  14. # any url param that *contains* one of these
  15. # will be scrubbed from logs
  16. _DEFAULT_SCRUB_PARAM_KEYS = {"token", "auth", "key", "code", "state", "xsrf"}
  17. def _scrub_uri(uri: str, extra_param_keys=None) -> str:
  18. """scrub auth info from uri"""
  19. scrub_param_keys = _DEFAULT_SCRUB_PARAM_KEYS.union(set(extra_param_keys or []))
  20. parsed = urlparse(uri)
  21. if parsed.query:
  22. # check for potentially sensitive url params
  23. # use manual list + split rather than parsing
  24. # to minimally perturb original
  25. parts = parsed.query.split("&")
  26. changed = False
  27. for i, s in enumerate(parts):
  28. key, sep, value = s.partition("=")
  29. for substring in scrub_param_keys:
  30. if substring in key:
  31. parts[i] = f"{key}{sep}[secret]"
  32. changed = True
  33. if changed:
  34. parsed = parsed._replace(query="&".join(parts))
  35. return urlunparse(parsed)
  36. return uri
  37. def log_request(handler, record_prometheus_metrics=True):
  38. """log a bit more information about each request than tornado's default
  39. - move static file get success to debug-level (reduces noise)
  40. - get proxied IP instead of proxy IP
  41. - log referer for redirect and failed requests
  42. - log user-agent for failed requests
  43. if record_prometheus_metrics is true, will record a histogram prometheus
  44. metric (http_request_duration_seconds) for each request handler
  45. """
  46. status = handler.get_status()
  47. request = handler.request
  48. try:
  49. logger = handler.log
  50. except AttributeError:
  51. logger = access_log
  52. extra_param_keys = handler.settings.get("extra_log_scrub_param_keys", [])
  53. if status < 300 or status == 304:
  54. # Successes (or 304 FOUND) are debug-level
  55. log_method = logger.debug
  56. elif status < 400:
  57. log_method = logger.info
  58. elif status < 500:
  59. log_method = logger.warning
  60. else:
  61. log_method = logger.error
  62. request_time = 1000.0 * handler.request.request_time()
  63. ns = {
  64. "status": status,
  65. "method": request.method,
  66. "ip": request.remote_ip,
  67. "uri": _scrub_uri(request.uri, extra_param_keys),
  68. "request_time": request_time,
  69. }
  70. # log username
  71. # make sure we don't break anything
  72. # in case mixins cause current_user to not be a User somehow
  73. try:
  74. user = handler.current_user
  75. except Exception:
  76. user = None
  77. username = (user.username if isinstance(user, User) else "unknown") if user else ""
  78. ns["username"] = username
  79. msg = "{status} {method} {uri} ({username}@{ip}) {request_time:.2f}ms"
  80. if status >= 400:
  81. # log bad referrers
  82. ns["referer"] = _scrub_uri(request.headers.get("Referer", "None"), extra_param_keys)
  83. msg = msg + " referer={referer}"
  84. if status >= 500 and status != 502:
  85. # Log a subset of the headers if it caused an error.
  86. headers = {}
  87. for header in ["Host", "Accept", "Referer", "User-Agent"]:
  88. if header in request.headers:
  89. headers[header] = request.headers[header]
  90. log_method(json.dumps(headers, indent=2))
  91. log_method(msg.format(**ns))
  92. if record_prometheus_metrics:
  93. prometheus_log_method(handler)