5.14_all_logging.patch 10 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239
  1. # Licensed to Cloudera, Inc. under one
  2. # or more contributor license agreements. See the NOTICE file
  3. # distributed with this work for additional information
  4. # regarding copyright ownership. Cloudera, Inc. licenses this file
  5. # to you under the Apache License, Version 2.0 (the
  6. # "License"); you may not use this file except in compliance
  7. # with the License. You may obtain a copy of the License at
  8. #
  9. # http://www.apache.org/licenses/LICENSE-2.0
  10. #
  11. # Unless required by applicable law or agreed to in writing, software
  12. # distributed under the License is distributed on an "AS IS" BASIS,
  13. # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  14. # See the License for the specific language governing permissions and
  15. # limitations under the License.
  16. diff --git a/apps/filebrowser/src/filebrowser/settings.py b/apps/filebrowser/src/filebrowser/settings.py
  17. index cb7a8c7c3d..9a783965a8 100644
  18. --- a/apps/filebrowser/src/filebrowser/settings.py
  19. +++ b/apps/filebrowser/src/filebrowser/settings.py
  20. @@ -22,7 +22,7 @@ ICON = "filebrowser/art/icon_filebrowser_48.png"
  21. MENU_INDEX = 20
  22. from aws.s3.s3fs import PERMISSION_ACTION_S3
  23. -from azure.adls.webhdfs import PERMISSION_ACTION_ADLS
  24. +PERMISSION_ACTION_ADLS = "adls_access"
  25. PERMISSION_ACTIONS = (
  26. diff --git a/desktop/core/src/desktop/conf.py b/desktop/core/src/desktop/conf.py
  27. index 429ee983a5..7d20ad4f25 100644
  28. --- a/desktop/core/src/desktop/conf.py
  29. +++ b/desktop/core/src/desktop/conf.py
  30. @@ -379,6 +379,18 @@ COLLECT_USAGE = Config(
  31. type=coerce_bool,
  32. default=True)
  33. +REST_RESPONSE_SIZE = Config(
  34. + key="rest_response_size",
  35. + help=_("Number of characters the rest api reponse calls to dump to the logs when debug is enabled."),
  36. + type=int,
  37. + default=1000)
  38. +
  39. +THRIFT_RESPONSE_SIZE = Config(
  40. + key="thrift_response_size",
  41. + help=_("Number of characters the thrift api reponse calls to dump to the logs when debug is enabled."),
  42. + type=int,
  43. + default=1000)
  44. +
  45. LEAFLET_TILE_LAYER = Config(
  46. key="leaflet_tile_layer",
  47. help=_("Tile layer server URL for the Leaflet map charts. Read more on http://leafletjs.com/reference.html#tilelayer. Make sure you add the tile domain to the img-src section of the 'secure_content_security_policy' configuration parameter as well."),
  48. @@ -1314,6 +1326,17 @@ MEMORY_PROFILER = Config(
  49. default=False)
  50. +def get_instrumentation_default():
  51. + """If django_debug_mode is True, this is automatically enabled"""
  52. + return DJANGO_DEBUG_MODE.get()
  53. +
  54. +INSTRUMENTATION = Config(
  55. + key='instrumentation',
  56. + help=_('Enable or disable instrumentation. If django_debug_mode is True, this is automatically enabled.'),
  57. + type=coerce_bool,
  58. + dynamic_default=get_instrumentation_default)
  59. +
  60. +
  61. AUDIT_EVENT_LOG_DIR = Config(
  62. key="audit_event_log_dir",
  63. help=_("The directory where to store the auditing logs. Auditing is disable if the value is empty."),
  64. diff --git a/desktop/core/src/desktop/lib/rest/resource.py b/desktop/core/src/desktop/lib/rest/resource.py
  65. index aa2e01a993..20150f9a09 100644
  66. --- a/desktop/core/src/desktop/lib/rest/resource.py
  67. +++ b/desktop/core/src/desktop/lib/rest/resource.py
  68. @@ -18,8 +18,12 @@ import logging
  69. import posixpath
  70. import time
  71. +from django.utils.encoding import iri_to_uri, smart_str
  72. +from django.utils.http import urlencode
  73. +
  74. from desktop.lib.i18n import smart_unicode
  75. +from desktop import conf
  76. LOG = logging.getLogger(__name__)
  77. @@ -82,15 +86,24 @@ class Resource(object):
  78. urlencode=self._urlencode,
  79. clear_cookies=clear_cookies)
  80. - if log_response and self._client.logger.isEnabledFor(logging.DEBUG):
  81. - self._client.logger.debug(
  82. - "%s %s Got response%s: %s%s" % (
  83. - method,
  84. - smart_unicode(path, errors='ignore'),
  85. - ' in %dms' % ((time.time() - start_time) * 1000),
  86. - smart_unicode(resp.content[:1000], errors='replace'),
  87. - len(resp.content) > 1000 and "..." or "")
  88. + if self._client.logger.isEnabledFor(logging.DEBUG):
  89. + log_length = conf.REST_RESPONSE_SIZE.get() != -1 and conf.REST_RESPONSE_SIZE.get() # We want to output duration without content
  90. + duration = time.time() - start_time
  91. + message = '%s %s %s%s%s %s%s returned in %dms %s %s %s%s' % (
  92. + method,
  93. + type(self._client._session.auth) if self._client._session and self._client._session.auth else None,
  94. + self._client._base_url,
  95. + smart_str(path),
  96. + iri_to_uri('?' + urlencode(params)) if params else '',
  97. + smart_unicode(data, errors='replace')[:log_length] if data else "",
  98. + log_length and len(data) > log_length and "..." or "" if data else "",
  99. + (duration * 1000),
  100. + resp.status_code if resp else 0,
  101. + len(resp.content) if resp else 0,
  102. + smart_unicode(resp.content[:log_length], errors='replace') if resp else "",
  103. + log_length and len(resp.content) > log_length and "..." or "" if resp else ""
  104. )
  105. + self._client.logger.debug("%s" % message)
  106. return self._format_response(resp)
  107. diff --git a/desktop/core/src/desktop/lib/thrift_util.py b/desktop/core/src/desktop/lib/thrift_util.py
  108. index b36a99d000..a1c40b5092 100644
  109. --- a/desktop/core/src/desktop/lib/thrift_util.py
  110. +++ b/desktop/core/src/desktop/lib/thrift_util.py
  111. @@ -36,6 +36,7 @@ from thrift.protocol.TMultiplexedProtocol import TMultiplexedProtocol
  112. from django.conf import settings
  113. from django.utils.translation import ugettext as _
  114. from desktop.conf import SASL_MAX_BUFFER, CHERRYPY_SERVER_THREADS
  115. +from desktop import conf
  116. from desktop.lib.python_util import create_synchronous_io_multiplexer
  117. from desktop.lib.thrift_.http_client import THttpClient
  118. @@ -440,7 +441,7 @@ class SuperClient(object):
  119. log_msg = _unpack_guid_secret_in_handle(repr(ret))
  120. # Truncate log message, increase output in DEBUG mode
  121. - log_limit = 2000 if settings.DEBUG else 1000
  122. + log_limit = conf.THRIFT_RESPONSE_SIZE.get() if settings.DEBUG else 1000
  123. log_msg = log_msg[:log_limit] + (log_msg[log_limit:] and '...')
  124. duration = time.time() - st
  125. diff --git a/desktop/core/src/desktop/log/access.py b/desktop/core/src/desktop/log/access.py
  126. index 679f9d1035..ad3c48805f 100644
  127. --- a/desktop/core/src/desktop/log/access.py
  128. +++ b/desktop/core/src/desktop/log/access.py
  129. @@ -22,6 +22,8 @@ This assumes a single-threaded server.
  130. import logging
  131. import re
  132. +import resource
  133. +import sys
  134. import threading
  135. import time
  136. @@ -81,15 +83,36 @@ class AccessInfo(dict):
  137. self['agent'] = request.META.get('HTTP_USER_AGENT', '-')
  138. self['time'] = time.time()
  139. self['duration'] = None
  140. + self['memory'] = None
  141. +
  142. + def memory_usage_resource(self):
  143. + """
  144. + This is a lightweight way to get the total peak memory as
  145. + doing the diffing before/after request with guppy was too inconsistent and memory intensive.
  146. + """
  147. + rusage_denom = 1024
  148. + if sys.platform == 'darwin':
  149. + rusage_denom = rusage_denom * 1024
  150. + # get peak memory usage, bytes on OSX, Kilobytes on Linux
  151. + return resource.getrusage(resource.RUSAGE_SELF).ru_maxrss / rusage_denom
  152. def log(self, level, msg=None, start_time=None):
  153. - self['duration'] = ' returned in %dms' % ((time.time() - start_time) * 1000) if start_time is not None else ''
  154. + is_instrumentation = desktop.conf.INSTRUMENTATION.get()
  155. + self['duration'] = ' returned in %dms' % ((time.time() - start_time) * 1000) if start_time is not None and is_instrumentation else ''
  156. + self['memory'] = ' (mem: %dmb)' % self.memory_usage_resource() if is_instrumentation else ''
  157. if msg is not None:
  158. self['msg'] = msg
  159. - ACCESS_LOG.log(level, '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s"%(duration)s -- %(msg)s' % self)
  160. + ACCESS_LOG.log(level, '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s"%(duration)s%(memory)s-- %(msg)s' % self)
  161. else:
  162. - ACCESS_LOG.log(level, '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s"%(duration)s' % self)
  163. + ACCESS_LOG.log(level, '%(remote_ip)s %(username)s - "%(method)s %(path)s %(proto)s"%(duration)s%(memory)s' % self)
  164. +
  165. + if is_instrumentation:
  166. + import gc
  167. + gc.collect()
  168. + for o in gc.garbage:
  169. + for r in gc.get_referrers(o):
  170. + ACCESS_LOG.log(level, 'ref for %r: %r' % (o, r))
  171. def add_to_access_history(self, app):
  172. """Record this user access to the recent access map"""
  173. diff --git a/desktop/core/src/desktop/middleware.py b/desktop/core/src/desktop/middleware.py
  174. index 0feaf5b545..b53df44ad2 100644
  175. --- a/desktop/core/src/desktop/middleware.py
  176. +++ b/desktop/core/src/desktop/middleware.py
  177. @@ -317,7 +317,8 @@ class LoginAndPermissionMiddleware(object):
  178. return PopupException(
  179. _("You do not have permission to access the %(app_name)s application.") % {'app_name': app_accessed.capitalize()}, error_code=401).response(request)
  180. else:
  181. - log_page_hit(request, view_func, level=access_log_level)
  182. + if not hasattr(request, 'view_func'):
  183. + log_page_hit(request, view_func, level=access_log_level)
  184. return None
  185. logging.info("Redirecting to login page: %s", request.get_full_path())
  186. @@ -334,7 +335,7 @@ class LoginAndPermissionMiddleware(object):
  187. def process_response(self, request, response):
  188. if hasattr(request, 'ts') and hasattr(request, 'view_func'):
  189. - log_page_hit(request, request.view_func, level=logging.DEBUG, start_time=request.ts)
  190. + log_page_hit(request, request.view_func, level=logging.INFO, start_time=request.ts)
  191. return response
  192. diff --git a/desktop/core/src/desktop/settings.py b/desktop/core/src/desktop/settings.py
  193. index a77673739d..7f83f68cc6 100644
  194. --- a/desktop/core/src/desktop/settings.py
  195. +++ b/desktop/core/src/desktop/settings.py
  196. @@ -20,6 +20,7 @@
  197. # Local customizations are done by symlinking a file
  198. # as local_settings.py.
  199. +import gc
  200. import logging
  201. import os
  202. import pkg_resources
  203. @@ -506,6 +507,9 @@ if desktop.conf.MEMORY_PROFILER.get():
  204. MEMORY_PROFILER = hpy()
  205. MEMORY_PROFILER.setrelheap()
  206. +# Instrumentation
  207. +if desktop.conf.INSTRUMENTATION.get():
  208. + gc.set_debug(gc.DEBUG_UNCOLLECTABLE | gc.DEBUG_OBJECTS)
  209. if not desktop.conf.DATABASE_LOGGING.get():
  210. def disable_database_logging():