Rework logging to allow for empty log message while pushing metrics

This commit is contained in:
Alexis Le-Quoc 2014-08-03 17:15:13 -04:00
parent 2753aac65b
commit bc2e132bce
3 changed files with 56 additions and 23 deletions

View File

@ -482,10 +482,10 @@ class Arbiter(object):
(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

View File

@ -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 @@ class Statsd(Logger):
# 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):

View File

@ -2,9 +2,17 @@ from datetime import timedelta
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")