Python gunicorn duplicate logs

4/17/2018

I wrote a module file that formats logs according to Google Stackdriver json standards. For doing so, I followed this guide.

This is my module:

import logging
import sys
from pythonjsonlogger import jsonlogger


class _MaxLevelFilter(object):
    def __init__(self, highest_log_level):
        self._highest_log_level = highest_log_level

    def filter(self, log_record):
        return log_record.levelno <= self._highest_log_level


class StackdriverJsonFormatter(jsonlogger.JsonFormatter, object):
    def __init__(self, fmt="%(levelname) %(message)", style='%', *args, **kwargs):
        jsonlogger.JsonFormatter.__init__(self, fmt=fmt, *args, **kwargs)

    def process_log_record(self, log_record):
        log_record['severity'] = log_record['levelname']
        del log_record['levelname']
        return super(StackdriverJsonFormatter, self).process_log_record(log_record)


formatter = StackdriverJsonFormatter()

"""
//////////////// INFO HANDLER ///////////////
"""
# A handler for low level logs that should be sent to STDOUT
info_handler = logging.StreamHandler(sys.stdout)
info_handler.setFormatter(formatter)
info_handler.setLevel(logging.INFO)
info_handler.addFilter(_MaxLevelFilter(logging.WARNING))
"""----------------------------------------"""

"""
//////////////// ERROR HANDLER ///////////////
"""
# A handler for high level logs that should be sent to STDERR
error_handler = logging.StreamHandler(sys.stderr)
error_handler.setFormatter(formatter)
error_handler.setLevel(logging.ERROR)
"""----------------------------------------"""

try:
    root_logger = logging.getLogger('gunicorn.error')
except:
    root_logger = logging.getLogger()
# root logger default level is WARNING, so we'll override to be DEBUG
root_logger.addHandler(info_handler)
root_logger.addHandler(error_handler)

It logs things formatted, although it duplicates the log one being json formatted and the other being text formatted:

[2018-04-17 12:40:48 +0000] [24255] [INFO] This is an INFO
{"message": "This is an INFO", "severity": "INFO"}
[2018-04-17 12:40:48 +0000] [24255] [ERROR] This is an ERROR
{"message": "This is an ERROR", "severity": "ERROR"}

Any ideas on what I might be doing wrong?

-- Mauricio
gunicorn
kubernetes
logging
python

1 Answer

8/22/2019

I was getting the ERROR tag on GCP StackDriver for all the logs. I used the below code and It worked. All the logs are correctly tagged without any duplicate logs.

class StackDriverJsonFormatter(jsonlogger.JsonFormatter, object):
    def __init__(self, fmt="%(levelname) %(message)", style='%', *args, **kwargs):
        jsonlogger.JsonFormatter.__init__(self, fmt=fmt, *args, **kwargs)
    def process_log_record(self, log_record):
        log_record['severity'] = log_record['levelname']
        del log_record['levelname']
        return super(StackDriverJsonFormatter, self).process_log_record(log_record)

handler = logging.StreamHandler(sys.stdout)
formatter = StackDriverJsonFormatter()
handler.setFormatter(formatter)
log= logging.getLogger()
log.addHandler(handler)
log.setLevel(logging.INFO)
-- Joel K Thomas
Source: StackOverflow