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.

tornado/curl_httpclient.py

@@ -20,17 +20,18 @@
 
 import cStringIO
 import collections
+import datetime
 import logging
 import pycurl
 import threading
-import time
 
 from tornado import httputil
 from tornado import ioloop
 from tornado import stack_context
 
 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"])

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()

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):

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
 

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):

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)

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)

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()

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)
 
 

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():