Merge pull request #1010 from krallin/fix-statsd-py3

Fix statsd Logging in Python 3
This commit is contained in:
Berker Peksag 2015-04-30 15:54:48 +03:00
commit a7354cf8fe
3 changed files with 53 additions and 33 deletions

View File

@ -224,8 +224,8 @@ class Logger(object):
def debug(self, msg, *args, **kwargs):
self.error_log.debug(msg, *args, **kwargs)
def exception(self, msg, *args):
self.error_log.exception(msg, *args)
def exception(self, msg, *args, **kwargs):
self.error_log.exception(msg, *args, **kwargs)
def log(self, lvl, msg, *args, **kwargs):
if isinstance(lvl, string_types):

View File

@ -8,7 +8,9 @@
import socket
import logging
from re import sub
from gunicorn.glogging import Logger
from gunicorn import six
# Instrumentation constants
STATSD_DEFAULT_PORT = 8125
@ -82,7 +84,7 @@ class Statsd(Logger):
if msg is not None and len(msg) > 0:
Logger.log(self, lvl, msg, *args, **kwargs)
except Exception:
pass
Logger.warning(self, "Failed to log to statsd", exc_info=True)
# access logging
def access(self, resp, req, environ, request_time):
@ -98,29 +100,22 @@ class Statsd(Logger):
# statsD methods
# you can use those directly if you want
def gauge(self, name, value):
try:
if self.sock:
self.sock.send("{0}{1}:{2}|g".format(self.prefix, name, value))
except Exception:
pass
self._sock_send("{0}{1}:{2}|g".format(self.prefix, name, value))
def increment(self, name, value, sampling_rate=1.0):
try:
if self.sock:
self.sock.send("{0}{1}:{2}|c|@{3}".format(self.prefix, name, value, sampling_rate))
except Exception:
pass
self._sock_send("{0}{1}:{2}|c|@{3}".format(self.prefix, name, value, sampling_rate))
def decrement(self, name, value, sampling_rate=1.0):
try:
if self.sock:
self.sock.send("{0){1}:-{2}|c|@{3}".format(self.prefix, name, value, sampling_rate))
except Exception:
pass
self._sock_send("{0){1}:-{2}|c|@{3}".format(self.prefix, name, value, sampling_rate))
def histogram(self, name, value):
self._sock_send("{0}{1}:{2}|ms".format(self.prefix, name, value))
def _sock_send(self, msg):
try:
if isinstance(msg, six.text_type):
msg = msg.encode("ascii")
if self.sock:
self.sock.send("{0}{1}:{2}|ms".format(self.prefix, name, value))
self.sock.send(msg)
except Exception:
pass
Logger.warning(self, "Error sending message to statsd", exc_info=True)

View File

@ -1,4 +1,5 @@
from datetime import timedelta
import socket
import t
@ -8,12 +9,18 @@ except ImportError:
from io import StringIO
import logging
import tempfile
import shutil
import os
from gunicorn.config import Config
from gunicorn.instrument.statsd import Statsd
class TestException(Exception): pass
class TestException(Exception):
pass
class MockSocket(object):
"Pretend to be a UDP socket"
@ -24,7 +31,25 @@ class MockSocket(object):
def send(self, msg):
if self.failp:
raise TestException("Should not interrupt the logger")
self.msgs.append(msg)
sock_dir = tempfile.mkdtemp()
sock_file = os.path.join(sock_dir, "test.sock")
server = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)
client = socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM)
try:
server.bind(sock_file)
client.connect(sock_file)
client.send(msg)
self.msgs.append(server.recv(1024))
finally:
client.close()
server.close()
shutil.rmtree(sock_dir)
def reset(self):
self.msgs = []
@ -53,30 +78,30 @@ def test_instrument():
# Regular message
logger.info("Blah", extra={"mtype": "gauge", "metric": "gunicorn.test", "value": 666})
t.eq(logger.sock.msgs[0], "gunicorn.test:666|g")
t.eq(logger.sock.msgs[0], b"gunicorn.test:666|g")
t.eq(sio.getvalue(), "Blah\n")
logger.sock.reset()
# Only metrics, no logging
logger.info("", extra={"mtype": "gauge", "metric": "gunicorn.test", "value": 666})
t.eq(logger.sock.msgs[0], "gunicorn.test:666|g")
t.eq(logger.sock.msgs[0], b"gunicorn.test:666|g")
t.eq(sio.getvalue(), "Blah\n") # log is unchanged
logger.sock.reset()
# Debug logging also supports metrics
logger.debug("", extra={"mtype": "gauge", "metric": "gunicorn.debug", "value": 667})
t.eq(logger.sock.msgs[0], "gunicorn.debug:667|g")
t.eq(logger.sock.msgs[0], b"gunicorn.debug:667|g")
t.eq(sio.getvalue(), "Blah\n") # log is unchanged
logger.sock.reset()
logger.critical("Boom")
t.eq(logger.sock.msgs[0], "gunicorn.log.critical:1|c|@1.0")
t.eq(logger.sock.msgs[0], b"gunicorn.log.critical:1|c|@1.0")
logger.sock.reset()
logger.access(MockResponse("200 OK"), None, {}, timedelta(seconds=7))
t.eq(logger.sock.msgs[0], "gunicorn.request.duration:7000.0|ms")
t.eq(logger.sock.msgs[1], "gunicorn.requests:1|c|@1.0")
t.eq(logger.sock.msgs[2], "gunicorn.request.status.200:1|c|@1.0")
t.eq(logger.sock.msgs[0], b"gunicorn.request.duration:7000.0|ms")
t.eq(logger.sock.msgs[1], b"gunicorn.requests:1|c|@1.0")
t.eq(logger.sock.msgs[2], b"gunicorn.request.status.200:1|c|@1.0")
def test_prefix():
c = Config()
@ -85,7 +110,7 @@ def test_prefix():
logger.sock = MockSocket(False)
logger.info("Blah", extra={"mtype": "gauge", "metric": "gunicorn.test", "value": 666})
t.eq(logger.sock.msgs[0], "test.gunicorn.test:666|g")
t.eq(logger.sock.msgs[0], b"test.gunicorn.test:666|g")
def test_prefix_no_dot():
c = Config()
@ -94,7 +119,7 @@ def test_prefix_no_dot():
logger.sock = MockSocket(False)
logger.info("Blah", extra={"mtype": "gauge", "metric": "gunicorn.test", "value": 666})
t.eq(logger.sock.msgs[0], "test.gunicorn.test:666|g")
t.eq(logger.sock.msgs[0], b"test.gunicorn.test:666|g")
def test_prefix_multiple_dots():
c = Config()
@ -103,7 +128,7 @@ def test_prefix_multiple_dots():
logger.sock = MockSocket(False)
logger.info("Blah", extra={"mtype": "gauge", "metric": "gunicorn.test", "value": 666})
t.eq(logger.sock.msgs[0], "test.gunicorn.test:666|g")
t.eq(logger.sock.msgs[0], b"test.gunicorn.test:666|g")
def test_prefix_nested():
c = Config()
@ -112,4 +137,4 @@ def test_prefix_nested():
logger.sock = MockSocket(False)
logger.info("Blah", extra={"mtype": "gauge", "metric": "gunicorn.test", "value": 666})
t.eq(logger.sock.msgs[0], "test.asdf.gunicorn.test:666|g")
t.eq(logger.sock.msgs[0], b"test.asdf.gunicorn.test:666|g")