nonebot / nonebot2

跨平台 Python 异步聊天机器人框架 / Asynchronous multi-platform chatbot framework written in Python
https://nonebot.dev
MIT License
5.97k stars 555 forks source link

Bug: `hook`函数`on_shutdown`在`Windows`上无法正常工作 #1654

Closed shoucandanghehe closed 1 year ago

shoucandanghehe commented 1 year ago

描述问题:

on_shutdown装饰的函数 在Windows上 不会在停止bot时 运行

如何复现?

  1. 写一个函数并应用on_shutdown装饰器
  2. 在Windows上运行nb
  3. Ctrl+C
  4. See error

期望的结果

应用on_shutdown装饰器的函数被运行

环境信息:

协议端信息:

截图或日志

Windows:

01-31 06:27:33 [INFO] nonebot | OneBot V11 | Bot ********** connected
01-31 06:27:33 [INFO] logging | connection open
01-31 06:27:37 [INFO] logging | Stopping reloader process [19532]

WSL@Ubuntu 22.04.1:

01-31 06:27:55 [INFO] nonebot | OneBot V11 | Bot ********** connected
01-31 06:27:55 [INFO] websockets | connection open
^C01-31 06:27:56 [INFO] uvicorn | Shutting down
01-31 06:27:56 [WARNING] nonebot | OneBot V11 | WebSocket for Bot ********** closed by peer
01-31 06:27:56 [INFO] websockets | connection closed
01-31 06:27:56 [INFO] uvicorn | Waiting for application shutdown.
01-31 06:27:56 [DEBUG] test | close
01-31 06:27:56 [INFO] uvicorn | Application shutdown complete.
01-31 06:27:56 [INFO] uvicorn | Finished server process [4927]
01-31 06:27:56 [INFO] uvicorn | Stopping reloader process [4897]

代码示例:

from nonebot import get_driver
from nonebot.log import logger

driver = get_driver()

@driver.on_shutdown
async def do_something():
    logger.debug('close')
shoucandanghehe commented 1 year ago

补充: Windows中的另一种日志:

01-31 06:40:45 [INFO] nonebot | OneBot V11 | Bot ********** connected
01-31 06:40:45 [INFO] logging | connection open
01-31 06:40:46 [INFO] logging | Shutting down
01-31 06:40:46 [WARNING] nonebot | OneBot V11 | WebSocket for Bot ********** closed by peer
01-31 06:40:46 [INFO] logging | connection closed
01-31 06:40:46 [INFO] logging | Stopping reloader process [28588]

两种情况似乎是随机出现的,但是都没有运行on_shutdown函数

yanyongyu commented 1 year ago

on_shutdown不会被运行是因为uvicorn的bug至今仍未合并https://github.com/encode/uvicorn/pull/1584

yanyongyu commented 1 year ago

nb-cli reload 模式目前已在最新 none 驱动器上可用,其他驱动器需要等待 encode/uvicorn#1909 合并后可用。

Kludex commented 1 year ago

on_shutdown will not be run because uvicorn's bug has not yet merged encode/uvicorn#1584

Can you confirm that PR works for you?

Hope my translator is translating right here :sunglasses: :+1:

yanyongyu commented 1 year ago

@shoucandanghehe 测一下 encode/uvicorn#1584 版本的 uvicorn 能否正确运行 shutdown?

he0119 commented 1 year ago

我试了一下 pip install git+https://github.com/StarHeartHunt/uvicorn.git@bug/fix-shutdown-event-on-windows-in-hot-reloader,一切正常了。

测试代码:

@driver.on_startup
async def _():
    print("startup")

@driver.on_shutdown
async def _():
    print("shutdown")
    await asyncio.sleep(3)
    print("after sleep")

日志:

❯ uvicorn bot:app --reload  
INFO:     Will watch for changes in these directories: ['C:\\Users\\hmy01\\Works\\Working\\Bot\\nonebot-plugin-test']
INFO:     Uvicorn running on http://127.0.0.1:8000 (Press CTRL+C to quit)
INFO:     Started reloader process [16816] using WatchFiles
03-24 18:35:18 [SUCCESS] nonebot | NoneBot is initializing...
03-24 18:35:18 [INFO] nonebot | Current Env: prod
03-24 18:35:18 [DEBUG] nonebot | Loaded Config: {'driver': '~fastapi', 'host': IPv4Address('127.0.0.1'), 'port': 8080, 'log_level': 'DEBUG', 'api_timeout': 30.0, 'superusers': {'123456'}, 'nickname': set(), 'command_start': {'/'}, 'command_sep': {'.'}, 'session_expire_timeout': datetime.timedelta(seconds=120)}        
03-24 18:35:18 [DEBUG] nonebot | OneBot V12 | Model for key "" <class 'nonebot.adapters.onebot.v12.event.BotEvent'> is overridden by <class 'nonebot.adapters.onebot.v12.event.Event'>
03-24 18:35:18 [SUCCESS] nonebot | Succeeded to import "test"
03-24 18:35:18 [SUCCESS] nonebot | Succeeded to import "simple"
03-24 18:35:18 [SUCCESS] nonebot | Succeeded to import "sub2"
03-24 18:35:18 [SUCCESS] nonebot | Succeeded to import "sub"
03-24 18:35:18 [SUCCESS] nonebot | Succeeded to import "tree"
INFO:     Started server process [17752]
INFO:     Waiting for application startup.
startup
INFO:     Application startup complete.
WARNING:  WatchFiles detected changes in 'src\plugins\test.py'. Reloading...
INFO:     Shutting down
INFO:     Waiting for application shutdown.
shutdown
after sleep
INFO:     Application shutdown complete.
INFO:     Finished server process [17752]
03-24 18:35:27 [SUCCESS] nonebot | NoneBot is initializing...
03-24 18:35:27 [INFO] nonebot | Current Env: prod
03-24 18:35:27 [DEBUG] nonebot | Loaded Config: {'driver': '~fastapi', 'host': IPv4Address('127.0.0.1'), 'port': 8080, 'log_level': 'DEBUG', 'api_timeout': 30.0, 'superusers': {'123456'}, 'nickname': set(), 'command_start': {'/'}, 'command_sep': {'.'}, 'session_expire_timeout': datetime.timedelta(seconds=120)}        
03-24 18:35:27 [SUCCESS] nonebot | Succeeded to import "sub2"
03-24 18:35:27 [SUCCESS] nonebot | Succeeded to import "sub"
03-24 18:35:27 [SUCCESS] nonebot | Succeeded to import "simple"
03-24 18:35:27 [SUCCESS] nonebot | Succeeded to import "tree"
03-24 18:35:27 [DEBUG] nonebot | OneBot V12 | Model for key "" <class 'nonebot.adapters.onebot.v12.event.BotEvent'> is overridden by <class 'nonebot.adapters.onebot.v12.event.Event'>
03-24 18:35:27 [SUCCESS] nonebot | Succeeded to import "test"
INFO:     Started server process [14756]
INFO:     Waiting for application startup.
startup
INFO:     Application startup complete.
INFO:     Shutting down
INFO:     Waiting for application shutdown.
shutdown
after sleep
INFO:     Application shutdown complete.
INFO:     Finished server process [14756]
INFO:     Stopping reloader process [16816]
yanyongyu commented 1 year ago

该问题已在 https://github.com/encode/uvicorn/pull/1584https://github.com/encode/uvicorn/pull/1909 解决

Kludex commented 1 year ago

Do we need to make a release already, or it can wait?

yanyongyu commented 1 year ago

Do we need to make a release already, or it can wait?

This is not a critical issue but this fix will allow developers using windows to test asgi applications correctly, so take your time to release. :)