Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with HTTPS or Subversion.

Download ZIP

Loading…

Use time.monotonic() where available. #583

Closed
wants to merge 2 commits into from

3 participants

@apenwarr

This patch changes tornado to use time.monotonic() wherever it can, rather than time.time(). This allows it to survive better when the normal clock jumps around (because of NTP or other reasons).

time.monotonic() is part of python 3.3, but you can also get my implementation for earlier versions from here: http://pypi.python.org/pypi/Monotime/ . This patch causes tornado to try that implementation if time.monotonic() is not otherwise available.

apenwarr added some commits
@apenwarr apenwarr Disable tests when old versions of twisted are installed.
Twisted 10.0 (on an older version of Ubuntu) doesn't seem to work with class
decorators, even on python 2.6.  This makes the tests fail with a TypeError:

Traceback (most recent call last):
  File "tornado/test/import_test.py", line 59, in test_import_twisted
    import tornado.platform.twisted
  File "tornado/platform/twisted.py", line 108, in <module>
    TornadoDelayedCall = implementer(IDelayedCall)(TornadoDelayedCall)
  File "/usr/lib/python2.6/dist-packages/zope/interface/declarations.py",
line 496, in __call__
    raise TypeError("Can't use implementer with classes.  Use one of "
TypeError: Can't use implementer with classes.  Use one of the
class-declaration functions instead.

If we catch a typeerror while importing twisted, act like twisted is not
installed.
a5bc9b5
@apenwarr apenwarr tornado: use time.monotonic() where available.
In ioloop.add_timeout(), we still support adding timeouts using time.time(),
but we actually convert them to time.monotonic() before running.  If you
don't explicitly set monotonic=False when calling add_timeout(), you'll get
a warning when that happens.

But mostly, you should really be passing in a datetime.timedelta object,
because almost always you want to use relative time instead of absolute
time.
a17cc80
@apenwarr

See also #558

@travisbot

This pull request passes (merged a17cc80 into 4daeaeb).

@bdarnell
Owner

Cool. I like this change, although I think it's probably too aggressive in encouraging the use of monotonic time. Logging a warning for each use of add_timeout(int) that doesn't specify monotonic is excessive (also the code doesn't seem to distinguish between None and False like the docstring says). I also wouldn't log at startup if neither time.monotonic or monotime is available (using the logging module at import time can mess up the logging configuration. I know we do it in ioloop.py but at least in that case it's limited to installations that are somehow broken).

In pull request #558, the time function is an attribute of the IOLoop instead of a global, which would let you have one thread's IOLoop using monotonic time and another thread on time.time(). I can see where that would be useful but it is kind of esoteric.

I don't really like the monotonic argument to add_timeout - it does allow for both monotonic and time.time-based code to coexist on the same IOLoop, but the new argument is effectively mandatory, which will get annoying. I'd almost say that add_timeout(int) should always use time.time (for cron-like tasks, "run this at midnight"), even when add_timeout(timedelta) uses monotonic time (and most instances of add_timeout should be converted to the timedelta form).

For the accompanying twisted change, a TypeError on importing tornado.platform.twisted could be a bug in that module, so I think this is a case where explicit version checks are better than catching the exception. I believe 11.0.0 is the first twisted version we support (it's at least the oldest version still in the tox config).

@apenwarr
@bdarnell bdarnell referenced this pull request from a commit
@bdarnell bdarnell Add time_func parameter to IOLoop, and make it possible to use time.m…
…onotonic.

This means that calls to IOLoop.add_timeout that pass a number must be
updated to use IOLoop.time instead of time.time.

There are still some places where we use time.time in the code, but they
are either places where wall time is desired, or non-critical deltas (e.g.
printing elapsed time at the end of a request).

Thanks to apenwarr and mgenti for pull requests and discussion relating to
this change. (#558 and #583)
20deb5c
@bdarnell
Owner

I've committed a time.monotonic change drawing on both pull requests. Like mgenti's version, I added a time_func argument to IOLoop's constructor. Instead of a monotonic argument to add_timeout, I simply said that all calls to add_timeout must be relative to the IOLoop's clock. This is going to be harder to audit for, but since use of a monotonic clock is opt-in I don't think it's too unreasonable (but I'm open to feedback on this point; it's not too late to change). Thanks to both of you for the pull requests and feedback.

@bdarnell bdarnell closed this
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Commits on Aug 14, 2012
  1. @apenwarr

    Disable tests when old versions of twisted are installed.

    apenwarr authored
    Twisted 10.0 (on an older version of Ubuntu) doesn't seem to work with class
    decorators, even on python 2.6.  This makes the tests fail with a TypeError:
    
    Traceback (most recent call last):
      File "tornado/test/import_test.py", line 59, in test_import_twisted
        import tornado.platform.twisted
      File "tornado/platform/twisted.py", line 108, in <module>
        TornadoDelayedCall = implementer(IDelayedCall)(TornadoDelayedCall)
      File "/usr/lib/python2.6/dist-packages/zope/interface/declarations.py",
    line 496, in __call__
        raise TypeError("Can't use implementer with classes.  Use one of "
    TypeError: Can't use implementer with classes.  Use one of the
    class-declaration functions instead.
    
    If we catch a typeerror while importing twisted, act like twisted is not
    installed.
  2. @apenwarr

    tornado: use time.monotonic() where available.

    apenwarr authored
    In ioloop.add_timeout(), we still support adding timeouts using time.time(),
    but we actually convert them to time.monotonic() before running.  If you
    don't explicitly set monotonic=False when calling add_timeout(), you'll get
    a warning when that happens.
    
    But mostly, you should really be passing in a datetime.timedelta object,
    because almost always you want to use relative time instead of absolute
    time.
This page is out of date. Refresh to see the latest.
View
9 tornado/curl_httpclient.py
@@ -20,10 +20,10 @@
import cStringIO
import collections
+import datetime
import logging
import pycurl
import threading
-import time
from tornado import httputil
from tornado import ioloop
@@ -31,6 +31,7 @@
from tornado.escape import utf8
from tornado.httpclient import HTTPRequest, HTTPResponse, HTTPError, AsyncHTTPClient, main
+from tornado.util import monotime
class CurlAsyncHTTPClient(AsyncHTTPClient):
@@ -108,7 +109,7 @@ def _set_timeout(self, msecs):
if self._timeout is not None:
self.io_loop.remove_timeout(self._timeout)
self._timeout = self.io_loop.add_timeout(
- time.time() + msecs / 1000.0, self._handle_timeout)
+ datetime.timedelta(milliseconds=msecs), self._handle_timeout)
def _handle_events(self, fd, events):
"""Called by IOLoop when there is activity on one of our
@@ -200,7 +201,7 @@ def _process_queue(self):
"buffer": cStringIO.StringIO(),
"request": request,
"callback": callback,
- "curl_start_time": time.time(),
+ "curl_start_time": monotime(),
}
# Disable IPv6 to mitigate the effects of this bug
# on curl versions <= 7.21.0
@@ -246,7 +247,7 @@ def _finish(self, curl, curl_error=None, curl_message=None):
info["callback"](HTTPResponse(
request=info["request"], code=code, headers=info["headers"],
buffer=buffer, effective_url=effective_url, error=error,
- request_time=time.time() - info["curl_start_time"],
+ request_time=monotime() - info["curl_start_time"],
time_info=time_info))
except Exception:
self.handle_callback_exception(info["callback"])
View
8 tornado/database.py
@@ -23,6 +23,8 @@
import logging
import time
+from tornado.util import monotime
+
try:
import MySQLdb.constants
import MySQLdb.converters
@@ -79,7 +81,7 @@ def __init__(self, host, database, user=None, password=None,
self._db = None
self._db_args = args
- self._last_use_time = time.time()
+ self._last_use_time = monotime()
try:
self.reconnect()
except Exception:
@@ -195,9 +197,9 @@ def _ensure_connected(self):
# case by preemptively closing and reopening the connection
# if it has been idle for too long (7 hours by default).
if (self._db is None or
- (time.time() - self._last_use_time > self.max_idle_time)):
+ (monotime() - self._last_use_time > self.max_idle_time)):
self.reconnect()
- self._last_use_time = time.time()
+ self._last_use_time = monotime()
def _cursor(self):
self._ensure_connected()
View
5 tornado/httpclient.py
@@ -34,13 +34,12 @@
import calendar
import email.utils
import httplib
-import time
import weakref
from tornado.escape import utf8
from tornado import httputil
from tornado.ioloop import IOLoop
-from tornado.util import import_object, bytes_type
+from tornado.util import import_object, bytes_type, monotime
class HTTPClient(object):
@@ -319,7 +318,7 @@ def __init__(self, url, method="GET", headers=None, body=None,
self.allow_ipv6 = allow_ipv6
self.client_key = client_key
self.client_cert = client_cert
- self.start_time = time.time()
+ self.start_time = monotime()
class HTTPResponse(object):
View
9 tornado/httpserver.py
@@ -29,14 +29,13 @@ class except to start a server at the beginning of the process
import Cookie
import logging
import socket
-import time
from tornado.escape import native_str, parse_qs_bytes
from tornado import httputil
from tornado import iostream
from tornado.netutil import TCPServer
from tornado import stack_context
-from tornado.util import b, bytes_type
+from tornado.util import b, bytes_type, monotime
try:
import ssl # Python 2.6+
@@ -378,7 +377,7 @@ def __init__(self, method, uri, version="HTTP/1.0", headers=None,
self.host = host or self.headers.get("Host") or "127.0.0.1"
self.files = files or {}
self.connection = connection
- self._start_time = time.time()
+ self._start_time = monotime()
self._finish_time = None
self.path, sep, self.query = uri.partition('?')
@@ -414,7 +413,7 @@ def write(self, chunk, callback=None):
def finish(self):
"""Finishes this HTTP request on the open connection."""
self.connection.finish()
- self._finish_time = time.time()
+ self._finish_time = monotime()
def full_url(self):
"""Reconstructs the full URL for this request."""
@@ -423,7 +422,7 @@ def full_url(self):
def request_time(self):
"""Returns the amount of time it took for this request to execute."""
if self._finish_time is None:
- return time.time() - self._start_time
+ return monotime() - self._start_time
else:
return self._finish_time - self._start_time
View
34 tornado/ioloop.py
@@ -47,6 +47,7 @@
signal = None
from tornado.platform.auto import set_close_exec, Waker
+from tornado.util import monotime
class IOLoop(object):
@@ -271,7 +272,7 @@ def start(self):
self._run_callback(callback)
if self._timeouts:
- now = time.time()
+ now = monotime()
while self._timeouts:
if self._timeouts[0].callback is None:
# the timeout was cancelled
@@ -366,7 +367,7 @@ def running(self):
"""Returns true if this IOLoop is currently running."""
return self._running
- def add_timeout(self, deadline, callback):
+ def add_timeout(self, deadline, callback, monotonic=None):
"""Calls the given callback at the time deadline from the I/O loop.
Returns a handle that may be passed to remove_timeout to cancel.
@@ -378,8 +379,15 @@ def add_timeout(self, deadline, callback):
Note that it is not safe to call `add_timeout` from other threads.
Instead, you must use `add_callback` to transfer control to the
IOLoop's thread, and then call `add_timeout` from there.
+
+ Set monotonic=False if deadline is from time.time(), or monotonic=True
+ if it comes from tornado.util.monotime(). If deadline is a
+ datetime.timedelta, you can omit the monotonic flag. For backward
+ compatibility, an unspecified monotonic flag acts like monotonic=False
+ but prints a warning.
"""
- timeout = _Timeout(deadline, stack_context.wrap(callback))
+ timeout = _Timeout(deadline, stack_context.wrap(callback),
+ monotonic=monotonic)
heapq.heappush(self._timeouts, timeout)
return timeout
@@ -441,11 +449,18 @@ class _Timeout(object):
# Reduce memory overhead when there are lots of pending callbacks
__slots__ = ['deadline', 'callback']
- def __init__(self, deadline, callback):
+ def __init__(self, deadline, callback, monotonic):
if isinstance(deadline, (int, long, float)):
- self.deadline = deadline
+ if monotonic:
+ self.deadline = deadline
+ else:
+ if hasattr(time, 'monotonic'):
+ import inspect
+ logging.warning('non-monotonic time _Timeout() created at %s:%d',
+ inspect.stack()[2][1], inspect.stack()[2][2])
+ self.deadline = deadline - time.time() + monotime()
elif isinstance(deadline, datetime.timedelta):
- self.deadline = time.time() + _Timeout.timedelta_to_seconds(deadline)
+ self.deadline = monotime() + _Timeout.timedelta_to_seconds(deadline)
else:
raise TypeError("Unsupported deadline %r" % deadline)
self.callback = callback
@@ -485,7 +500,7 @@ def __init__(self, callback, callback_time, io_loop=None):
def start(self):
"""Starts the timer."""
self._running = True
- self._next_timeout = time.time()
+ self._next_timeout = monotime()
self._schedule_next()
def stop(self):
@@ -506,10 +521,11 @@ def _run(self):
def _schedule_next(self):
if self._running:
- current_time = time.time()
+ current_time = monotime()
while self._next_timeout <= current_time:
self._next_timeout += self.callback_time / 1000.0
- self._timeout = self.io_loop.add_timeout(self._next_timeout, self._run)
+ self._timeout = self.io_loop.add_timeout(self._next_timeout,
+ self._run, monotonic=True)
class _EPoll(object):
View
7 tornado/platform/twisted.py
@@ -48,7 +48,6 @@
import functools
import logging
-import time
from twisted.internet.posixbase import PosixReactorBase
from twisted.internet.interfaces import \
@@ -62,6 +61,7 @@
import tornado.ioloop
from tornado.stack_context import NullContext
from tornado.ioloop import IOLoop
+from tornado.util import monotime
class TornadoDelayedCall(object):
@@ -71,7 +71,8 @@ def __init__(self, reactor, seconds, f, *args, **kw):
self._func = functools.partial(f, *args, **kw)
self._time = self._reactor.seconds() + seconds
self._timeout = self._reactor._io_loop.add_timeout(self._time,
- self._called)
+ self._called,
+ monotonic=True)
self._active = True
def _called(self):
@@ -139,7 +140,7 @@ def start_if_necessary():
# IReactorTime
def seconds(self):
- return time.time()
+ return monotime()
def callLater(self, seconds, f, *args, **kw):
dc = TornadoDelayedCall(self, seconds, f, *args, **kw)
View
13 tornado/simple_httpclient.py
@@ -6,7 +6,7 @@
from tornado.httputil import HTTPHeaders
from tornado.iostream import IOStream, SSLIOStream
from tornado import stack_context
-from tornado.util import b, GzipDecompressor
+from tornado.util import b, GzipDecompressor, monotime
import base64
import collections
@@ -18,7 +18,6 @@
import re
import socket
import sys
-import time
import urlparse
try:
@@ -124,7 +123,7 @@ class _HTTPConnection(object):
def __init__(self, io_loop, client, request, release_callback,
final_callback, max_buffer_size):
- self.start_time = time.time()
+ self.start_time = monotime()
self.io_loop = io_loop
self.client = client
self.request = request
@@ -218,7 +217,7 @@ def __init__(self, io_loop, client, request, release_callback,
if timeout:
self._timeout = self.io_loop.add_timeout(
self.start_time + timeout,
- stack_context.wrap(self._on_timeout))
+ stack_context.wrap(self._on_timeout), monotonic=True)
self.stream.set_close_callback(self._on_close)
self.stream.connect(sockaddr,
functools.partial(self._on_connect, parsed,
@@ -236,7 +235,7 @@ def _on_connect(self, parsed, parsed_hostname):
if self.request.request_timeout:
self._timeout = self.io_loop.add_timeout(
self.start_time + self.request.request_timeout,
- stack_context.wrap(self._on_timeout))
+ stack_context.wrap(self._on_timeout), monotonic=True)
if (self.request.validate_cert and
isinstance(self.stream, SSLIOStream)):
match_hostname(self.stream.socket.getpeercert(),
@@ -319,7 +318,7 @@ def cleanup(self):
except Exception, e:
logging.warning("uncaught exception", exc_info=True)
self._run_callback(HTTPResponse(self.request, 599, error=e,
- request_time=time.time() - self.start_time,
+ request_time=monotime() - self.start_time,
))
if hasattr(self, "stream"):
self.stream.close()
@@ -425,7 +424,7 @@ def _on_body(self, data):
buffer = BytesIO(data) # TODO: don't require one big string?
response = HTTPResponse(original_request,
self.code, headers=self.headers,
- request_time=time.time() - self.start_time,
+ request_time=monotime() - self.start_time,
buffer=buffer,
effective_url=self.request.url)
self._run_callback(response)
View
5 tornado/test/import_test.py
@@ -56,4 +56,7 @@ def test_import_twisted(self):
except ImportError:
pass
else:
- import tornado.platform.twisted
+ try:
+ import tornado.platform.twisted
+ except TypeError:
+ pass
View
4 tornado/test/iostream_test.py
@@ -5,10 +5,10 @@
from tornado.testing import AsyncHTTPTestCase, LogTrapTestCase, get_unused_port
from tornado.util import b
from tornado.web import RequestHandler, Application
+import datetime
import errno
import socket
import sys
-import time
class HelloHandler(RequestHandler):
@@ -226,7 +226,7 @@ def test_close_buffered_data(self):
# Allow the close to propagate to the client side of the
# connection. Using add_callback instead of add_timeout
# doesn't seem to work, even with multiple iterations
- self.io_loop.add_timeout(time.time() + 0.01, self.stop)
+ self.io_loop.add_timeout(datetime.timedelta(seconds=0.01), self.stop)
self.wait()
client.read_bytes(256, self.stop)
data = self.wait()
View
6 tornado/test/testing_test.py
@@ -1,8 +1,8 @@
#!/usr/bin/env python
from __future__ import absolute_import, division, with_statement
+import datetime
import unittest
-import time
from tornado.testing import AsyncTestCase, LogTrapTestCase
@@ -20,9 +20,9 @@ def test_subsequent_wait_calls(self):
This test makes sure that a second call to wait()
clears the first timeout.
"""
- self.io_loop.add_timeout(time.time() + 0.01, self.stop)
+ self.io_loop.add_timeout(datetime.timedelta(seconds=0.01), self.stop)
self.wait(timeout=0.02)
- self.io_loop.add_timeout(time.time() + 0.03, self.stop)
+ self.io_loop.add_timeout(datetime.timedelta(seconds=0.03), self.stop)
self.wait(timeout=0.1)
View
2  tornado/test/twisted_test.py
@@ -37,7 +37,7 @@
from tornado.platform.twisted import TornadoReactor
from zope.interface import implementer
have_twisted = True
-except ImportError:
+except (ImportError, TypeError):
have_twisted = False
from tornado.httpclient import AsyncHTTPClient
View
4 tornado/testing.py
@@ -36,11 +36,11 @@
from tornado.stack_context import StackContext, NullContext
from tornado.util import raise_exc_info
import contextlib
+import datetime
import logging
import os
import signal
import sys
-import time
import unittest
_next_port = 10000
@@ -189,7 +189,7 @@ def timeout_func():
self.stop()
if self.__timeout is not None:
self.io_loop.remove_timeout(self.__timeout)
- self.__timeout = self.io_loop.add_timeout(time.time() + timeout, timeout_func)
+ self.__timeout = self.io_loop.add_timeout(datetime.timedelta(seconds=timeout), timeout_func)
while True:
self.__running = True
with NullContext():
View
20 tornado/util.py
@@ -5,6 +5,26 @@
import zlib
+try:
+ # You can get the monotime module from:
+ # http://pypi.python.org/pypi/Monotime/
+ import monotime
+except ImportError:
+ pass
+import time
+try:
+ # python 3.3 has time.monotonic(), or the monotime module might have
+ # added it.
+ monotime_impl = time.monotonic
+except AttributeError:
+ import logging
+ logging.warning("time.monotonic() not available; using time.time()")
+ monotime_impl = time.time
+# wrap monotime_impl so that monotime_impl can be reassigned in unit tests
+def monotime():
+ return monotime_impl()
+
+
class ObjectDict(dict):
"""Makes a dictionary behave like an object."""
def __getattr__(self, name):
View
6 tornado/websocket.py
@@ -21,11 +21,11 @@
# Author: Jacob Kristhammar, 2010
import array
+import datetime
import functools
import hashlib
import logging
import struct
-import time
import base64
import tornado.escape
import tornado.web
@@ -433,7 +433,7 @@ def close(self):
self.stream.close()
elif self._waiting is None:
self._waiting = self.stream.io_loop.add_timeout(
- time.time() + 5, self._abort)
+ datetime.timedelta(seconds=5), self._abort)
class WebSocketProtocol13(WebSocketProtocol):
@@ -651,4 +651,4 @@ def close(self):
# Give the client a few seconds to complete a clean shutdown,
# otherwise just close the connection.
self._waiting = self.stream.io_loop.add_timeout(
- time.time() + 5, self._abort)
+ datetime.timedelta(seconds=5), self._abort)
View
7 tornado/wsgi.py
@@ -35,7 +35,6 @@
import httplib
import logging
import sys
-import time
import tornado
import urllib
@@ -43,7 +42,7 @@
from tornado import httputil
from tornado import web
from tornado.escape import native_str, utf8, parse_qs_bytes
-from tornado.util import b, bytes_type
+from tornado.util import b, bytes_type, monotime
try:
from io import BytesIO # python 3
@@ -168,7 +167,7 @@ def __init__(self, environ):
httputil.parse_body_arguments(self.headers.get("Content-Type", ""),
self.body, self.arguments, self.files)
- self._start_time = time.time()
+ self._start_time = monotime()
self._finish_time = None
def supports_http_1_1(self):
@@ -195,7 +194,7 @@ def full_url(self):
def request_time(self):
"""Returns the amount of time it took for this request to execute."""
if self._finish_time is None:
- return time.time() - self._start_time
+ return monotime() - self._start_time
else:
return self._finish_time - self._start_time
Something went wrong with that request. Please try again.