Python logger stops logging after uncaught exception

Question

The native python logger used by our flask app seems to stop writing to the log after an exception happens. The last entry logged before each stoppage is a message describing the exception. Typically the next message is one written by code in after_request but for cases where the logger stops, the after_request message is never written out.

Any idea what could be causing this?

Note: I originally posted this question on Serverfault (https://serverfault.com/questions/655683/python-logger-stops-logging) thinking it was an infrastructure issue. But now that we have narrowed the issue down to it occurring after an exception, this issue may be better suited for Stackoverflow.

Update [12/22/2015]:

Logger instantiation:

logging.addLevelName(Config.LOG_AUDIT_LEVEL_NUM, Config.LOG_AUDIT_LEVEL_NAME)

logger = logging.getLogger(Config.LOGGER_NAME)
logger.setLevel(Config.LOG_LEVEL)

handler = SysLogHandler(address='/dev/log', facility=SysLogHandler.LOG_LOCAL3)
handler.setLevel(Config.LOG_LEVEL)

formatter = log_formatter()
handler.setFormatter(formatter)
logger.addHandler(handler)

log_formatter:

class log_formatter(logging.Formatter):

    def __init__(self,
                 fmt=None,
                 datefmt=None,
                 json_cls=None,
                 json_default=_default_json_default):
        """
        :param fmt: Config as a JSON string, allowed fields;
               extra: provide extra fields always present in logs
               source_host: override source host name
        :param datefmt: Date format to use (required by logging.Formatter
            interface but not used)
        :param json_cls: JSON encoder to forward to json.dumps
        :param json_default: Default JSON representation for unknown types,
                             by default coerce everything to a string
        """

        if fmt is not None:
            self._fmt = json.loads(fmt)
        else:
            self._fmt = {}
        self.json_default = json_default
        self.json_cls = json_cls

        if 'extra' not in self._fmt:
            self.defaults = {}
        else:
            self.defaults = self._fmt['extra']

        try:
            self.source_host = socket.gethostname()
        except:
            self.source_host = ""

    def format(self, record):
        """
        Format a log record to JSON, if the message is a dict
        assume an empty message and use the dict as additional
        fields.
        """

        fields = record.__dict__.copy()
        aux_fields = [
            'relativeCreated', 'process', 'args', 'module', 'funcName', 'name',
            'thread', 'created', 'threadName', 'msecs', 'filename', 'levelno',
            'processName', 'pathname', 'lineno', 'levelname'
        ]
        for k in aux_fields:
            del fields[k]

        if isinstance(record.msg, dict):
            fields.update(record.msg)
            fields.pop('msg')
            msg = ""
        else:
            msg = record.getMessage()

        if 'msg' in fields:
            fields.pop('msg')

        if 'exc_info' in fields:
            if fields['exc_info']:
                formatted = tb.format_exception(*fields['exc_info'])
                fields['exception'] = formatted
            fields.pop('exc_info')

        if 'exc_text' in fields and not fields['exc_text']:
            fields.pop('exc_text')

        logr = self.defaults.copy()

        logr = {
            'timestamp': datetime.datetime.utcnow().strftime('%Y-%m-%dT%H:%M:%S.%fZ'),
            'host': self.source_host,
        }
        logr.update(self._build_fields(logr, fields))

        if msg:
            logr['message'] = msg

        something = json.dumps(logr, default=self.json_default, cls=self.json_cls)
        return something

    def _build_fields(self, defaults, fields):
        return dict(defaults.get('fields', {}).items() + fields.items())

Update [01/03/2015]:

Answering questions posted:

Is the application still working after the exception?

Yes, the application continues to run.

Which type of exception is raised and what's the cause of it?

Internal/custom exception. Logger has stopped due to different types of exceptions.

Are you using threads in you application?

Yes, the app is threaded by gunicorn.

How is the logging library used?

We are using default FileHandler, SysLogHandler and a custom formatter (outputs JSON)

Does it log on a file? Does it use log rotation?

Yes, it logs to a file, but no rotation.

Answer 1

In regards to after_request, from the docs:

As of Flask 0.7 this function might not be executed at the end of the request in case an unhandled exception occurred.

And as for your logging issue, it may be that your debug flag is set to true, which would cause the debugger to kick in and possibly stop the logging.

References:
(http://flask.pocoo.org/docs/0.10/api/#flask.Flask.after_request)
(http://flask.pocoo.org/docs/0.10/errorhandling/#working-with-debuggers)