diff --git a/gunicorn/arbiter.py b/gunicorn/arbiter.py index 38b93d54e..ae53290d1 100644 --- a/gunicorn/arbiter.py +++ b/gunicorn/arbiter.py @@ -482,10 +482,10 @@ def manage_workers(self): (pid, _) = workers.pop(0) self.kill_worker(pid, signal.SIGTERM) - self.log.info("{0} workers".format(len(workers)), - extra={"metric": "gunicorn.workers", - "value": len(workers), - "mtype": "gauge"}) + self.log.debug("", + extra={ "metric": "gunicorn.workers", + "value": len(workers), + "mtype": "gauge"}) def spawn_worker(self): self.worker_age += 1 diff --git a/gunicorn/instrument/statsd.py b/gunicorn/instrument/statsd.py index e712c47ff..2d519c478 100644 --- a/gunicorn/instrument/statsd.py +++ b/gunicorn/instrument/statsd.py @@ -6,6 +6,7 @@ "Bare-bones implementation of statsD's protocol, client-side" import socket +import logging from gunicorn.glogging import Logger # Instrumentation constants @@ -50,30 +51,37 @@ def exception(self, msg, *args, **kwargs): # Special treatement for info, the most common log level def info(self, msg, *args, **kwargs): - """Log a given statistic if metric, value and type are present - """ - Logger.info(self, msg, *args, **kwargs) - 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 + self.log(logging.INFO, msg, *args, **kwargs) # skip the run-of-the-mill logs def debug(self, msg, *args, **kwargs): - Logger.debug(self, msg, *args, **kwargs) + self.log(logging.DEBUG, msg, *args, **kwargs) def log(self, lvl, msg, *args, **kwargs): - Logger.log(self, lvl, msg, *args, **kwargs) + """Log a given statistic if metric, value and type are present + """ + try: + 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 + + # Log to parent logger only if there is something to say + if msg is not None and len(msg) > 0: + Logger.log(self, lvl, msg, *args, **kwargs) + except Exception: + pass + # access logging def access(self, resp, req, environ, request_time): diff --git a/tests/test_010-statsd.py b/tests/test_010-statsd.py index aaf75dd5a..f2ba1a4e6 100644 --- a/tests/test_010-statsd.py +++ b/tests/test_010-statsd.py @@ -2,9 +2,17 @@ import t +try: + from cStringIO import StringIO +except ImportError: + from io import StringIO + +import logging + from gunicorn.config import Config from gunicorn.instrument.statsd import Statsd + class TestException(Exception): pass class MockSocket(object): @@ -38,10 +46,27 @@ def test_statsd_fail(): def test_instrument(): logger = Statsd(Config()) + # Capture logged messages + sio = StringIO() + logger.error_log.addHandler(logging.StreamHandler(sio)) logger.sock = MockSocket(False) + # 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(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(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(sio.getvalue(), "Blah\n") # log is unchanged logger.sock.reset() logger.critical("Boom")