V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
推荐学习书目
Learn Python the Hard Way
Python Sites
PyPI - Python Package Index
http://diveintopython.org/toc/index.html
Pocoo
值得关注的项目
PyPy
Celery
Jinja2
Read the Docs
gevent
pyenv
virtualenv
Stackless Python
Beautiful Soup
结巴中文分词
Green Unicorn
Sentry
Shovel
Pyflakes
pytest
Python 编程
pep8 Checker
Styles
PEP 8
Google Python Style Guide
Code Style from The Hitchhiker's Guide
f1ynnv2
V2EX  ›  Python

多进程使用 logging 把日志存储到不同文件的实践

  •  1
     
  •   f1ynnv2 · 2023-05-31 08:21:03 +08:00 · 3475 次点击
    这是一个创建于 393 天前的主题,其中的信息可能已经有所发展或是发生改变。

    之前用 python 写单进程多线程的应用时,使用 logging 记录日志写到同一个文件很正常,最近写了个多进程多线程的应用使用 logging 记录日志到同一个文件时就开始出现问题了,主要就是基于时间的文件归档时会出 bug 。

    简单搜了一下也找到了原因:logging 是线程安全但是进程不安全,官方推荐使用 queue 或者 socket 来实现多进程日志记录到同一个文件,或者自己修改 doRollOver 相关的操作。

    我想问的问题是,我其实并没有上面“多进程存储日志到一个日志文件”的需求,相反我是希望把每个进程的日志单独存储为一个文件的,但是实践上感觉不太方便,以下是详情:

    之前写单进程多线程时,只要在 logging 的封装模块里初始化一个全局的 logger ,其它所有模块不管是在哪个线程里,只要 import 一下这个 logger 就可以直接拿来用。 但是现在写多进程多线程的时候问题就出现了:

    • 如果仍然按照上述方法,那么不同进程 import 这个 logger 后,在自己的变量空间里虽然是互不干扰,但是在底层仍然操作同一个文件,因此会导致上面提到按时间归档的问题;
    • 有一个解决方法是在每个进程的启动函数里初始化一个专属的 logger ,指定不同的存储文件,然后通过参数的方式传递给调用的所有模块 /函数,让这些模块 /函数直接使用这个 logger 。技术上可行,但是实践上非常不优雅,调用的每个子模块都要传递这个 logger 参数。

    因为想问问大家,这个需求“多进程通过 logging 写日志到各自文件”是否有更优雅的实践?如果没的话,最后也只能回归官方通过 socket/queue 的方案来写单个文件了。

    第 1 条附言  ·  2023-05-31 08:55:39 +08:00
    又想到另一个方案:

    在每个函数里重新获取一次 logger ,这个 logger 在函数里初始化时根据当前函数所在的进程名称来初始化使用的文件。

    这个方案和原来单进程多线程相比仍然不够方便:之前单进程多线程的环境下,每个模块只要 import 一下 logger 这个全局变量,模块里的任何函数都能直接用。目前看来想要实现这种方便,是不是只能回归官方的 socket/queue 方案了。
    第 2 条附言  ·  2023-05-31 11:42:25 +08:00
    目前使用#9 楼的方案,最终能实现多进程多线程与单进程多线程相同的使用方式:每个模块 import 一下封装好的 logger 模块里初始化好的全局 logger ,不管在哪个进程的线程里都可以直接使用 loggger.
    十分感谢。
    第 3 条附言  ·  2023-05-31 13:41:10 +08:00
    另外,4 楼的 concurrent-log-handler 也可以 100%满足要求,效果和 9 楼的方案是一样的。
    只要在封装 logger 的地方对应把 TimedRotatingFileHandler 换成 ConcurrentTimedRotatingFileHandler 就可以了。

    4 楼和 9 楼的方案本质上应该都是一样的,重写了 doRollOver 过程,确实可以完美的在任何模块中 import 个 logger ,所有模块内的方法直接使用。我先回归单个日志文件了,技术来说也可以在 logger 里判断一下当前属于哪个进程,来使用单独的日志文件。
    35 条回复    2023-05-31 22:11:29 +08:00
    Three2
        1
    Three2  
       2023-05-31 08:28:35 +08:00   ❤️ 1
    每个进程的日志名字不同不就完事了
    f1ynnv2
        2
    f1ynnv2  
    OP
       2023-05-31 08:45:06 +08:00
    @Three2 #1 可能我没表达清楚,我最后的问题其实就是“如何优雅的实现每个进程使用不同日志名字”。目前只想到这一个办法,但是不够优雅:

    -------

    每个进程的启动函数里初始化一个专属的 logger ,指定不同的存储文件,然后通过参数的方式传递给调用的所有模块 /函数,让这些模块 /函数直接使用这个 logger 。技术上可行,但是实践上非常不优雅,调用的每个子模块都要传递这个 logger 参数。
    gulu
        3
    gulu  
       2023-05-31 08:48:06 +08:00 via iPhone
    全局的 logger 定义为 None ,第一次用的时候再初始化它。
    feihuaxx010
        4
    feihuaxx010  
       2023-05-31 08:57:24 +08:00   ❤️ 1
    试试 concurrent-log-handler
    lucifer69
        5
    lucifer69  
       2023-05-31 09:12:00 +08:00
    我也遇到过这个问题,是按你想到的另一个方案做的。import 封装的 logger 模块,里面有个方法是 get_logger ,要使用的地方传递 logger 名字,模块里面有同名就复用,没同名就再初始化一个。用起来确实麻烦
    encro
        6
    encro  
       2023-05-31 09:15:02 +08:00
    chatgpt:

    在多进程程序中,为每个进程创建不同的 logger ,并将其 log 输出到不同的文件中。例如:

    ```
    from multiprocessing import Process
    import logging

    def process1():
    logger = logging.getLogger('process1')
    logger.setLevel(logging.DEBUG)
    # 创建文件处理器
    file_handler = logging.FileHandler('process1.log')
    file_handler.setLevel(logging.DEBUG)
    # 设置格式
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    file_handler.setFormatter(formatter)
    # 将文件处理器添加到 logger
    logger.addHandler(file_handler)

    logger.debug('Process 1 started')

    def process2():
    logger = logging.getLogger('process2')
    logger.setLevel(logging.DEBUG)
    # 创建文件处理器
    file_handler = logging.FileHandler('process2.log')
    file_handler.setLevel(logging.DEBUG)
    # 设置格式
    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
    file_handler.setFormatter(formatter)
    # 将文件处理器添加到 logger
    logger.addHandler(file_handler)

    logger.debug('Process 2 started')

    if __name__ == '__main__':
    p1 = Process(target=process1)
    p2 = Process(target=process2)
    p1.start()
    p2.start()
    p1.join()
    p2.join()
    ```
    encro
        7
    encro  
       2023-05-31 09:17:50 +08:00
    简单来说可以定一个 getlogger 方法,传递线程 id 进去,让后在方法里面调用 logging.FileHandler(线程 id.log)写到不同文件
    sujin190
        8
    sujin190  
       2023-05-31 09:25:33 +08:00
    如果你日志是有时许的,每个进程写单独文件,看日志的时候还不累死了,不就是时间的文件归档有问题么,修改下 doRollOver 加个锁就是了呗,也不是啥麻烦的事情
    sujin190
        9
    sujin190  
       2023-05-31 09:30:41 +08:00   ❤️ 1
    https://gist.github.com/snower/adcf300f3daff99549dbe1949982a5dc

    我们项目就是重写了 doRollOver ,使用文件锁来处理,这样就算多个进程是独立创建的也没有问题,只是似乎不能在 windows 上用,而且这个函数只有在需要重新创建日志文件的时候才会调用,正常写日志的时候不会有影响,所以也没啥性能问题
    f1ynnv2
        10
    f1ynnv2  
    OP
       2023-05-31 09:32:25 +08:00
    @sujin190 #8 其实多进程下,不仅仅是按时间归档的问题,如果是高并发的时候,写日志到一个文件也有小概率出现日志混乱的问题,尤其是日志内容比较大的情况。
    todd7zhang
        11
    todd7zhang  
       2023-05-31 09:42:02 +08:00
    子进程启动的地方,先 init_logger(), 这里面只需要设置 root logger 的 file handler 。然后其他地方使用各自 py 文件下的 logger 啊
    BingoXuan
        12
    BingoXuan  
       2023-05-31 09:43:20 +08:00
    多进程模式下,我是单独开一个 daemon 进程保存 log 的,用 zmq 的 pub 和 sub 模式来通信
    sujin190
        13
    sujin190  
       2023-05-31 09:44:22 +08:00
    @f1ynnv2 #10 确定不是写的问题,我们十多个进程每天写入数十 G 的时候没发现有错行的问题,也这样运行好多年了,没发现啥异常
    todd7zhang
        14
    todd7zhang  
       2023-05-31 09:46:20 +08:00
    ```python
    # example.py
    import logging
    import multiprocessing
    import os

    _logger = logging.getLogger(__name__)

    def init_logging():
    # create logger
    root_logger = logging.getLogger()
    root_logger.setLevel(logging.DEBUG)

    # create file handler
    log_file = 'my_log_{}.log'.format(os.getpid())
    file_handler = logging.FileHandler(log_file)
    file_handler.setLevel(logging.DEBUG)

    # create formatter
    formatter = logging.Formatter('%(asctime)s - %(process)d - %(name)s - %(levelname)s - %(message)s')
    file_handler.setFormatter(formatter)

    # add file handler to logger
    root_logger.addHandler(file_handler)



    def start():
    init_logging()
    from . import file1, file2
    file1.say_hello()
    file2.say_hello()


    def main():
    processes = []
    for i in range(4):
    p = multiprocessing.Process(target=start)
    processes.append(p)
    p.start()

    for p in processes:
    p.join()

    if __name__ == '__main__':
    main()


    # file1.py
    import logging
    _logger = logging.getLogger(__name__)

    def say_hello():
    _logger.info("this is hello message from file1.py")


    # file2.py
    import logging
    _logger = logging.getLogger(__name__)

    def say_hello():
    _logger.info("this is hello message from file2.py")

    ```
    f1ynnv2
        15
    f1ynnv2  
    OP
       2023-05-31 09:46:48 +08:00
    @sujin190 #9 感谢,我来研究一下。
    Trim21
        16
    Trim21  
       2023-05-31 09:48:04 +08:00 via Android
    loguru
    lolizeppelin
        17
    lolizeppelin  
       2023-05-31 09:51:07 +08:00
    linux 下 append 写入,是原子性,多进程安全的
    你的问题应该不是多进程的安全问题

    基于时间的文件归档有问题的话,多半是你们滚日志的时候只有主进程做了重新打开日志文件的操作

    正确流程是发信号到进程组,所有进程组内所有进程都重新打开日志文件
    todd7zhang
        18
    todd7zhang  
       2023-05-31 10:01:29 +08:00
    todd7zhang
        19
    todd7zhang  
       2023-05-31 10:10:32 +08:00
    我认为,日志滚动不应该让 python 来做,python 就直接 logging 到 stdout 。
    外面用 supervisor 来守护,同时 supervisor 来收集日志到文件,最后由 logrotate 做每天的日志滚动。
    xyjincan
        20
    xyjincan  
       2023-05-31 10:14:42 +08:00
    写日志用追加模式,linux 中,底层追加模式写文件用的是系统调用,具有原子性
    g5tf87
        21
    g5tf87  
       2023-05-31 11:00:18 +08:00
    lolizeppelin xyjincan 说的是对的,但是要注意原子性也是有大小限制的,比如某些系统 4k 的 append 是原子。
    可以参考 nginx 的实现方式,append+信号通知重新打开文件
    billzhuang
        22
    billzhuang  
       2023-05-31 11:08:03 +08:00
    写到 stdout 或 stderr ,然后用 flunetd 来收集。
    xuanbg
        23
    xuanbg  
       2023-05-31 11:09:23 +08:00
    什么年代了,还在代码中写日志到文件。。。搞一套 ELK 之类的日志平台又不费什么事。
    NoOneNoBody
        24
    NoOneNoBody  
       2023-05-31 11:20:24 +08:00
    ?
    怎么我就没读明白需求呢
    不同进程不同 log file 这个是明白了,然后是不希望每个进程都实例 化一个 logger ?只使用一个全局 logger 对象?

    每进程一个 log 实例是最清晰的,因为消息也是分开的,没必要全局一起处理,除非需求是按级别,如 error 为全局消息

    如果必须需要全局单实例,可以把 output 方法以参数分开就可以了,没必要初始化就设定 output 路径
    “优雅一点”,就用别名方法 alias ,用 funtools.partical 或闭包把参数带上
    nicebird
        25
    nicebird  
       2023-05-31 11:26:34 +08:00
    日志文件名字 增加进程名 & 进程 id
    Nem0
        26
    Nem0  
       2023-05-31 11:36:24 +08:00   ❤️ 1
    我用的 loguru 中的 filter ,不同文件的 logger 有不同的日志头,以此写入不同文件
    f1ynnv2
        27
    f1ynnv2  
    OP
       2023-05-31 11:39:07 +08:00
    @NoOneNoBody #24 每个进程初始化一个 logger 没问题,但是某个进程的调用的所有模块如何使用这个进程独立的 logger 就是个问题了,要么通过传参的方式把 logger 传给子函数,要么在每个子函数里重新获取一下 logger ,这不就没有单进程多线程那种模块头部 import ,全模块随便用的方便了嘛。
    f1ynnv2
        28
    f1ynnv2  
    OP
       2023-05-31 11:41:17 +08:00
    @sujin190 #9 特意来感谢一下,最后还是修改了 doRollOver 这种方案,最终能实现多进程多线程与单进程多线程相同的使用方式:每个模块 import 一下封装好的 logger 模块里初始化好的全局 logger ,不管在哪个进程的线程里都可以直接使用 loggger.
    ruanimal
        29
    ruanimal  
       2023-05-31 11:45:35 +08:00
    又是 x-y 问题,你直接打到一个文件不就行了吗, 看 #4 的 concurrent-log-handler 库就行了
    f1ynnv2
        30
    f1ynnv2  
    OP
       2023-05-31 11:47:53 +08:00
    @todd7zhang #14 这个方案是给每个模块分配一个日志文件,确实可行
    NoOneNoBody
        31
    NoOneNoBody  
       2023-05-31 12:14:25 +08:00
    @f1ynnv2 #27
    所以我说没读明白

    from mylog import Logger

    def worker(logpath):
    worker_log = Logger(savepath=logpath)
    ...

    进程入口就是 worker ,传参一次就可以了,进程内其他什么都是调用 worker_log ,不需要再传参数了,这事应该不涉及进程安全,只有跨进程的才需要考虑进程安全

    你简单说说某个子模块是如何调用 logger 的,根据#28 ,我觉得单个进程内只是 namespace 的问题
    f1ynnv2
        32
    f1ynnv2  
    OP
       2023-05-31 13:36:51 +08:00
    @NoOneNoBody #31 某个模块是可以被多个进程调用的,实际上在某个模块由于和进程入口不在同一个文件里,所以必然不是同一个 namespace ,要么通过传参的方式把 logger 传起来,要么在子模块的函数里重新初始一次 logger ,还是麻烦哦。
    todd7zhang
        33
    todd7zhang  
       2023-05-31 14:45:58 +08:00
    @f1ynnv2 看完你的回复之后,我感觉你对 python 的 logger 理解有误。
    每个 py 文件都应该有自己 logger, 每个 logger 不需要自己来输出到文件,你不需要也不应该从其他模块导入一个的 logger, 它最后都会把 log record propagate 到 root logger
    你只要对 root logger 配置 handler 和 formatter 就行。
    然后,我的代码是给每个子进程配置了他们 root logger ,file1.pyfile2.py 并没有额外指定日志输出文件。
    f1ynnv2
        34
    f1ynnv2  
    OP
       2023-05-31 15:11:31 +08:00
    @todd7zhang #33 按照你的代码来说的话, 确实。在整个 app 入口处初始一个 root logger ,然后每个模块里获取一下自己的 logger ,这个 logger 会使用 root logger 的配置。虽然不是我想要的那种每个模块 import 一下就直接用,但是你这种方法也挺简洁。如果没 4 楼和 9 楼的方案,确实可以用你的这种方案。
    ClericPy
        35
    ClericPy  
       2023-05-31 22:11:29 +08:00
    去年用系统自带的 logging 里的 Socket handler 做客户端, asyncio 自带的 Socket server + reuse_port 做服务端做了个多核日志服务, 分布式打过来的日志能扛的并发让我惊讶... asyncio 没加 uvloop 就超顶了, 切到 Python3.11 和 uvloop, 性能高的离谱...

    服务端多核通信没走跨进程队列, 走的 asyncio 自带的 Unix domain Socket, 以前一直以为会扛不住, 结果才三个 CPU 就扛住了几万并发, CPU 使用率才 30% 多... 过分低估 Python 在 IO 密集时候的实力了, 连 pypy 都没上呢
    关于   ·   帮助文档   ·   博客   ·   API   ·   FAQ   ·   实用小工具   ·   4990 人在线   最高记录 6679   ·     Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 · 27ms · UTC 09:33 · PVG 17:33 · LAX 02:33 · JFK 05:33
    Developed with CodeLauncher
    ♥ Do have faith in what you're doing.