Python如何在日志中隐藏明文密码

前言

在项目开发中，有的时候会遇到一些安全需求，用以提升程序整体的安全性，提高外来非法攻击的门槛，而在日志中隐藏明文密码打印便是最典型的安全需求之一。

在Python中，明文密码往往发生于命令执行参数、debug日志、依赖库打印等场景中。对于程序自身的明文密码打印，很轻易地就能通过修改相应代码行的方式修复，而对于非程序自身打印，比如依赖库、外部命令等，则比较棘手，无法通过直接修改代码的方式解决。其实，在Python中，logging日志模块提供了一些自定义方法以过滤特定字符串，绝大多数的Python程序均使用logging模块作为其日志记录系统，如果开发者已经得知相关明文密码打印的规则，且使用logging模块记录日志，那么使用在logging模块中过滤特定字符串的方法不失为一个很好的选择。

概念

logging日志模块是python的一个内置模块，该模块定义了一些函数和类，为上层应用程序或库实现了一个强大而又灵活的日志记录系统。

logging模块将日志的处理分为四个层次，分别是：

logger：logger向上层应用程序暴露接口，程序通过调用logger打印日志，比如logger.info，logger.error等等；
handler：handler用于将logger创建的日志记录输出至适合的目的地，比如标准输出、错误、文件等；
filter：filter对如何将日志记录输出提供了更细粒度的控制；
formatter：formatter指定了最终日志记录输出的格式。

如上，filter以及formatter层次均提供了对日志行为扩展的手段，针对明文密码打印问题，我们可以通过自定义filter或者formatter，使用特定规则过滤明文密码字段的方式实现。

LogRecord

LogRecord是日志的基本单元，每次应用程序调用Logger打印日志时，logging模块都会自动创建一个LogRecord实例，其记录了日志文本、参数、模块、行数乃至进程ID、线程ID等等有用的信息。

>>> type(record)
<class 'logging.LogRecord'>
>>> record.msg
'password=123456 %s %s'
>>> record.args
('1', '2')
>>> record.created
1697184354.6492243
>>> record.levelname
'INFO'
>>> record.name
'__main__'
>>> record.process
200

上面列出了一些LogRecord对象的属性，这些属性大部分也同样是最后格式化日志输出的参数。

filter

filter一般用作匹配并过滤部分日志，判断匹配条件的日志是否允许打印，它提供了一个filter方法，使用布尔值作为返回值，如果返回true则表示允许打印，否则表示不允许。

filter方法以LogRecord作为参数，这也表示除了过滤指定日志的功能以外，也能够对日志做更精细的控制。

class Filter(object):
    """
    Filter instances are used to perform arbitrary filtering of LogRecords.
    """
    def filter(self, record: LogRecord) -> bool:
        """
        Determine if the specified record is to be logged.

        Returns True if the record should be logged, or False otherwise.
        If deemed appropriate, the record may be modified in-place.
        """

formatter

formatter负责将LogRecord转化为最终的输出字符串，它主要是使用args来渲染msg，除此之外，如果LogRecord包含异常堆栈，那么也会打印出来。

formatter方法以LogRecord作为参数，并返回渲染处理后的字符串，当自定义formatter类时，我们能够既能够处理渲染前的LogRecord，也能修改渲染后的字符串。

class Formatter(object):
    """
    Formatter instances are used to convert a LogRecord to text.
    """
    def format(self, record: LogRecord) -> str:
        """
        Format the specified record as text.

        The record's attribute dictionary is used as the operand to a
        string formatting operation which yields the returned string.
        Before formatting the dictionary, a couple of preparatory steps
        are carried out. The message attribute of the record is computed
        using LogRecord.getMessage(). If the formatting string uses the
        time (as determined by a call to usesTime(), formatTime() is
        called to format the event time. If there is exception information,
        it is formatted using formatException() and appended to the message.
        """

使用formatter实现明文密码隐藏

import re
import logging
import logging.config

# 自定义formatter类
class SensitiveFormatter(logging.Formatter):
    """Formatter that removes sensitive information in urls."""
    @staticmethod
    def _mask_passwd(s) -> str:
        return re.sub(r'(?<=password=)\S+', r'***', s)

    def format(self, record) -> str:
        s = super().format(record)
        return self._mask_passwd(s)

LOGGING_CONFIG = {
    "version": 1,
    "formatters": {
        "default": {
            "()": SensitiveFormatter,
            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
        }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "default",
            "stream": "ext://sys.stdout"
        },
    },
    "loggers": {},
    "root": {
        "level": "DEBUG",
        "handlers": [
            "console",
        ]
    }
}

logging.config.dictConfig(LOGGING_CONFIG)
LOG = logging.getLogger(__name__)

LOG.info('password=123456')
# 2023-10-13 16:58:50,443 - __main__ - INFO - password=***

使用filter实现明文密码隐藏

import re
import logging
import logging.config

# 自定义filter类
class SensitiveFilter(logging.Filter):
    def __init__(self, patterns):
        super().__init__()
        self._patterns = patterns

    def _mask(self, msg):
        if not isinstance(msg, str):
            return msg
        for pattern in self._patterns:
               msg = re.sub(pattern, r'***', msg)
        return msg

    def filter(self, record):
        record.msg = self._mask(record.msg)
        if isinstance(record.args, dict):
            for k in record.args.keys():
                record.args[k] = self._mask(record.args[k])
        elif isinstance(record.args, tuple):
            record.args = tuple(self._mask(arg) for arg in record.args)
        return super().filter(record)

LOGGING_CONFIG = {
    "version": 1,
    "filters": {
        "default": {
            "()": SensitiveFilter,
            "patterns": [
                r'(?<=password=)\S+',
            ],
        },
    },
    "formatters": {
        "default": {
            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
        }
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "default",
            "filters": [
                "default",
            ],
            "stream": "ext://sys.stdout"
        },
    },
    "loggers": {},
    "root": {
        "level": "DEBUG",
        "handlers": [
            "console",
        ]
    }
}

logging.config.dictConfig(LOGGING_CONFIG)
LOG = logging.getLogger(__name__)

LOG.info('password=123456')
# 2023-10-13 16:59:22,545 - __main__ - INFO - password=***

附录

Hiding Sensitive Data from Logs with Python (relaxdiego.com)

logging — Logging facility for Python — Python 3.12.0 documentation

frankming