diff --git a/gunicorn/arbiter.py b/gunicorn/arbiter.py index 44ae5061..a390c9ca 100644 --- a/gunicorn/arbiter.py +++ b/gunicorn/arbiter.py @@ -479,9 +479,9 @@ class Arbiter(object): self.kill_worker(pid, signal.SIGQUIT) self.log.info("%d workers", - metric="gunicorn.workers", - value=len(self.WORKERS), - mtype="gauge") + extra={"metric": "gunicorn.workers", + "value": len(self.WORKERS), + "mtype": "gauge"}) def spawn_worker(self): self.worker_age += 1 diff --git a/gunicorn/instrument/statsd.py b/gunicorn/instrument/statsd.py index ec7f9697..85e195e2 100644 --- a/gunicorn/instrument/statsd.py +++ b/gunicorn/instrument/statsd.py @@ -3,8 +3,8 @@ # This file is part of gunicorn released under the MIT license. # See the NOTICE for more information. -"""Bare-bones implementation of statsD's protocol, client-side -""" +"Bare-bones implementation of statsD's protocol, client-side" + import socket from gunicorn.glogging import Logger @@ -33,22 +33,18 @@ class Statsd(Logger): # Log errors and warnings def critical(self, msg, *args, **kwargs): - self._sanitize(kwargs) Logger.critical(self, msg, *args, **kwargs) self.increment("gunicorn.log.critical", 1) def error(self, msg, *args, **kwargs): - self._sanitize(kwargs) Logger.error(self, msg, *args, **kwargs) self.increment("gunicorn.log.error", 1) def warning(self, msg, *args, **kwargs): - self._sanitize(kwargs) Logger.warning(self, msg, *args, **kwargs) self.increment("gunicorn.log.warning", 1) def exception(self, msg, *args, **kwargs): - self._sanitize(kwargs) Logger.exception(self, msg, *args, **kwargs) self.increment("gunicorn.log.exception", 1) @@ -56,28 +52,27 @@ class Statsd(Logger): def info(self, msg, *args, **kwargs): """Log a given statistic if metric, value and type are present """ - metric = kwargs.get(METRIC_VAR, None) - value = kwargs.get(VALUE_VAR, None) - typ = kwargs.get(MTYPE_VAR, None) - if metric and value and typ: - self._sanitize(kwargs) - if typ == GAUGE_TYPE: - self.gauge(metric, value) - elif typ == COUNTER_TYPE: - self.increment(metric, value) - elif typ == HISTOGRAM_TYPE: - self.histogram(metric, value) - else: - pass + extra = kwargs.get("extra", None) + if extra is not None: + metric = extra.get(METRIC_VAR, None) + value = extra.get(VALUE_VAR, None) + typ = extra.get(MTYPE_VAR, None) + if metric and value and typ: + if typ == GAUGE_TYPE: + self.gauge(metric, value) + elif typ == COUNTER_TYPE: + self.increment(metric, value) + elif typ == HISTOGRAM_TYPE: + self.histogram(metric, value) + else: + pass Logger.info(self, msg, *args, **kwargs) # skip the run-of-the-mill logs def debug(self, msg, *args, **kwargs): - self._sanitize(kwargs) Logger.debug(self, msg, *args, **kwargs) def log(self, lvl, msg, *args, **kwargs): - self._sanitize(kwargs) Logger.log(self, lvl, msg, *args, **kwargs) # access logging @@ -89,14 +84,7 @@ class Statsd(Logger): duration_in_s = request_time.seconds + float(request_time.microseconds)/10**6 self.histogram("gunicorn.request.duration", duration_in_s) self.increment("gunicorn.requests", 1) - - def _sanitize(self, kwargs): - """Drop stasd keywords from the logger""" - for k in (METRIC_VAR, VALUE_VAR, MTYPE_VAR): - try: - kwargs.pop(k) - except KeyError: - pass + self.increment("gunicorn.request.status.%d" % int(resp.status), 1) # statsD methods # you can use those directly if you want diff --git a/tests/test_009-statsd.py b/tests/test_009-statsd.py new file mode 100644 index 00000000..24bb6f57 --- /dev/null +++ b/tests/test_009-statsd.py @@ -0,0 +1,54 @@ +from datetime import timedelta + +import t + +from gunicorn.config import Config +from gunicorn.instrument.statsd import Statsd + +class TestException(Exception): pass + +class MockSocket(object): + "Pretend to be a UDP socket" + def __init__(self, failp): + self.failp = failp + self.msgs = [] # accumulate messages for later inspection + + def send(self, msg): + if self.failp: + raise TestException("Should not interrupt the logger") + self.msgs.append(msg) + + def reset(self): + self.msgs = [] + +class MockResponse(object): + def __init__(self, status): + self.status = status + +def test_statsd_fail(): + "UDP socket fails" + logger = Statsd(Config()) + logger.sock = MockSocket(True) + logger.info("No impact on logging") + logger.debug("No impact on logging") + logger.critical("No impact on logging") + logger.error("No impact on logging") + logger.warning("No impact on logging") + logger.exception("No impact on logging") + +def test_instrument(): + logger = Statsd(Config()) + logger.sock = MockSocket(False) + + logger.info("Blah", extra={"mtype": "gauge", "metric": "gunicorn.test", "value": 666}) + t.eq(logger.sock.msgs[0], "gunicorn.test:666|g") + logger.sock.reset() + + logger.critical("Boom") + t.eq(logger.sock.msgs[0], "gunicorn.log.critical:1|c|@1.0") + logger.sock.reset() + + logger.access(MockResponse(200), None, {}, timedelta(seconds=7)) + t.eq(logger.sock.msgs[0], "gunicorn.request.duration:7.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")