From e340491473498e7b67fd0e9e2e2a31d6b16ee20e Mon Sep 17 00:00:00 2001 From: Ben Darnell Date: Tue, 23 Mar 2010 17:31:14 -0700 Subject: [PATCH 1/2] Add __slots__ to ioloop._Timeout to reduce memory overhead when there are many pending timeouts. --- tornado/ioloop.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/tornado/ioloop.py b/tornado/ioloop.py index b2a10567..0d3083ef 100644 --- a/tornado/ioloop.py +++ b/tornado/ioloop.py @@ -297,6 +297,10 @@ class IOLoop(object): class _Timeout(object): """An IOLoop timeout, a UNIX timestamp and a callback""" + + # Reduce memory overhead when there are lots of pending callbacks + __slots__ = ['deadline', 'callback'] + def __init__(self, deadline, callback): self.deadline = deadline self.callback = callback From e391fd289ed085671344504cc5b1fa84f5a3c774 Mon Sep 17 00:00:00 2001 From: Brandon Bickford Date: Mon, 15 Mar 2010 14:48:17 -0700 Subject: [PATCH 2/2] Use per-module loggers instead of the root logger. --- tornado/auth.py | 19 ++++++++++--------- tornado/autoreload.py | 3 ++- tornado/database.py | 5 +++-- tornado/httpclient.py | 15 ++++++++------- tornado/httpserver.py | 15 ++++++++------- tornado/ioloop.py | 16 +++++++++------- tornado/iostream.py | 9 +++++---- tornado/locale.py | 7 ++++--- tornado/options.py | 1 + tornado/template.py | 5 +++-- tornado/web.py | 23 ++++++++++++----------- tornado/websocket.py | 4 +++- tornado/wsgi.py | 13 +++++++------ 13 files changed, 75 insertions(+), 60 deletions(-) diff --git a/tornado/auth.py b/tornado/auth.py index ca352b3b..f67d9e54 100644 --- a/tornado/auth.py +++ b/tornado/auth.py @@ -58,6 +58,7 @@ import urllib import urlparse import uuid +_log = logging.getLogger("tornado.auth") class OpenIdMixin(object): """Abstract implementation of OpenID and Attribute Exchange. @@ -145,7 +146,7 @@ class OpenIdMixin(object): def _on_authentication_verified(self, callback, response): if response.error or u"is_valid:true" not in response.body: - logging.warning("Invalid OpenID response: %s", response.error or + _log.warning("Invalid OpenID response: %s", response.error or response.body) callback(None) return @@ -232,12 +233,12 @@ class OAuthMixin(object): request_key = self.get_argument("oauth_token") request_cookie = self.get_cookie("_oauth_request_token") if not request_cookie: - logging.warning("Missing OAuth request token cookie") + _log.warning("Missing OAuth request token cookie") callback(None) return cookie_key, cookie_secret = request_cookie.split("|") if cookie_key != request_key: - logging.warning("Request token does not match cookie") + _log.warning("Request token does not match cookie") callback(None) return token = dict(key=cookie_key, secret=cookie_secret) @@ -289,7 +290,7 @@ class OAuthMixin(object): def _on_access_token(self, callback, response): if response.error: - logging.warning("Could not fetch access token") + _log.warning("Could not fetch access token") callback(None) return access_token = _oauth_parse_response(response.body) @@ -441,7 +442,7 @@ class TwitterMixin(OAuthMixin): def _on_twitter_request(self, callback, response): if response.error: - logging.warning("Error response %s fetching %s", response.error, + _log.warning("Error response %s fetching %s", response.error, response.request.url) callback(None) return @@ -561,7 +562,7 @@ class FriendFeedMixin(OAuthMixin): def _on_friendfeed_request(self, callback, response): if response.error: - logging.warning("Error response %s fetching %s", response.error, + _log.warning("Error response %s fetching %s", response.error, response.request.url) callback(None) return @@ -819,17 +820,17 @@ class FacebookMixin(object): def _parse_response(self, callback, response): if response.error: - logging.warning("HTTP error from Facebook: %s", response.error) + _log.warning("HTTP error from Facebook: %s", response.error) callback(None) return try: json = escape.json_decode(response.body) except: - logging.warning("Invalid JSON from Facebook: %r", response.body) + _log.warning("Invalid JSON from Facebook: %r", response.body) callback(None) return if isinstance(json, dict) and json.get("error_code"): - logging.warning("Facebook error: %d: %r", json["error_code"], + _log.warning("Facebook error: %d: %r", json["error_code"], json.get("error_msg")) callback(None) return diff --git a/tornado/autoreload.py b/tornado/autoreload.py index 8fd5f88d..231cfe89 100644 --- a/tornado/autoreload.py +++ b/tornado/autoreload.py @@ -29,6 +29,7 @@ import os.path import sys import types +_log = logging.getLogger('tornado.autoreload') def start(io_loop=None, check_time=500): """Restarts the process automatically when a module is modified. @@ -68,7 +69,7 @@ def _reload_on_update(io_loop, modify_times): modify_times[path] = modified continue if modify_times[path] != modified: - logging.info("%s modified; restarting server", path) + _log.info("%s modified; restarting server", path) _reload_attempted = True for fd in io_loop._handlers.keys(): try: diff --git a/tornado/database.py b/tornado/database.py index 1dde6bf8..3f78e00b 100644 --- a/tornado/database.py +++ b/tornado/database.py @@ -24,6 +24,7 @@ import MySQLdb.cursors import itertools import logging +_log = logging.getLogger('tornado.database') class Connection(object): """A lightweight wrapper around MySQLdb DB-API connections. @@ -71,7 +72,7 @@ class Connection(object): try: self.reconnect() except: - logging.error("Cannot connect to MySQL on %s", self.host, + _log.error("Cannot connect to MySQL on %s", self.host, exc_info=True) def __del__(self): @@ -150,7 +151,7 @@ class Connection(object): try: return cursor.execute(query, parameters) except OperationalError: - logging.error("Error connecting to MySQL on %s", self.host) + _log.error("Error connecting to MySQL on %s", self.host) self.close() raise diff --git a/tornado/httpclient.py b/tornado/httpclient.py index f01f8bb4..2c9155eb 100644 --- a/tornado/httpclient.py +++ b/tornado/httpclient.py @@ -29,6 +29,7 @@ import pycurl import time import weakref +_log = logging.getLogger('tornado.httpclient') class HTTPClient(object): """A blocking HTTP client backed with pycurl. @@ -342,7 +343,7 @@ class CurlError(HTTPError): def _curl_create(max_simultaneous_connections=None): curl = pycurl.Curl() - if logging.getLogger().isEnabledFor(logging.DEBUG): + if _log.isEnabledFor(logging.DEBUG): curl.setopt(pycurl.VERBOSE, 1) curl.setopt(pycurl.DEBUGFUNCTION, _curl_debug) curl.setopt(pycurl.MAXCONNECTS, max_simultaneous_connections or 5) @@ -417,11 +418,11 @@ def _curl_setup_request(curl, request, buffer, headers): userpwd = "%s:%s" % (request.auth_username, request.auth_password) curl.setopt(pycurl.HTTPAUTH, pycurl.HTTPAUTH_BASIC) curl.setopt(pycurl.USERPWD, userpwd) - logging.info("%s %s (username: %r)", request.method, request.url, + _log.info("%s %s (username: %r)", request.method, request.url, request.auth_username) else: curl.unsetopt(pycurl.USERPWD) - logging.info("%s %s", request.method, request.url) + _log.info("%s %s", request.method, request.url) if request.prepare_curl_callback is not None: request.prepare_curl_callback(curl) @@ -434,7 +435,7 @@ def _curl_header_callback(headers, header_line): return parts = header_line.split(": ") if len(parts) != 2: - logging.warning("Invalid HTTP response header line %r", header_line) + _log.warning("Invalid HTTP response header line %r", header_line) return name = parts[0].strip() value = parts[1].strip() @@ -447,12 +448,12 @@ def _curl_header_callback(headers, header_line): def _curl_debug(debug_type, debug_msg): debug_types = ('I', '<', '>', '<', '>') if debug_type == 0: - logging.debug('%s', debug_msg.strip()) + _log.debug('%s', debug_msg.strip()) elif debug_type in (1, 2): for line in debug_msg.splitlines(): - logging.debug('%s %s', debug_types[debug_type], line) + _log.debug('%s %s', debug_types[debug_type], line) elif debug_type == 4: - logging.debug('%s %r', debug_types[debug_type], debug_msg) + _log.debug('%s %r', debug_types[debug_type], debug_msg) def _utf8(value): diff --git a/tornado/httpserver.py b/tornado/httpserver.py index ec95b7f1..0e516c29 100644 --- a/tornado/httpserver.py +++ b/tornado/httpserver.py @@ -33,6 +33,7 @@ try: except ImportError: ssl = None +_log = logging.getLogger('tornado.httpserver') class HTTPServer(object): """A non-blocking, single-threaded HTTP server. @@ -164,16 +165,16 @@ class HTTPServer(object): try: num_processes = os.sysconf("SC_NPROCESSORS_CONF") except ValueError: - logging.error("Could not get num processors from sysconf; " + _log.error("Could not get num processors from sysconf; " "running with one process") num_processes = 1 if num_processes > 1 and ioloop.IOLoop.initialized(): - logging.error("Cannot run in multiple processes: IOLoop instance " + _log.error("Cannot run in multiple processes: IOLoop instance " "has already been initialized. You cannot call " "IOLoop.instance() before calling start()") num_processes = 1 if num_processes > 1: - logging.info("Pre-forking %d server processes", num_processes) + _log.info("Pre-forking %d server processes", num_processes) for i in range(num_processes): if os.fork() == 0: self.io_loop = ioloop.IOLoop.instance() @@ -210,7 +211,7 @@ class HTTPServer(object): HTTPConnection(stream, address, self.request_callback, self.no_keep_alive, self.xheaders) except: - logging.error("Error in connection callback", exc_info=True) + _log.error("Error in connection callback", exc_info=True) class HTTPConnection(object): @@ -313,13 +314,13 @@ class HTTPConnection(object): if not part: continue eoh = part.find("\r\n\r\n") if eoh == -1: - logging.warning("multipart/form-data missing headers") + _log.warning("multipart/form-data missing headers") continue headers = HTTPHeaders.parse(part[:eoh]) name_header = headers.get("Content-Disposition", "") if not name_header.startswith("form-data;") or \ not part.endswith("\r\n"): - logging.warning("Invalid multipart/form-data") + _log.warning("Invalid multipart/form-data") continue value = part[eoh + 4:-2] name_values = {} @@ -327,7 +328,7 @@ class HTTPConnection(object): name, name_value = name_part.strip().split("=", 1) name_values[name] = name_value.strip('"').decode("utf-8") if not name_values.get("name"): - logging.warning("multipart/form-data value missing name") + _log.warning("multipart/form-data value missing name") continue name = name_values["name"] if name_values.get("filename"): diff --git a/tornado/ioloop.py b/tornado/ioloop.py index 0d3083ef..9e16b258 100644 --- a/tornado/ioloop.py +++ b/tornado/ioloop.py @@ -25,6 +25,8 @@ import select import time +_log = logging.getLogger("tornado.ioloop") + class IOLoop(object): """A level-triggered I/O loop. @@ -141,7 +143,7 @@ class IOLoop(object): try: self._impl.unregister(fd) except (OSError, IOError): - logging.debug("Error deleting fd from IOLoop", exc_info=True) + _log.debug("Error deleting fd from IOLoop", exc_info=True) def start(self): """Starts the I/O loop. @@ -185,7 +187,7 @@ class IOLoop(object): event_pairs = self._impl.poll(poll_timeout) except Exception, e: if e.errno == errno.EINTR: - logging.warning("Interrupted system call", exc_info=1) + _log.warning("Interrupted system call", exc_info=1) continue else: raise @@ -206,10 +208,10 @@ class IOLoop(object): # Happens when the client closes the connection pass else: - logging.error("Exception in I/O handler for fd %d", + _log.error("Exception in I/O handler for fd %d", fd, exc_info=True) except: - logging.error("Exception in I/O handler for fd %d", + _log.error("Exception in I/O handler for fd %d", fd, exc_info=True) # reset the stopped flag so another start/stop pair can be issued self._stopped = False @@ -277,7 +279,7 @@ class IOLoop(object): The exception itself is not passed explicitly, but is available in sys.exc_info. """ - logging.error("Exception in callback %r", callback, exc_info=True) + _log.error("Exception in callback %r", callback, exc_info=True) def _read_waker(self, fd, events): try: @@ -335,7 +337,7 @@ class PeriodicCallback(object): except (KeyboardInterrupt, SystemExit): raise except: - logging.error("Error in periodic callback", exc_info=True) + _log.error("Error in periodic callback", exc_info=True) self.start() @@ -466,5 +468,5 @@ else: # All other systems import sys if "linux" in sys.platform: - logging.warning("epoll module not found; using select()") + _log.warning("epoll module not found; using select()") _poll = _Select diff --git a/tornado/iostream.py b/tornado/iostream.py index 53a50c76..af7c6edb 100644 --- a/tornado/iostream.py +++ b/tornado/iostream.py @@ -21,6 +21,7 @@ import ioloop import logging import socket +_log = logging.getLogger('tornado.iostream') class IOStream(object): """A utility class to write to and read from a non-blocking socket. @@ -138,7 +139,7 @@ class IOStream(object): def _handle_events(self, fd, events): if not self.socket: - logging.warning("Got events for closed stream %d", fd) + _log.warning("Got events for closed stream %d", fd) return if events & self.io_loop.READ: self._handle_read() @@ -167,7 +168,7 @@ class IOStream(object): if e[0] in (errno.EWOULDBLOCK, errno.EAGAIN): return else: - logging.warning("Read error on %d: %s", + _log.warning("Read error on %d: %s", self.socket.fileno(), e) self.close() return @@ -176,7 +177,7 @@ class IOStream(object): return self._read_buffer += chunk if len(self._read_buffer) >= self.max_buffer_size: - logging.error("Reached maximum read buffer size") + _log.error("Reached maximum read buffer size") self.close() return if self._read_bytes: @@ -204,7 +205,7 @@ class IOStream(object): if e[0] in (errno.EWOULDBLOCK, errno.EAGAIN): break else: - logging.warning("Write error on %d: %s", + _log.warning("Write error on %d: %s", self.socket.fileno(), e) self.close() return diff --git a/tornado/locale.py b/tornado/locale.py index 4bdd8685..a1dfad5d 100644 --- a/tornado/locale.py +++ b/tornado/locale.py @@ -45,6 +45,7 @@ _default_locale = "en_US" _translations = {} _supported_locales = frozenset([_default_locale]) +_log = logging.getLogger('tornado.locale') def get(*locale_codes): """Returns the closest match for the given locale codes. @@ -105,7 +106,7 @@ def load_translations(directory): if not path.endswith(".csv"): continue locale, extension = path.split(".") if locale not in LOCALE_NAMES: - logging.error("Unrecognized locale %r (path: %s)", locale, + _log.error("Unrecognized locale %r (path: %s)", locale, os.path.join(directory, path)) continue f = open(os.path.join(directory, path), "r") @@ -119,13 +120,13 @@ def load_translations(directory): else: plural = "unknown" if plural not in ("plural", "singular", "unknown"): - logging.error("Unrecognized plural indicator %r in %s line %d", + _log.error("Unrecognized plural indicator %r in %s line %d", plural, path, i + 1) continue _translations[locale].setdefault(plural, {})[english] = translation f.close() _supported_locales = frozenset(_translations.keys() + [_default_locale]) - logging.info("Supported locales: %s", sorted(_supported_locales)) + _log.info("Supported locales: %s", sorted(_supported_locales)) def get_supported_locales(cls): diff --git a/tornado/options.py b/tornado/options.py index 8edf6df9..a33ae4b6 100644 --- a/tornado/options.py +++ b/tornado/options.py @@ -49,6 +49,7 @@ for define() below. """ import datetime +import logging import logging.handlers import re import sys diff --git a/tornado/template.py b/tornado/template.py index b62735ee..7ed56cfa 100644 --- a/tornado/template.py +++ b/tornado/template.py @@ -88,6 +88,7 @@ import logging import os.path import re +_log = logging.getLogger('tornado.template') class Template(object): """A compiled template. @@ -108,7 +109,7 @@ class Template(object): self.compiled = compile(self.code, self.name, "exec") except: formatted_code = _format_code(self.code).rstrip() - logging.error("%s code:\n%s", self.name, formatted_code) + _log.error("%s code:\n%s", self.name, formatted_code) raise def generate(self, **kwargs): @@ -127,7 +128,7 @@ class Template(object): return execute() except: formatted_code = _format_code(self.code).rstrip() - logging.error("%s code:\n%s", self.name, formatted_code) + _log.error("%s code:\n%s", self.name, formatted_code) raise def _generate_python(self, loader, compress_whitespace): diff --git a/tornado/web.py b/tornado/web.py index f1ee8ee5..8cba99a8 100644 --- a/tornado/web.py +++ b/tornado/web.py @@ -70,6 +70,7 @@ import urllib import urlparse import uuid +_log = logging.getLogger('tornado.web') class RequestHandler(object): """Subclass this class and define get() or post() to make a handler. @@ -285,11 +286,11 @@ class RequestHandler(object): else: signature = self._cookie_signature(parts[0], parts[1]) if not _time_independent_equals(parts[2], signature): - logging.warning("Invalid cookie signature %r", value) + _log.warning("Invalid cookie signature %r", value) return None timestamp = int(parts[1]) if timestamp < time.time() - 31 * 86400: - logging.warning("Expired cookie %r", value) + _log.warning("Expired cookie %r", value) return None try: return base64.b64decode(parts[0]) @@ -499,7 +500,7 @@ class RequestHandler(object): for your application. """ if self._headers_written: - logging.error("Cannot send error response after headers written") + _log.error("Cannot send error response after headers written") if not self._finished: self.finish() return @@ -673,7 +674,7 @@ class RequestHandler(object): hashes[path] = hashlib.md5(f.read()).hexdigest() f.close() except: - logging.error("Could not open static file %r", path) + _log.error("Could not open static file %r", path) hashes[path] = None base = self.request.protocol + "://" + self.request.host \ if getattr(self, "include_host", False) else "" @@ -697,7 +698,7 @@ class RequestHandler(object): return callback(*args, **kwargs) except Exception, e: if self._headers_written: - logging.error("Exception after headers written", + _log.error("Exception after headers written", exc_info=True) else: self._handle_request_exception(e) @@ -742,11 +743,11 @@ class RequestHandler(object): def _log(self): if self._status_code < 400: - log_method = logging.info + log_method = _log.info elif self._status_code < 500: - log_method = logging.warning + log_method = _log.warning else: - log_method = logging.error + log_method = _log.error request_time = 1000.0 * self.request.request_time() log_method("%d %s %.2fms", self._status_code, self._request_summary(), request_time) @@ -760,14 +761,14 @@ class RequestHandler(object): if e.log_message: format = "%d %s: " + e.log_message args = [e.status_code, self._request_summary()] + list(e.args) - logging.warning(format, *args) + _log.warning(format, *args) if e.status_code not in httplib.responses: - logging.error("Bad HTTP status code: %d", e.status_code) + _log.error("Bad HTTP status code: %d", e.status_code) self.send_error(500, exception=e) else: self.send_error(e.status_code, exception=e) else: - logging.error("Uncaught exception %s\n%r", self._request_summary(), + _log.error("Uncaught exception %s\n%r", self._request_summary(), self.request, exc_info=e) self.send_error(500, exception=e) diff --git a/tornado/websocket.py b/tornado/websocket.py index dfca709c..38a58012 100644 --- a/tornado/websocket.py +++ b/tornado/websocket.py @@ -19,6 +19,8 @@ import logging import tornado.escape import tornado.web +_log = logging.getLogger('tornado.websocket') + class WebSocketHandler(tornado.web.RequestHandler): """A request handler for HTML 5 Web Sockets. @@ -114,7 +116,7 @@ class WebSocketHandler(tornado.web.RequestHandler): try: return callback(*args, **kwargs) except Exception, e: - logging.error("Uncaught exception in %s", + _log.error("Uncaught exception in %s", self.request.path, exc_info=True) self.stream.close() return wrapper diff --git a/tornado/wsgi.py b/tornado/wsgi.py index 79791121..7dab5187 100644 --- a/tornado/wsgi.py +++ b/tornado/wsgi.py @@ -60,6 +60,7 @@ import time import urllib import web +_log = logging.getLogger('tornado.wsgi') class WSGIApplication(web.Application): """A WSGI-equivalent of web.Application. @@ -158,13 +159,13 @@ class HTTPRequest(object): if not part: continue eoh = part.find("\r\n\r\n") if eoh == -1: - logging.warning("multipart/form-data missing headers") + _log.warning("multipart/form-data missing headers") continue headers = HTTPHeaders.parse(part[:eoh]) name_header = headers.get("Content-Disposition", "") if not name_header.startswith("form-data;") or \ not part.endswith("\r\n"): - logging.warning("Invalid multipart/form-data") + _log.warning("Invalid multipart/form-data") continue value = part[eoh + 4:-2] name_values = {} @@ -172,7 +173,7 @@ class HTTPRequest(object): name, name_value = name_part.strip().split("=", 1) name_values[name] = name_value.strip('"').decode("utf-8") if not name_values.get("name"): - logging.warning("multipart/form-data value missing name") + _log.warning("multipart/form-data value missing name") continue name = name_values["name"] if name_values.get("filename"): @@ -276,11 +277,11 @@ class WSGIContainer(object): def _log(self, status_code, request): if status_code < 400: - log_method = logging.info + log_method = _log.info elif status_code < 500: - log_method = logging.warning + log_method = _log.warning else: - log_method = logging.error + log_method = _log.error request_time = 1000.0 * request.request_time() summary = request.method + " " + request.uri + " (" + \ request.remote_ip + ")"