Files
zulip/zerver/lib/tornado_ioloop_logging.py
Tim Abbott e111a2f9a5 [manual] Rename Django app from zephyr to zerver.
This needs to be deployed to both staging and prod at the same
off-peak time (and the schema migration run).

At the time it is deployed, we need to make a few changes directly in
the database:

(1) UPDATE django_content_type set app_label='zerver' where app_label='zephyr';
(2) UPDATE south_migrationhistory set app_name='zerver' where app_name='zephyr';

(imported from commit eb3fd719571740189514ef0b884738cb30df1320)
2013-08-06 07:39:36 -04:00

63 lines
2.2 KiB
Python

from __future__ import absolute_import
import logging
import time
from tornado import ioloop
from django.conf import settings
orig_poll_impl = ioloop._poll
# A hack to keep track of how much time we spend working, versus sleeping in
# the event loop.
#
# Creating a new event loop instance with a custom impl object fails (events
# don't get processed), so instead we modify the ioloop module variable holding
# the default poll implementation. We need to do this before any Tornado code
# runs that might instantiate the default event loop.
class InstrumentedPoll(object):
def __init__(self):
self._underlying = orig_poll_impl()
self._times = []
self._last_print = 0
# Python won't let us subclass e.g. select.epoll, so instead
# we proxy every method. __getattr__ handles anything we
# don't define elsewhere.
def __getattr__(self, name):
return getattr(self._underlying, name)
# Call the underlying poll method, and report timing data.
def poll(self, timeout):
# Avoid accumulating a bunch of insignificant data points
# from short timeouts.
if timeout < 1e-3:
return self._underlying.poll(timeout)
# Record start and end times for the underlying poll
t0 = time.time()
result = self._underlying.poll(timeout)
t1 = time.time()
# Log this datapoint and restrict our log to the past minute
self._times.append((t0, t1))
while self._times and self._times[0][0] < t1 - 60:
self._times.pop(0)
# Report (at most once every 5s) the percentage of time spent
# outside poll
if self._times and t1 - self._last_print >= 5:
total = t1 - self._times[0][0]
in_poll = sum(b-a for a,b in self._times)
if total > 0:
percent_busy = 100 * (1 - in_poll/total)
if settings.DEPLOYED or percent_busy > 20:
logging.info('Tornado %5.1f%% busy over the past %4.1f seconds'
% (percent_busy, total))
self._last_print = t1
return result
def instrument_tornado_ioloop():
ioloop._poll = InstrumentedPoll