🔊 add more logs

nonebot/__init__.py

@@ -1,7 +1,6 @@
 #!/usr/bin/env python3
 # -*- coding: utf-8 -*-
 
-import logging
 import importlib
 from nonebot.typing import Bot, Dict, Type, Union, Driver, Optional, NoReturn
 
@@ -84,7 +83,7 @@ def get_asgi():
     return driver.asgi
 
 
-def get_bots() -> Dict[str, Bot]:
+def get_bots() -> Union[NoReturn, Dict[str, Bot]]:
     """
     :说明:
 
@@ -146,26 +145,29 @@ def init(*, _env_file: Optional[str] = None, **kwargs):
 
     """
     global _driver
-    env = Env()
+    if not _driver:
-    logger.opt(
+        logger.debug("NoneBot is initializing...")
-        colors=True).debug(f"Current <y><b>Env: {env.environment}</b></y>")
+        env = Env()
-    config = Config(**kwargs, _env_file=_env_file or f".env.{env.environment}")
+        logger.opt(
+            colors=True).debug(f"Current <y><b>Env: {env.environment}</b></y>")
+        config = Config(**kwargs,
+                        _env_file=_env_file or f".env.{env.environment}")
 
-    default_filter.level = "DEBUG" if config.debug else "INFO"
+        default_filter.level = "DEBUG" if config.debug else "INFO"
-    logger.opt(
+        logger.opt(
-        colors=True).debug(f"Loaded <y><b>Config</b></y>: {config.dict()}")
+            colors=True).debug(f"Loaded <y><b>Config</b></y>: {config.dict()}")
 
-    DriverClass: Type[Driver] = getattr(importlib.import_module(config.driver),
+        DriverClass: Type[Driver] = getattr(
-                                        "Driver")
+            importlib.import_module(config.driver), "Driver")
-    _driver = DriverClass(env, config)
+        _driver = DriverClass(env, config)
 
-    # register build-in adapters
+        # register build-in adapters
-    _driver.register_adapter("cqhttp", CQBot)
+        _driver.register_adapter("cqhttp", CQBot)
 
-    # load nonebot test frontend if debug
+        # load nonebot test frontend if debug
-    if config.debug and nonebot_test:
+        if config.debug and nonebot_test:
-        logger.debug("Loading nonebot test frontend...")
+            logger.debug("Loading nonebot test frontend...")
-        nonebot_test.init()
+            nonebot_test.init()
 
 
 def run(host: Optional[str] = None,
@@ -195,6 +197,7 @@ def run(host: Optional[str] = None,
         nonebot.run(host="127.0.0.1", port=8080)
 
     """
+    logger.info("Running NoneBot...")
     get_driver().run(host, port, *args, **kwargs)
 
 

nonebot/adapters/cqhttp.py

@@ -27,6 +27,10 @@ from nonebot.typing import overrides, Driver, WebSocket, NoReturn
 from nonebot.adapters import BaseBot, BaseEvent, BaseMessage, BaseMessageSegment
 
 
+def log(level: str, message: str):
+    return logger.opt(colors=True).log(level, "<m>CQHTTP</m> | " + message)
+
+
 def escape(s: str, *, escape_comma: bool = True) -> str:
     """
     对字符串进行 CQ 码转义。
@@ -109,7 +113,7 @@ def _check_nickname(bot: "Bot", event: "Event"):
                       re.IGNORECASE)
         if m:
             nickname = m.group(1)
-            logger.debug(f"User is calling me {nickname}")
+            log("DEBUG", f"User is calling me {nickname}")
             event.to_me = True
             first_msg_seg.data["text"] = first_text[m.end():]
 
@@ -200,6 +204,7 @@ class Bot(BaseBot):
                 bot = self.driver.bots[str(self_id)]
                 return await bot.call_api(api, **data)
 
+        log("DEBUG", f"Calling API <y>{api}</y>")
         if self.type == "websocket":
             seq = ResultStore.get_seq()
             await self.websocket.send({
@@ -403,7 +408,7 @@ class MessageSegment(BaseMessageSegment):
     @overrides(BaseMessageSegment)
     def __init__(self, type: str, data: Dict[str, Union[str, list]]) -> None:
         if type == "text":
-            data["text"] = unescape(data["text"])
+            data["text"] = unescape(data["text"])  # type: ignore
         super().__init__(type=type, data=data)
 
     @overrides(BaseMessageSegment)
@@ -413,7 +418,9 @@ class MessageSegment(BaseMessageSegment):
 
         # process special types
         if type_ == "text":
-            return escape(data.get("text", ""), escape_comma=False)
+            return escape(
+                data.get("text", ""),  # type: ignore
+                escape_comma=False)
 
         params = ",".join(
             [f"{k}={escape(str(v))}" for k, v in data.items() if v is not None])
@@ -449,7 +456,7 @@ class MessageSegment(BaseMessageSegment):
 
     @staticmethod
     def forward(id_: str) -> "MessageSegment":
-        logger.warning("Forward Message only can be received!")
+        log("WARNING", "Forward Message only can be received!")
         return MessageSegment("forward", {"id": id_})
 
     @staticmethod

nonebot/drivers/fastapi.py

@@ -84,18 +84,9 @@ class Driver(BaseDriver):
         LOGGING_CONFIG = {
             "version": 1,
             "disable_existing_loggers": False,
-            # "formatters": {
-            #     "default": {
-            #         "()": "logging.Formatter",
-            #         "fmt": "[%(asctime)s %(name)s] %(levelname)s: %(message)s",
-            #     },
-            # },
             "handlers": {
                 "default": {
                     "class": "nonebot.log.LoguruHandler",
-                    # "formatter": "default",
-                    # "class": "logging.StreamHandler",
-                    # "stream": "ext://sys.stdout",
                 },
             },
             "loggers": {
@@ -201,6 +192,9 @@ class Driver(BaseDriver):
 
         await ws.accept()
         self._clients[x_self_id] = bot
+        logger.opt(colors=True).info(
+            f"WebSocket Connection from <y>{adapter.upper()} "
+            f"Bot {x_self_id}</y> Accepted!")
 
         try:
             while not ws.closed:

nonebot/log.py

@@ -74,9 +74,9 @@ class LoguruHandler(logging.Handler):
 logger.remove()
 default_filter = Filter()
 default_format = (
-    "<g>{time:MM-DD HH:mm:ss}</g>|"
+    "<g>{time:MM-DD HH:mm:ss}</g> "
-    "<lvl>{level: ^8}</lvl>|"
+    "[<lvl>{level}</lvl>] "
-    "<c><u>{name}</u></c>| "
+    "<c><u>{name}</u></c> | "
     # "<c>{function}:{line}</c>| "
     "{message}")
 logger.add(sys.stdout,

nonebot/matcher.py

@@ -1,6 +1,7 @@
 #!/usr/bin/env python3
 # -*- coding: utf-8 -*-
 
+from nonebot.log import logger
 import typing
 import inspect
 from functools import wraps
@@ -19,9 +20,21 @@ current_bot: ContextVar = ContextVar("current_bot")
 current_event: ContextVar = ContextVar("current_event")
 
 
-class Matcher:
+class MatcherMeta(type):
+
+    def __repr__(self) -> str:
+        return (f"<Matcher from {self.module or 'unknow'}, "  # type: ignore
+                f"type={self.type}, priority={self.priority}, "  # type: ignore
+                f"temp={self.temp}>")  # type: ignore
+
+    def __str__(self) -> str:
+        return self.__repr__()
+
+
+class Matcher(metaclass=MatcherMeta):
     """`Matcher`类
     """
+    module: Optional[str] = None
 
     type: str = ""
     rule: Rule = Rule()
@@ -43,8 +56,8 @@ class Matcher:
         self.state = self._default_state.copy()
 
     def __repr__(self) -> str:
-        return (f"<Matcher {self.type}, priority={self.priority},"
+        return (f"<Matcher from {self.module or 'unknow'}, type={self.type}, "
-                f" temp={self.temp}, expire={self.expire_time}>")
+                f"priority={self.priority}, temp={self.temp}>")
 
     def __str__(self) -> str:
         return self.__repr__()
@@ -59,6 +72,7 @@ class Matcher:
             priority: int = 1,
             block: bool = False,
             *,
+            module: Optional[str] = None,
             default_state: Optional[dict] = None,
             expire_time: Optional[datetime] = None) -> Type["Matcher"]:
         """创建新的 Matcher
@@ -69,6 +83,7 @@ class Matcher:
 
         NewMatcher = type(
             "Matcher", (Matcher,), {
+                "module": module,
                 "type": type_,
                 "rule": rule,
                 "permission": permission,
@@ -253,5 +268,6 @@ class Matcher:
         except FinishedException:
             pass
         finally:
+            logger.info(f"Matcher {self} running complete")
             current_bot.reset(b_t)
             current_event.reset(e_t)

nonebot/message.py

@@ -30,8 +30,8 @@ async def _run_matcher(Matcher: Type[Matcher], bot: Bot, event: Event,
                 bot, event) or not await Matcher.check_rule(bot, event, state):
             return
     except Exception as e:
-        logger.error(f"Rule check failed for matcher {Matcher}. Ignored.")
+        logger.opt(colors=True, exception=e).error(
-        logger.exception(e)
+            f"<r><bg #f8bbd0>Rule check failed for {Matcher}.</bg #f8bbd0></r>")
         return
 
     # TODO: log matcher
@@ -43,8 +43,9 @@ async def _run_matcher(Matcher: Type[Matcher], bot: Bot, event: Event,
         logger.debug(f"Running matcher {matcher}")
         await matcher.run(bot, event, state)
     except Exception as e:
-        logger.error(f"Running matcher {matcher} failed.")
+        logger.opt(colors=True, exception=e).error(
-        logger.exception(e)
+            f"<r><bg #f8bbd0>Running matcher {matcher} failed.</bg #f8bbd0></r>"
+        )
 
     exceptions = []
     if Matcher.temp:
@@ -56,20 +57,23 @@ async def _run_matcher(Matcher: Type[Matcher], bot: Bot, event: Event,
 
 
 async def handle_event(bot: Bot, event: Event):
-    log_msg = f"{bot.type.upper()} Bot {event.self_id} [{event.name}]: "
+    log_msg = f"<m>{bot.type.upper()} </m>| {event.self_id} [{event.name}]: "
     if event.type == "message":
         log_msg += f"Message {event.id} from "
         log_msg += str(event.user_id)
         if event.detail_type == "group":
-            log_msg += f"@[群:{event.group_id}]: "
+            log_msg += f"@[群:{event.group_id}]:"
-        log_msg += repr(str(event.message))
+
+        log_msg += ' "' + "".join(
+            map(lambda x: str(x) if x.type == "text" else f"<le>{x!s}</le>",
+                event.message)) + '"'  # type: ignore
     elif event.type == "notice":
         log_msg += f"Notice {event.raw_event}"
     elif event.type == "request":
         log_msg += f"Request {event.raw_event}"
     elif event.type == "meta_event":
         log_msg += f"MetaEvent {event.raw_event}"
-    logger.info(log_msg)
+    logger.opt(colors=True).info(log_msg)
 
     coros = []
     state = {}
@@ -80,7 +84,8 @@ async def handle_event(bot: Bot, event: Event):
             logger.debug("Running PreProcessors...")
             await asyncio.gather(*coros)
         except IgnoredException:
-            logger.info(f"Event {event.name} is ignored")
+            logger.opt(
+                colors=True).info(f"Event {event.name} is <b>ignored</b>")
             return
 
     # Trie Match
@@ -96,7 +101,7 @@ async def handle_event(bot: Bot, event: Event):
             for matcher in matchers[priority]
         ]
 
-        logger.debug(f"Checking for all matchers in priority {priority}...")
+        logger.debug(f"Checking for matchers in priority {priority}...")
         results = await asyncio.gather(*pending_tasks, return_exceptions=True)
 
         i = 0
@@ -104,8 +109,12 @@ async def handle_event(bot: Bot, event: Event):
             if isinstance(result, _ExceptionContainer):
                 e_list = result.exceptions
                 if StopPropagation in e_list:
-                    break_flag = True
+                    if not break_flag:
-                    logger.debug("Stop event propagation")
+                        break_flag = True
+                        logger.debug("Stop event propagation")
                 if ExpiredException in e_list:
+                    logger.debug(
+                        f"Matcher {matchers[priority][index - i]} will be removed."
+                    )
                     del matchers[priority][index - i]
                     i += 1

nonebot/plugin.py

@@ -168,6 +168,8 @@ def load_plugin(module_path: str) -> Optional[Plugin]:
     try:
         _tmp_matchers.clear()
         module = importlib.import_module(module_path)
+        for m in _tmp_matchers:
+            m.module = module_path
         plugin = Plugin(module_path, module, _tmp_matchers.copy())
         plugins[module_path] = plugin
         logger.opt(colors=True).info(f'Succeeded to import "{module_path}"')
@@ -193,6 +195,8 @@ def load_plugins(*plugin_dir: str) -> Set[Plugin]:
         try:
             module = _load(spec)
 
+            for m in _tmp_matchers:
+                m.module = name
             plugin = Plugin(name, module, _tmp_matchers.copy())
             plugins[name] = plugin
             loaded_plugins.add(plugin)