uvicorn日志清空问题以及uvicorn日志配置

uvicorn日志清空问题

1、配置:

uvicorn + starlette

2、现象描述:

当我使用uvicorn + starlette进行Python web开发的时候,本来想把所有的日志都打印到一个文件里面,于是我写了一个启动脚本,所有的日志都输出到log.txt里面:

$ more run_s 
nohup uvicorn server:app --host 0.0.0.0 --port 6786 > log.txt 2>&1 &

运行一段时间后,我发现log.txt里面的日志占了很大的磁盘空间,于是我就准备手动的清空log.txt文件,执行了下面的命令:

$ > log.txt

命令执行之后,输入ll查看一下最终结果,发现log.txt的大小确实变成了0,正准备满心欢喜的收工去喝杯小酒解解乏,基于程序员的敏感度,我进行了二次确认,就发送了一个新请求,待新请求出现后再次输入了ll命令检查日志文件,发现日志文件占用的磁盘大小又变回了为清空之前的模样,好像我们执行的清空命令毫无作用,赶紧查看一下log.txt的内容:

发现日志文件前半部分缺失内容被清空了,文件的尾部出现了我二次确认时发送的请求,神奇。

3、根因分析:

3.1、采用daphne + starlette验证

重复了上面的步骤,发现日志可以正常清空,于是排除starlette的问题,问题出现在uvicorn上

3.2、查看uvicorn的日志配置

默认情况下,uvicorn使用了logging.StreamHandler,流式写入日志,logging.StreamHandler 会记录文件写入位置,在下一次写入日志时会自动seek到上一次的位置再写新日志。由于日志已被清空,所以在上一次写入位置之前的内容全部为NUL,即0。

uvicorn按天输出访问日志配置

其实从一开始我就不应该使用默认的日志输出方式,而应该采用自定义的方式,比如一天生成一个文件,或者一小时生成一个文件,这样过期的文件直接删除,也不需要手动做清空操作。于是开始寻找解决方案。从上面的截图我们可以看到,uvicorn默认有个配置文件,仿照它来写即可。

1、日志配置文件:

uvicorn支持多种格式的配置文件,我们这里采用大家日常比较熟悉的格式:json,新建一个uvicorn_log.json:

{
  "version": 1,
  "disable_existing_loggers": "False",
  "formatters": {
    "default": {
      "()": "uvicorn.logging.DefaultFormatter",
      "fmt": "%(levelprefix)s %(message)s",
      "use_colors": "None"
    },
    "access": {
      "()": "uvicorn.logging.AccessFormatter",
      "fmt": "%(levelprefix)s %(client_addr)s - %(request_line)s %(status_code)s"
    }
  },
  "handlers": {
    "default": {
      "formatter": "default",
      "class": "logging.StreamHandler",
      "stream": "ext://sys.stderr"
    },
    "access": {
      "formatter": "access",
      "class": "logging.handlers.TimedRotatingFileHandler",
      "filename": "./access.log",
      "when": "MIDNIGHT",
      "interval": 1,
      "backupCount": 5,
      "level": "DEBUG"
    }
  },
  "loggers": {
    "uvicorn": {
      "handlers": [
        "default"
      ],
      "level": "INFO",
      "propagate":0
    },
    "uvicorn.error": {
      "handlers": [
        "default"
      ],
      "level": "INFO",
      "propagate":0
    },
    "uvicorn.access": {
      "handlers": [
        "access"
      ],
      "level": "INFO",
      "propagate":0
    }
  }
}

注意事项:

1、"propagate":0 这个地方需要配置为0,而不是False,因为代码里面是利用 if not 判断的

2、"when": "MIDNIGHT"这个地方如果你想每天生成一个文件,需要配置为MIDNIGHT,而不是D,配置为D是每隔24小时生成一个文件

2、日志文件使用

使用--log-config uvicorn_log.json来启动uvicorn即可

$ more run_s 
nohup uvicorn server:app --host 0.0.0.0 --port 6786 --log-config uvicorn_log.json > log.txt 2>&1 &

总结:

1、默认的uvicorn的日志清空存在BUG,建议不要使用

2、采用按一定的间隔来生成文件的策略更简单,让Python自己来维护日志文件的生成与清理