add more logs

nonebot/__init__.py

@@ -147,6 +147,7 @@ def init(*, _env_file: Optional[str] = None, **kwargs):
     """
     global _driver
     env = Env()
+    logger.debug(f"Current Env: {env.environment}")
     config = Config(**kwargs, _env_file=_env_file or f".env.{env.environment}")
 
     logger.setLevel(logging.DEBUG if config.debug else logging.INFO)

nonebot/adapters/__init__.py

@@ -54,18 +54,32 @@ class BaseEvent(abc.ABC):
         self._raw_event = raw_event
 
     def __repr__(self) -> str:
-        # TODO: pretty print
+        return f"<Event {self.self_id}: {self.name} {self.time}>"
-        return f"<Event: {self.type}/{self.detail_type} {self.raw_message}>"
 
     @property
     def raw_event(self) -> dict:
         return self._raw_event
 
+    @property
+    @abc.abstractmethod
+    def id(self) -> int:
+        raise NotImplementedError
+
+    @property
+    @abc.abstractmethod
+    def name(self) -> str:
+        raise NotImplementedError
+
     @property
     @abc.abstractmethod
     def self_id(self) -> str:
         raise NotImplementedError
 
+    @property
+    @abc.abstractmethod
+    def time(self) -> int:
+        raise NotImplementedError
+
     @property
     @abc.abstractmethod
     def type(self) -> str:

nonebot/adapters/cqhttp.py

@@ -168,9 +168,14 @@ class Bot(BaseBot):
         if not message:
             return
 
+        if "post_type" not in message:
+            ResultStore.add_result(message)
+            return
+
         event = Event(message)
 
         # Check whether user is calling me
+        # TODO: Check reply
         _check_at_me(self, event)
         _check_nickname(self, event)
 
@@ -262,11 +267,29 @@ class Event(BaseEvent):
 
         super().__init__(raw_event)
 
+    @property
+    @overrides(BaseEvent)
+    def id(self) -> Optional[int]:
+        return self._raw_event.get("message_id") or self._raw_event.get("flag")
+
+    @property
+    @overrides(BaseEvent)
+    def name(self) -> str:
+        n = self.type + "." + self.detail_type
+        if self.sub_type:
+            n += "." + self.sub_type
+        return n
+
     @property
     @overrides(BaseEvent)
     def self_id(self) -> str:
         return str(self._raw_event["self_id"])
 
+    @property
+    @overrides(BaseEvent)
+    def time(self) -> int:
+        return self._raw_event["time"]
+
     @property
     @overrides(BaseEvent)
     def type(self) -> str:

nonebot/drivers/fastapi.py

@@ -1,19 +1,20 @@
 #!/usr/bin/env python3
 # -*- coding: utf-8 -*-
 
+import hmac
 import json
 import logging
 
 import uvicorn
+from fastapi.responses import Response
 from fastapi import Body, status, Header, FastAPI, Depends, HTTPException
 from starlette.websockets import WebSocketDisconnect, WebSocket as FastAPIWebSocket
 
 from nonebot.log import logger
 from nonebot.config import Env, Config
 from nonebot.utils import DataclassEncoder
-from nonebot.adapters.cqhttp import Bot as CQBot
 from nonebot.drivers import BaseDriver, BaseWebSocket
-from nonebot.typing import Union, Optional, Callable, overrides
+from nonebot.typing import Optional, Callable, overrides
 
 
 def get_auth_bearer(access_token: Optional[str] = Header(
@@ -116,28 +117,50 @@ class Driver(BaseDriver):
                     **kwargs)
 
     @overrides(BaseDriver)
-    async def _handle_http(
+    async def _handle_http(self,
-        self,
+                           adapter: str,
-        adapter: str,
+                           data: dict = Body(...),
-        data: dict = Body(...),
+                           x_self_id: Optional[str] = Header(None),
-        x_self_id: str = Header(None),
+                           x_signature: Optional[str] = Header(None)):
-        access_token: Optional[str] = Depends(get_auth_bearer)):
+        # 检查self_id
-        secret = self.config.secret
+        if not x_self_id:
-        if secret is not None and secret != access_token:
+            logger.warning("Missing X-Self-ID Header")
-            raise HTTPException(status_code=status.HTTP_401_UNAUTHORIZED,
+            raise HTTPException(status_code=status.HTTP_400_BAD_REQUEST,
-                                detail="Not authenticated",
+                                detail="Missing X-Self-ID Header")
-                                headers={"WWW-Authenticate": "Bearer"})
 
-        # Create Bot Object
+        # 检查签名
+        secret = self.config.secret
+        if secret:
+            if not x_signature:
+                logger.warning("Missing Signature Header")
+                raise HTTPException(status_code=status.HTTP_401_UNAUTHORIZED,
+                                    detail="Missing Signature")
+            sig = hmac.new(secret.encode("utf-8"),
+                           json.dumps(data).encode(), "sha1").hexdigest()
+            if x_signature != "sha1=" + sig:
+                logger.warning("Signature Header is invalid")
+                raise HTTPException(status_code=status.HTTP_403_FORBIDDEN,
+                                    detail="Signature is invalid")
+
+        if not isinstance(data, dict):
+            logger.warning("Data received is invalid")
+            raise HTTPException(status_code=status.HTTP_400_BAD_REQUEST)
+
+        if x_self_id in self._clients:
+            logger.warning("There's already a reverse websocket api connection,"
+                           "so the event may be handled twice.")
+
+        # 创建 Bot 对象
         if adapter in self._adapters:
             BotClass = self._adapters[adapter]
             bot = BotClass(self, "http", self.config, x_self_id)
         else:
+            logger.warning("Unknown adapter")
             raise HTTPException(status_code=status.HTTP_404_NOT_FOUND,
                                 detail="adapter not found")
 
         await bot.handle_message(data)
-        return {"status": 200, "message": "success"}
+        return Response("", 204)
 
     @overrides(BaseDriver)
     async def _handle_ws_reverse(
@@ -146,19 +169,21 @@ class Driver(BaseDriver):
         websocket: FastAPIWebSocket,
         x_self_id: str = Header(None),
         access_token: Optional[str] = Depends(get_auth_bearer)):
+        ws = WebSocket(websocket)
+
         secret = self.config.secret
         if secret is not None and secret != access_token:
-            await websocket.close(code=status.WS_1008_POLICY_VIOLATION)
+            logger.warning("Authorization Header is invalid"
-
+                           if access_token else "Missing Authorization Header")
-        websocket = WebSocket(websocket)
+            await ws.close(code=status.WS_1008_POLICY_VIOLATION)
 
         if not x_self_id:
-            logger.error(f"Error Connection Unkown: self_id {x_self_id}")
+            logger.warning(f"Missing X-Self-ID Header")
-            await websocket.close(code=status.WS_1008_POLICY_VIOLATION)
+            await ws.close(code=status.WS_1008_POLICY_VIOLATION)
 
         if x_self_id in self._clients:
-            logger.error(f"Error Connection Conflict: self_id {x_self_id}")
+            logger.warning(f"Connection Conflict: self_id {x_self_id}")
-            await websocket.close(code=status.WS_1008_POLICY_VIOLATION)
+            await ws.close(code=status.WS_1008_POLICY_VIOLATION)
 
         # Create Bot Object
         if adapter in self._adapters:
@@ -167,17 +192,18 @@ class Driver(BaseDriver):
                            "websocket",
                            self.config,
                            x_self_id,
-                           websocket=websocket)
+                           websocket=ws)
         else:
+            logger.warning("Unknown adapter")
             raise HTTPException(status_code=status.HTTP_404_NOT_FOUND,
                                 detail="adapter not found")
 
-        await websocket.accept()
+        await ws.accept()
         self._clients[x_self_id] = bot
 
         try:
-            while not websocket.closed:
+            while not ws.closed:
-                data = await websocket.receive()
+                data = await ws.receive()
 
                 if not data:
                     continue
@@ -213,8 +239,11 @@ class WebSocket(BaseWebSocket):
         data = None
         try:
             data = await self.websocket.receive_json()
+            if not isinstance(data, dict):
+                data = None
+                raise ValueError
         except ValueError:
-            logger.debug("Received an invalid json message.")
+            logger.warning("Received an invalid json message.")
         except WebSocketDisconnect:
             self._closed = True
             logger.error("WebSocket disconnected by peer.")

nonebot/message.py

@@ -53,15 +53,31 @@ 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}]: "
+    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 += repr(str(event.message))
+    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)
+
     coros = []
     state = {}
     for preprocessor in _event_preprocessors:
         coros.append(preprocessor(bot, event, state))
     if coros:
         try:
+            logger.debug("Running PreProcessors...")
             await asyncio.gather(*coros)
         except IgnoredException:
-            logger.info(f"Event {event} is ignored")
+            logger.info(f"Event {event.name} is ignored")
             return
 
     # Trie Match
@@ -77,6 +93,7 @@ async def handle_event(bot: Bot, event: Event):
             for matcher in matchers[priority]
         ]
 
+        logger.debug(f"Checking for all matchers in priority {priority}...")
         results = await asyncio.gather(*pending_tasks, return_exceptions=True)
 
         i = 0
@@ -85,6 +102,7 @@ async def handle_event(bot: Bot, event: Event):
                 e_list = result.exceptions
                 if StopPropagation in e_list:
                     break_flag = True
+                    logger.debug("Stop event propafation")
                 if ExpiredException in e_list:
                     del matchers[priority][index - i]
                     i += 1