class BaseWatchdogMiddleware(object):
def __init__(self):
self._init_timer()
def _init_timer(self):
self.interval = int(self._get_config().get('DOGSLOW_TIMER', 25))
self.timer = Timer()
self.timer.setDaemon(True)
self.timer.start()
def _get_config():
raise NotImplementedError()
def _log_to_custom_logger(self, logger_name, frame, output, req_string,
request):
log_level = self._safe_get_setting('DOGSLOW_LOG_LEVEL', 'WARNING')
log_to_sentry = self._safe_get_setting('DOGSLOW_LOG_TO_SENTRY', False)
log_level = logging.getLevelName(log_level)
logger = logging.getLogger(logger_name)
# we're passing the request object along
# with the log call in case we're being used with Sentry:
extra = {'request': request}
# if this is not going to Sentry, then we'll use the original msg
if not log_to_sentry:
msg = 'Slow Request Watchdog: %s, %s - %s' % (
request.path,
# resolve(request.META.get('PATH_INFO')).url_name,
req_string.encode('utf-8'),
output,
)
else:
# if it is going to Sentry, we instead want to format differently and send more in extra
msg, extra = self._get_message_for_sentry(frame, request, extra)
logger.log(log_level, msg, extra=extra)
def _safe_get_setting(self, name, default_value):
raise NotImplementedError()
def _get_message_for_sentry(self, frame, request, extra):
msg = 'Slow Request Watchdog: %s' % self._get_path(request)
module = inspect.getmodule(frame.f_code)
# This is a bizarre construct, `module` in `function`, but
# this is how all stack traces are formatted.
extra['culprit'] = '%s in %s' % (module.__name__, frame.f_code.co_name)
# We've got to simplify the stack, because raven only accepts
# a list of 2-tuples of (frame, lineno).
# This is a list comprehension split over a few lines.
extra['stack'] = [(frame, lineno)
for frame, filename, lineno, function, code_context,
index in inspect.getouterframes(frame)]
# Lastly, we have to reverse the order of the frames
# because getouterframes() gives it to you backwards.
extra['stack'].reverse()
return msg, extra
def _get_path(self, requst):
raise NotImplementedError()
def _compose_output(self, frame, req_string, started, thread_id):
output = 'Undead request intercepted at: %s\n\n' \
'%s\n' \
'Hostname: %s\n' \
'Thread ID: %d\n' \
'Process ID: %d\n' \
'Started: %s\n\n' % \
(dt.datetime.utcnow().strftime("%d-%m-%Y %H:%M:%S UTC"),
req_string,
socket.gethostname(),
thread_id,
os.getpid(),
started.strftime("%d-%m-%Y %H:%M:%S UTC"),)
output += stack(frame, with_locals=False)
output += '\n\n'
stack_vars = self._safe_get_setting('DOGSLOW_STACK_VARS', False)
if not stack_vars:
# no local stack variables
output += ('This report does not contain the local stack '
'variables.\n'
'To enable this (very verbose) information, add '
'this to your application settings:\n'
' DOGSLOW_STACK_VARS = True\n')
else:
output += 'Full backtrace with local variables:'
output += '\n\n'
output += stack(frame, with_locals=True)
return output.encode('utf-8')
def peek(self, request, thread_id, started):
try:
frame = sys._current_frames()[thread_id]
req_string = '%s %s://%s%s' % (
request.method,
'http',
request.headers.get('HTTP_HOST'),
request.path,
)
query_string = self._get_query_string(request)
if query_string:
req_string = '%s?%s' % (req_string, query_string)
output = self._compose_output(frame, req_string, started,
thread_id)
# dump to file:
self._dump_to_file_if_needed(output)
# and email?
self._send_email_if_needed(output, req_string)
# and a custom logger:
logger_name = self._safe_get_setting('DOGSLOW_LOGGER', None)
if logger_name is not None:
self._log_to_custom_logger(logger_name, frame, output,
req_string, request)
except Exception:
logging.exception('Dogslow failed')
def _get_query_string(self, request):
raise NotImplementedError()
def _dump_to_file_if_needed(self, output):
log_to_file = self._safe_get_setting('DOGSLOW_LOG_TO_FILE', True)
if log_to_file:
self._log_to_file(output)
def _log_to_file(self, output):
fd, fn = tempfile.mkstemp(
prefix='slow_request_',
suffix='.log',
dir=self._safe_get_setting('DOGSLOW_OUTPUT',
tempfile.gettempdir()),
)
try:
os.write(fd, output)
finally:
os.close(fd)
def _send_email_if_needed(self, output, req_string):
email_to = self._safe_get_setting('DOGSLOW_EMAIL_TO', None)
email_from = self._safe_get_setting('DOGSLOW_EMAIL_FROM', None)
if email_to is not None and email_from is not None:
BaseWatchdogMiddleware._log_to_email(email_to, email_from, output,
req_string)
@staticmethod
def _log_to_email(email_to, email_from, output, req_string):
raise NotImplementedError()
def _is_exempt(self):
raise NotImplementedError()
def process_request(self):
raise NotImplementedError()
def _cancel(self, exc=None):
raise NotImplementedError()
class WatchdogMiddleware(object):
def __init__(self):
if not getattr(settings, 'DOGSLOW', True):
raise MiddlewareNotUsed
else:
self.interval = int(getattr(settings, 'DOGSLOW_TIMER', 25))
self.timer = Timer()
self.timer.setDaemon(True)
self.timer.start()
@staticmethod
def _log_to_custom_logger(logger_name, frame, output, req_string, request):
log_level = getattr(settings, 'DOGSLOW_LOG_LEVEL', 'WARNING')
log_to_sentry = getattr(settings, 'DOGSLOW_LOG_TO_SENTRY', False)
log_level = logging.getLevelName(log_level)
logger = logging.getLogger(logger_name)
# we're passing the Django request object along
# with the log call in case we're being used with
# Sentry:
extra = {'request': request}
# if this is not going to Sentry,
# then we'll use the original msg
if not log_to_sentry:
msg = 'Slow Request Watchdog: %s, %s - %s' % (
resolve(request.META.get('PATH_INFO')).url_name,
req_string.encode('utf-8'),
output
)
# if it is going to Sentry,
# we instead want to format differently and send more in extra
else:
msg = 'Slow Request Watchdog: %s' % request.META.get(
'PATH_INFO')
module = inspect.getmodule(frame.f_code)
# This is a bizarre construct, `module` in `function`, but
# this is how all stack traces are formatted.
extra['culprit'] = '%s in %s' % (module.__name__,
frame.f_code.co_name)
# We've got to simplify the stack, because raven only accepts
# a list of 2-tuples of (frame, lineno).
# This is a list comprehension split over a few lines.
extra['stack'] = [
(frame, lineno)
for frame, filename, lineno, function, code_context, index
in inspect.getouterframes(frame)
]
# Lastly, we have to reverse the order of the frames
# because getouterframes() gives it to you backwards.
extra['stack'].reverse()
logger.log(log_level, msg, extra=extra)
@staticmethod
def _log_to_email(email_to, email_from, output, req_string):
em = EmailMessage('Slow Request Watchdog: %s' %
req_string.encode('utf-8'),
output,
email_from,
(email_to,))
em.send(fail_silently=True)
@staticmethod
def _log_to_file(output):
fd, fn = tempfile.mkstemp(prefix='slow_request_', suffix='.log',
dir=getattr(settings, 'DOGSLOW_OUTPUT',
tempfile.gettempdir()))
try:
os.write(fd, output)
finally:
os.close(fd)
@staticmethod
def _compose_output(frame, req_string, started, thread_id):
output = 'Undead request intercepted at: %s\n\n' \
'%s\n' \
'Hostname: %s\n' \
'Thread ID: %d\n' \
'Process ID: %d\n' \
'Started: %s\n\n' % \
(dt.datetime.utcnow().strftime("%d-%m-%Y %H:%M:%S UTC"),
req_string,
socket.gethostname(),
thread_id,
os.getpid(),
started.strftime("%d-%m-%Y %H:%M:%S UTC"),)
output += stack(frame, with_locals=False)
output += '\n\n'
stack_vars = getattr(settings, 'DOGSLOW_STACK_VARS', False)
if not stack_vars:
# no local stack variables
output += ('This report does not contain the local stack '
'variables.\n'
'To enable this (very verbose) information, add '
'this to your Django settings:\n'
' DOGSLOW_STACK_VARS = True\n')
else:
output += 'Full backtrace with local variables:'
output += '\n\n'
output += stack(frame, with_locals=True)
return output.encode('utf-8')
@staticmethod
def peek(request, thread_id, started):
try:
frame = sys._current_frames()[thread_id]
req_string = '%s %s://%s%s' % (
request.META.get('REQUEST_METHOD'),
request.META.get('wsgi.url_scheme', 'http'),
request.META.get('HTTP_HOST'),
request.META.get('PATH_INFO'),
)
if request.META.get('QUERY_STRING', ''):
req_string += ('?' + request.META.get('QUERY_STRING'))
output = WatchdogMiddleware._compose_output(
frame, req_string, started, thread_id)
# dump to file:
log_to_file = getattr(settings, 'DOGSLOW_LOG_TO_FILE', True)
if log_to_file:
WatchdogMiddleware._log_to_file(output)
# and email?
email_to = getattr(settings, 'DOGSLOW_EMAIL_TO', None)
email_from = getattr(settings, 'DOGSLOW_EMAIL_FROM', None)
if email_to is not None and email_from is not None:
WatchdogMiddleware._log_to_email(email_to, email_from,
output, req_string)
# and a custom logger:
logger_name = getattr(settings, 'DOGSLOW_LOGGER', None)
if logger_name is not None:
WatchdogMiddleware._log_to_custom_logger(
logger_name, frame, output, req_string, request)
except Exception:
logging.exception('Dogslow failed')
def _is_exempt(self, request):
"""Returns True if this request's URL resolves to a url pattern whose
name is listed in settings.DOGSLOW_IGNORE_URLS.
"""
exemptions = getattr(settings, 'DOGSLOW_IGNORE_URLS', ())
if exemptions:
try:
match = resolve(request.META.get('PATH_INFO'))
except Resolver404:
return False
return match and (match.url_name in exemptions)
else:
return False
def process_request(self, request):
if not self._is_exempt(request):
request.dogslow = self.timer.run_later(
WatchdogMiddleware.peek,
self.interval,
request,
thread.get_ident(),
dt.datetime.utcnow())
def _cancel(self, request):
try:
if safehasattr(request, 'dogslow'):
self.timer.cancel(request.dogslow)
del request.dogslow
except Exception:
logging.exception('Failed to cancel Dogslow timer')
def process_response(self, request, response):
self._cancel(request)
return response
def process_exception(self, request, exception):
self._cancel(request)
class WatchdogMiddleware(object):
def __init__(self):
if not getattr(settings, 'DOGSLOW', True):
raise MiddlewareNotUsed
else:
self.interval = int(getattr(settings, 'DOGSLOW_TIMER', 25))
self.timer = Timer()
self.timer.setDaemon(True)
self.timer.start()
@staticmethod
def peek(request, thread_id, started):
try:
frame = sys._current_frames()[thread_id]
req_string = '%s %s://%s%s' % (
request.META.get('REQUEST_METHOD'),
request.META.get('wsgi.url_scheme', 'http'),
request.META.get('HTTP_HOST'),
request.META.get('PATH_INFO'),
)
if request.META.get('QUERY_STRING', ''):
req_string += ('?' + request.META.get('QUERY_STRING'))
output = 'Undead request intercepted at: %s\n\n' \
'%s\n' \
'Thread ID: %d\n' \
'Process ID: %d\n' \
'Started: %s\n\n' % \
(dt.datetime.utcnow().strftime("%d-%m-%Y %H:%M:%S UTC"),
req_string,
thread_id,
os.getpid(),
started.strftime("%d-%m-%Y %H:%M:%S UTC"),)
output += stack(frame, with_locals=False)
output += '\n\n'
if (hasattr(settings, 'DOGSLOW_STACK_VARS')
and not bool(settings.DOGSLOW_STACK_VARS)):
# no local stack variables
output += ('This report does not contain the local stack '
'variables.\n'
'To enable this (very verbose) information, add '
'this to your Django settings:\n'
' DOGSLOW_STACK_VARS=True\n')
else:
output += 'Full backtrace with local variables:'
output += '\n\n'
output += stack(frame, with_locals=True)
output = output.encode('utf-8')
# dump to file:
fd, fn = tempfile.mkstemp(prefix='slow_request_', suffix='.log',
dir=getattr(settings, 'DOGSLOW_OUTPUT',
tempfile.gettempdir()))
try:
os.write(fd, output)
finally:
os.close(fd)
# and email?
if hasattr(settings, 'DOGSLOW_EMAIL_TO')\
and hasattr(settings, 'DOGSLOW_EMAIL_FROM'):
em = EmailMessage('Slow Request Watchdog: %s' %
req_string.encode('utf-8'),
output,
getattr(settings, 'DOGSLOW_EMAIL_FROM'),
(getattr(settings, 'DOGSLOW_EMAIL_TO'),))
em.send(fail_silently=True)
# and a custom logger:
if hasattr(settings, 'DOGSLOW_LOGGER'):
logger = logging.getLogger(getattr(settings, 'DOGSLOW_LOGGER'))
logger.warn('Slow Request Watchdog: %s, %%s - %%s' %
resolve(request.META.get('PATH_INFO')).url_name,
req_string.encode('utf-8'), output)
except Exception:
logging.exception('Request watchdog failed')
def _is_exempt(self, request):
"""Returns True if this request's URL resolves to a url pattern whose
name is listed in settings.DOGSLOW_IGNORE_URLS.
"""
match = resolve(request.META.get('PATH_INFO'))
return match and (match.url_name in
getattr(settings, 'DOGSLOW_IGNORE_URLS', ()))
def process_request(self, request):
if not self._is_exempt(request):
request.dogslow = self.timer.run_later(
WatchdogMiddleware.peek,
self.interval,
request,
thread.get_ident(),
dt.datetime.utcnow())
def _cancel(self, request):
try:
if hasattr(request, 'dogslow'):
self.timer.cancel(request.dogslow)
del request.dogslow
except:
logging.exception('Failed to cancel request watchdog')
def process_response(self, request, response):
self._cancel(request)
return response
def process_exception(self, request, exception):
self._cancel(request)
class WatchdogMiddleware(object):
def __init__(self):
if not getattr(settings, 'DOGSLOW', True):
raise MiddlewareNotUsed
else:
self.interval = int(getattr(settings, 'DOGSLOW_TIMER', 25))
self.timer = Timer()
self.timer.setDaemon(True)
self.timer.start()
@staticmethod
def _log_to_custom_logger(logger_name, frame, output, req_string, request):
log_level = getattr(settings, 'DOGSLOW_LOG_LEVEL', 'WARNING')
log_to_sentry = getattr(settings, 'DOGSLOW_LOG_TO_SENTRY', False)
log_level = logging.getLevelName(log_level)
logger = logging.getLogger(logger_name)
# we're passing the Django request object along
# with the log call in case we're being used with
# Sentry:
extra = {'request': request}
# if this is not going to Sentry,
# then we'll use the original msg
if not log_to_sentry:
msg = 'Slow Request Watchdog: %s - %s' % (
req_string,
output
)
# if it is going to Sentry,
# we instead want to format differently and send more in extra
else:
msg = 'Slow Request Watchdog: %s' % request.META.get(
'PATH_INFO')
module = inspect.getmodule(frame.f_code)
# This is a bizarre construct, `module` in `function`, but
# this is how all stack traces are formatted.
extra['culprit'] = '%s in %s' % (
getattr(module, '__name__', '(unknown module)'),
frame.f_code.co_name)
# We've got to simplify the stack, because raven only accepts
# a list of 2-tuples of (frame, lineno).
# This is a list comprehension split over a few lines.
extra['stack'] = [
(frame, lineno)
for frame, filename, lineno, function, code_context, index
in inspect.getouterframes(frame)
]
# Lastly, we have to reverse the order of the frames
# because getouterframes() gives it to you backwards.
extra['stack'].reverse()
logger.log(log_level, msg, extra=extra)
@staticmethod
def _log_to_email(email_to, email_from, output, req_string):
if hasattr(email_to, 'split'):
# Looks like a string, but EmailMessage expects a sequence.
email_to = (email_to,)
em = EmailMessage('Slow Request Watchdog: %s' %
req_string,
output.decode('utf-8', 'replace'),
email_from,
email_to)
em.send(fail_silently=True)
@staticmethod
def _log_to_file(output):
fd, fn = tempfile.mkstemp(prefix='slow_request_', suffix='.log',
dir=getattr(settings, 'DOGSLOW_OUTPUT',
tempfile.gettempdir()))
try:
os.write(fd, output)
finally:
os.close(fd)
@staticmethod
def _compose_output(frame, req_string, started, thread_id):
output = 'Undead request intercepted at: %s\n\n' \
'%s\n' \
'Hostname: %s\n' \
'Thread ID: %d\n' \
'Process ID: %d\n' \
'Started: %s\n\n' % \
(dt.datetime.utcnow().strftime("%d-%m-%Y %H:%M:%S UTC"),
req_string,
socket.gethostname(),
thread_id,
os.getpid(),
started.strftime("%d-%m-%Y %H:%M:%S UTC"),)
output += stack(frame, with_locals=False)
output += '\n\n'
stack_vars = getattr(settings, 'DOGSLOW_STACK_VARS', False)
if not stack_vars:
# no local stack variables
output += ('This report does not contain the local stack '
'variables.\n'
'To enable this (very verbose) information, add '
'this to your Django settings:\n'
' DOGSLOW_STACK_VARS = True\n')
else:
output += 'Full backtrace with local variables:'
output += '\n\n'
output += stack(frame, with_locals=True)
return output
@staticmethod
def peek(request, thread_id, started):
try:
frame = sys._current_frames()[thread_id]
req_string = '%s %s' % (
request.META.get('REQUEST_METHOD'),
request.META.get('PATH_INFO'),
)
if request.META.get('QUERY_STRING', ''):
req_string += ('?' + request.META.get('QUERY_STRING'))
output = WatchdogMiddleware._compose_output(
frame, req_string, started, thread_id)
# dump to file:
log_to_file = getattr(settings, 'DOGSLOW_LOG_TO_FILE', True)
if log_to_file:
WatchdogMiddleware._log_to_file(output)
# and email?
email_to = getattr(settings, 'DOGSLOW_EMAIL_TO', None)
email_from = getattr(settings, 'DOGSLOW_EMAIL_FROM', None)
if email_to is not None and email_from is not None:
WatchdogMiddleware._log_to_email(email_to, email_from,
output, req_string)
# and a custom logger:
logger_name = getattr(settings, 'DOGSLOW_LOGGER', None)
if logger_name is not None:
WatchdogMiddleware._log_to_custom_logger(
logger_name, frame, output, req_string, request)
except Exception:
logging.exception('Dogslow failed')
def _is_exempt(self, request):
"""Returns True if this request's URL resolves to a url pattern whose
name is listed in settings.DOGSLOW_IGNORE_URLS.
"""
exemptions = getattr(settings, 'DOGSLOW_IGNORE_URLS', ())
if exemptions:
try:
match = resolve(request.META.get('PATH_INFO'))
except Resolver404:
return False
return match and (match.url_name in exemptions)
else:
return False
def process_request(self, request):
if not self._is_exempt(request):
request.dogslow = self.timer.run_later(
WatchdogMiddleware.peek,
self.interval,
request,
thread.get_ident(),
dt.datetime.utcnow())
def _cancel(self, request):
try:
if safehasattr(request, 'dogslow'):
self.timer.cancel(request.dogslow)
del request.dogslow
except Exception:
logging.exception('Failed to cancel Dogslow timer')
def process_response(self, request, response):
self._cancel(request)
return response
def process_exception(self, request, exception):
self._cancel(request)
class WatchdogMiddleware(object):
def __init__(self):
if not getattr(settings, "DOGSLOW", True):
raise MiddlewareNotUsed
else:
# allow floating points to cater for millisecond precision
self.interval = float(getattr(settings, "DOGSLOW_TIMER", 25))
self.timer = Timer()
self.timer.setDaemon(True)
self.timer.start()
@staticmethod
def peek(request, thread_id, started):
try:
frame = sys._current_frames()[thread_id]
req_string = "%s %s://%s%s" % (
request.META.get("REQUEST_METHOD"),
request.META.get("wsgi.url_scheme", "http"),
request.META.get("HTTP_HOST"),
request.META.get("PATH_INFO"),
)
if request.META.get("QUERY_STRING", ""):
req_string += "?" + request.META.get("QUERY_STRING")
output = (
"Undead request intercepted at: %s\n\n"
"%s\n"
"Hostname: %s\n"
"Thread ID: %d\n"
"Process ID: %d\n"
"Started: %s\n\n"
% (
dt.datetime.utcnow().strftime("%d-%m-%Y %H:%M:%S UTC"),
req_string,
socket.gethostname(),
thread_id,
os.getpid(),
started.strftime("%d-%m-%Y %H:%M:%S UTC"),
)
)
output += stack(frame, with_locals=False)
output += "\n\n"
stack_vars = getattr(settings, "DOGSLOW_STACK_VARS", False)
if not stack_vars:
# no local stack variables
output += (
"This report does not contain the local stack "
"variables.\n"
"To enable this (very verbose) information, add "
"this to your Django settings:\n"
" DOGSLOW_STACK_VARS=True\n"
)
else:
output += "Full backtrace with local variables:"
output += "\n\n"
output += stack(frame, with_locals=True)
output = output.encode("utf-8")
# Default to None to allow local logs to be omitted
local_path = getattr(settings, "DOGSLOW_OUTPUT", None)
if local_path is not None:
# dump to file:
fd = tempfile.mkstemp(prefix="slow_request_", suffix=".log", dir=local_path)
try:
os.write(fd, output)
finally:
os.close(fd)
# and email?
email_to = getattr(settings, "DOGSLOW_EMAIL_TO", None)
email_from = getattr(settings, "DOGSLOW_EMAIL_FROM", None)
if email_to is not None and email_from is not None:
em = EmailMessage(
"Slow Request Watchdog: %s" % req_string.encode("utf-8"), output, email_from, (email_to,)
)
em.send(fail_silently=True)
# and a custom logger:
logger_name = getattr(settings, "DOGSLOW_LOGGER", None)
log_level = getattr(settings, "DOGSLOW_LOG_LEVEL", "WARNING")
if logger_name is not None:
log_level = logging.getLevelName(log_level)
logger = logging.getLogger(logger_name)
logger.log(
log_level,
"Slow Request Watchdog: %s, %s - %s",
resolve(request.META.get("PATH_INFO")).url_name,
req_string.encode("utf-8"),
output,
# we're passing the Django request object along
# with the log call in case we're being used with
# Sentry:
extra={"request": request},
)
except Exception:
logging.exception("Request watchdog failed")
def _is_exempt(self, request):
"""Returns True if this request's URL resolves to a url pattern whose
name is listed in settings.DOGSLOW_IGNORE_URLS.
"""
try:
match = resolve(request.META.get("PATH_INFO"))
except Resolver404:
return False
return match and (match.url_name in getattr(settings, "DOGSLOW_IGNORE_URLS", ()))
def process_request(self, request):
if not self._is_exempt(request):
request.dogslow = self.timer.run_later(
WatchdogMiddleware.peek, self.interval, request, thread.get_ident(), dt.datetime.utcnow()
)
def _cancel(self, request):
try:
if safehasattr(request, "dogslow"):
self.timer.cancel(request.dogslow)
del request.dogslow
except:
logging.exception("Failed to cancel request watchdog")
def process_response(self, request, response):
self._cancel(request)
return response
def process_exception(self, request, exception):
self._cancel(request)