From db432ad0085a6c0c3c7aecc30957ec2aff7e4dbd Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Wed, 22 Oct 2025 19:29:38 +0800 Subject: [PATCH 01/16] feat: update log context --- src/memos/api/middleware/request_context.py | 25 +++++++- src/memos/context/context.py | 67 +++++++++++++++++++-- src/memos/log.py | 48 +++++++++++---- 3 files changed, 122 insertions(+), 18 deletions(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index cb41428d4..aabb61b64 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -2,6 +2,8 @@ Request context middleware for automatic trace_id injection. """ +import time + from collections.abc import Callable from starlette.middleware.base import BaseHTTPMiddleware @@ -38,8 +40,19 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: # Extract or generate trace_id trace_id = extract_trace_id_from_headers(request) or generate_trace_id() + env = request.headers.get("x-env") + user_type = request.headers.get("x-user-type") + user_name = request.headers.get("x-user-name") + start_time = time.time() + # Create and set request context - context = RequestContext(trace_id=trace_id, api_path=request.url.path) + context = RequestContext( + trace_id=trace_id, + api_path=request.url.path, + env=env, + user_type=user_type, + user_name=user_name, + ) set_request_context(context) # Log request start with parameters @@ -49,15 +62,21 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: if request.query_params: params_log["query_params"] = dict(request.query_params) - logger.info(f"Request started: {request.method} {request.url.path}, {params_log}") + logger.info(f"Request started, params: {params_log}, headers: {request.headers}") # Process the request response = await call_next(request) + end_time = time.time() # Log request completion with output - logger.info(f"Request completed: {request.url.path}, status: {response.status_code}") + logger.info( + f"Request completed: {request.url.path}, status: {response.status_code}, cost: {end_time - start_time}s" + ) # Add trace_id to response headers for debugging response.headers["x-trace-id"] = trace_id + response.headers["x-env"] = env + response.headers["x-user-type"] = user_type + response.headers["x-user-name"] = user_name return response diff --git a/src/memos/context/context.py b/src/memos/context/context.py index 4f54348fb..9d77e19e4 100644 --- a/src/memos/context/context.py +++ b/src/memos/context/context.py @@ -93,6 +93,36 @@ def get_current_api_path() -> str | None: return None +def get_current_env() -> str | None: + """ + Get the current request's env. + """ + context = _request_context.get() + if context: + return context.get("env") + return "prod" + + +def get_current_user_type() -> str | None: + """ + Get the current request's user type. + """ + context = _request_context.get() + if context: + return context.get("user_type") + return "normal" + + +def get_current_user_name() -> str | None: + """ + Get the current request's user name. + """ + context = _request_context.get() + if context: + return context.get("user_name") + return "unknown" + + def get_current_context() -> RequestContext | None: """ Get the current request context. @@ -103,7 +133,11 @@ def get_current_context() -> RequestContext | None: context_dict = _request_context.get() if context_dict: ctx = RequestContext( - trace_id=context_dict.get("trace_id"), api_path=context_dict.get("api_path") + trace_id=context_dict.get("trace_id"), + api_path=context_dict.get("api_path"), + env=context_dict.get("env"), + user_type=context_dict.get("user_type"), + user_name=context_dict.get("user_name"), ) ctx._data = context_dict.get("data", {}).copy() return ctx @@ -141,6 +175,9 @@ def __init__(self, target, args=(), kwargs=None, **thread_kwargs): self.main_trace_id = get_current_trace_id() self.main_api_path = get_current_api_path() + self.main_env = get_current_env() + self.main_user_type = get_current_user_type() + self.main_user_name = get_current_user_name() self.main_context = get_current_context() def run(self): @@ -148,7 +185,11 @@ def run(self): if self.main_context: # Copy the context data child_context = RequestContext( - trace_id=self.main_trace_id, api_path=self.main_context.api_path + trace_id=self.main_trace_id, + api_path=self.main_api_path, + env=self.main_env, + user_type=self.main_user_type, + user_name=self.main_user_name, ) child_context._data = self.main_context._data.copy() @@ -171,13 +212,22 @@ def submit(self, fn: Callable[..., T], *args: Any, **kwargs: Any) -> Any: """ main_trace_id = get_current_trace_id() main_api_path = get_current_api_path() + main_env = get_current_env() + main_user_type = get_current_user_type() + main_user_name = get_current_user_name() main_context = get_current_context() @functools.wraps(fn) def wrapper(*args: Any, **kwargs: Any) -> Any: if main_context: # Create and set new context in worker thread - child_context = RequestContext(trace_id=main_trace_id, api_path=main_api_path) + child_context = RequestContext( + trace_id=main_trace_id, + api_path=main_api_path, + env=main_env, + user_type=main_user_type, + user_name=main_user_name, + ) child_context._data = main_context._data.copy() set_request_context(child_context) @@ -198,13 +248,22 @@ def map( """ main_trace_id = get_current_trace_id() main_api_path = get_current_api_path() + main_env = get_current_env() + main_user_type = get_current_user_type() + main_user_name = get_current_user_name() main_context = get_current_context() @functools.wraps(fn) def wrapper(*args: Any, **kwargs: Any) -> Any: if main_context: # Create and set new context in worker thread - child_context = RequestContext(trace_id=main_trace_id, api_path=main_api_path) + child_context = RequestContext( + trace_id=main_trace_id, + api_path=main_api_path, + env=main_env, + user_type=main_user_type, + user_name=main_user_name, + ) child_context._data = main_context._data.copy() set_request_context(child_context) diff --git a/src/memos/log.py b/src/memos/log.py index 339d13f26..a610d4011 100644 --- a/src/memos/log.py +++ b/src/memos/log.py @@ -14,7 +14,13 @@ from dotenv import load_dotenv from memos import settings -from memos.context.context import get_current_api_path, get_current_trace_id +from memos.context.context import ( + get_current_api_path, + get_current_env, + get_current_trace_id, + get_current_user_name, + get_current_user_type, +) # Load environment variables @@ -34,15 +40,21 @@ def _setup_logfile() -> Path: return logfile -class TraceIDFilter(logging.Filter): - """add trace_id to the log record""" +class ContextFilter(logging.Filter): + """add context to the log record""" def filter(self, record): try: trace_id = get_current_trace_id() record.trace_id = trace_id if trace_id else "trace-id" + record.env = get_current_env() + record.user_type = get_current_user_type() + record.user_name = get_current_user_name() except Exception: record.trace_id = "trace-id" + record.env = "prod" + record.user_type = "normal" + record.user_name = "unknown" return True @@ -86,13 +98,24 @@ def emit(self, record): try: trace_id = get_current_trace_id() or "trace-id" api_path = get_current_api_path() + env = get_current_env() + user_type = get_current_user_type() + user_name = get_current_user_name() if api_path is not None: - self._executor.submit(self._send_log_sync, record.getMessage(), trace_id, api_path) + self._executor.submit( + self._send_log_sync, + record.getMessage(), + trace_id, + api_path, + env, + user_type, + user_name, + ) except Exception as e: if not self._is_shutting_down.is_set(): print(f"Error sending log: {e}") - def _send_log_sync(self, message, trace_id, api_path): + def _send_log_sync(self, message, trace_id, api_path, env, user_type, user_name): """Send log message synchronously in a separate thread""" try: logger_url = os.getenv("CUSTOM_LOGGER_URL") @@ -104,6 +127,9 @@ def _send_log_sync(self, message, trace_id, api_path): "trace_id": trace_id, "action": api_path, "current_time": round(time.time(), 3), + "env": env, + "user_type": user_type, + "user_name": user_name, } # Add auth token if exists @@ -145,18 +171,18 @@ def close(self): "disable_existing_loggers": False, "formatters": { "standard": { - "format": "%(asctime)s [%(trace_id)s] - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(asctime)s [%(trace_id)s] - %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "no_datetime": { - "format": "[%(trace_id)s] - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "[%(trace_id)s] - %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "simplified": { - "format": "%(asctime)s | %(trace_id)s | %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" + "format": "%(asctime)s | %(trace_id)s | %(env)s | %(user_type)s | %(user_name)s | %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" }, }, "filters": { "package_tree_filter": {"()": "logging.Filter", "name": settings.LOG_FILTER_TREE_PREFIX}, - "trace_id_filter": {"()": "memos.log.TraceIDFilter"}, + "context_filter": {"()": "memos.log.ContextFilter"}, }, "handlers": { "console": { @@ -164,7 +190,7 @@ def close(self): "class": "logging.StreamHandler", "stream": stdout, "formatter": "no_datetime", - "filters": ["package_tree_filter", "trace_id_filter"], + "filters": ["package_tree_filter", "context_filter"], }, "file": { "level": "DEBUG", @@ -173,7 +199,7 @@ def close(self): "maxBytes": 1024**2 * 10, "backupCount": 10, "formatter": "standard", - "filters": ["trace_id_filter"], + "filters": ["context_filter"], }, "custom_logger": { "level": "INFO", From 9502acc18aec4340e13edb58781b1cc73c4d59ac Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Wed, 22 Oct 2025 20:43:36 +0800 Subject: [PATCH 02/16] feat: update log context --- src/memos/context/context.py | 29 ++++++++++++++++++++++++++--- 1 file changed, 26 insertions(+), 3 deletions(-) diff --git a/src/memos/context/context.py b/src/memos/context/context.py index 9d77e19e4..2eecca92c 100644 --- a/src/memos/context/context.py +++ b/src/memos/context/context.py @@ -29,9 +29,19 @@ class RequestContext: This provides a Flask g-like object for FastAPI applications. """ - def __init__(self, trace_id: str | None = None, api_path: str | None = None): + def __init__( + self, + trace_id: str | None = None, + api_path: str | None = None, + env: str | None = None, + user_type: str | None = None, + user_name: str | None = None, + ): self.trace_id = trace_id or "trace-id" self.api_path = api_path + self.env = env + self.user_type = user_type + self.user_name = user_name self._data: dict[str, Any] = {} def set(self, key: str, value: Any) -> None: @@ -43,7 +53,13 @@ def get(self, key: str, default: Any | None = None) -> Any: return self._data.get(key, default) def __setattr__(self, name: str, value: Any) -> None: - if name.startswith("_") or name in ("trace_id", "api_path"): + if name.startswith("_") or name in ( + "trace_id", + "api_path", + "env", + "user_type", + "user_name", + ): super().__setattr__(name, value) else: if not hasattr(self, "_data"): @@ -58,7 +74,14 @@ def __getattr__(self, name: str) -> Any: def to_dict(self) -> dict[str, Any]: """Convert context to dictionary.""" - return {"trace_id": self.trace_id, "api_path": self.api_path, "data": self._data.copy()} + return { + "trace_id": self.trace_id, + "api_path": self.api_path, + "env": self.env, + "user_type": self.user_type, + "user_name": self.user_name, + "data": self._data.copy(), + } def set_request_context(context: RequestContext) -> None: From d74e62898f55e54906824a58be2d8219e4e086d0 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Thu, 23 Oct 2025 17:33:51 +0800 Subject: [PATCH 03/16] feat: update mcp --- src/memos/api/middleware/request_context.py | 6 ------ 1 file changed, 6 deletions(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index aabb61b64..42e1fbb65 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -73,10 +73,4 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: f"Request completed: {request.url.path}, status: {response.status_code}, cost: {end_time - start_time}s" ) - # Add trace_id to response headers for debugging - response.headers["x-trace-id"] = trace_id - response.headers["x-env"] = env - response.headers["x-user-type"] = user_type - response.headers["x-user-name"] = user_name - return response From 32b2ac103f98a75f09a8f0221fcd4dcf6d2f70ed Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Thu, 23 Oct 2025 17:43:28 +0800 Subject: [PATCH 04/16] feat: update mcp --- src/memos/utils.py | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/src/memos/utils.py b/src/memos/utils.py index 6a1d42558..5801bc2d2 100644 --- a/src/memos/utils.py +++ b/src/memos/utils.py @@ -1,5 +1,6 @@ import time +from memos import settings from memos.log import get_logger @@ -13,7 +14,8 @@ def wrapper(*args, **kwargs): start = time.perf_counter() result = func(*args, **kwargs) elapsed = time.perf_counter() - start - logger.info(f"[TIMER] {func.__name__} took {elapsed:.2f} s") + if settings.DEBUG: + logger.info(f"[TIMER] {func.__name__} took {elapsed:.2f} s") return result return wrapper From e4c6b924a813560fa3a916234f8fd3ddd368838f Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Thu, 23 Oct 2025 17:58:17 +0800 Subject: [PATCH 05/16] feat: add error log --- src/memos/api/middleware/request_context.py | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index 42e1fbb65..c81ab5a5a 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -68,9 +68,13 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: response = await call_next(request) end_time = time.time() - # Log request completion with output - logger.info( - f"Request completed: {request.url.path}, status: {response.status_code}, cost: {end_time - start_time}s" - ) + if response.status_code == 200: + logger.info( + f"Request completed: {request.url.path}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + ) + else: + logger.error( + f"Request Failed: {request.url.path}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + ) return response From c27bd61af8cace0b4ae550ec473c1e7b99c83038 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Thu, 23 Oct 2025 17:59:27 +0800 Subject: [PATCH 06/16] feat: add error log --- src/memos/log.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/memos/log.py b/src/memos/log.py index a610d4011..59e9ed0e3 100644 --- a/src/memos/log.py +++ b/src/memos/log.py @@ -171,10 +171,10 @@ def close(self): "disable_existing_loggers": False, "formatters": { "standard": { - "format": "%(asctime)s [%(trace_id)s] - %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(asctime)s | %(trace_id)s | %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "no_datetime": { - "format": "[%(trace_id)s] - %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(trace_id)s| %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "simplified": { "format": "%(asctime)s | %(trace_id)s | %(env)s | %(user_type)s | %(user_name)s | %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" From 6769b4c47abbfe1600c8dfb6f97a13b32cc6adf4 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Thu, 23 Oct 2025 20:49:58 +0800 Subject: [PATCH 07/16] feat: add error log --- src/memos/api/middleware/request_context.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index c81ab5a5a..b9063a64d 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -74,7 +74,7 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: ) else: logger.error( - f"Request Failed: {request.url.path}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + f"Request Failed: {request.url.path}, response: {response.json()}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" ) return response From 01547e1adcc1d1576ef69a5c51c321aa672a1755 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 10:09:57 +0800 Subject: [PATCH 08/16] feat: update log --- src/memos/log.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/memos/log.py b/src/memos/log.py index 59e9ed0e3..4abdb19c7 100644 --- a/src/memos/log.py +++ b/src/memos/log.py @@ -171,13 +171,13 @@ def close(self): "disable_existing_loggers": False, "formatters": { "standard": { - "format": "%(asctime)s | %(trace_id)s | %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(asctime)s | trace_id=%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s |%(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "no_datetime": { - "format": "%(trace_id)s| %(env)s | %(user_type)s | %(user_name)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "trace_id=%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "simplified": { - "format": "%(asctime)s | %(trace_id)s | %(env)s | %(user_type)s | %(user_name)s | %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" + "format": "%(asctime)s | trace_id=%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | % %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" }, }, "filters": { From a19584f71174647d6545e260fb87576de6d6cbcd Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 11:44:11 +0800 Subject: [PATCH 09/16] feat: add chat_time --- src/memos/api/middleware/request_context.py | 11 +++++++++-- src/memos/log.py | 6 +++--- 2 files changed, 12 insertions(+), 5 deletions(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index b9063a64d..bdcbcc004 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -68,13 +68,20 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: response = await call_next(request) end_time = time.time() + try: + print(f"response.json(): {response}") + response_json = response.json() + except Exception as e: + response_json = None + logger.error(f"Error getting response body: {e}") + if response.status_code == 200: logger.info( - f"Request completed: {request.url.path}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + f"Request completed: {request.url.path}, response: {response_json}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" ) else: logger.error( - f"Request Failed: {request.url.path}, response: {response.json()}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + f"Request Failed: {request.url.path}, response: {response_json}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" ) return response diff --git a/src/memos/log.py b/src/memos/log.py index 4abdb19c7..8113f098e 100644 --- a/src/memos/log.py +++ b/src/memos/log.py @@ -171,13 +171,13 @@ def close(self): "disable_existing_loggers": False, "formatters": { "standard": { - "format": "%(asctime)s | trace_id=%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s |%(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(asctime)s | %(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s |%(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "no_datetime": { - "format": "trace_id=%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "simplified": { - "format": "%(asctime)s | trace_id=%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | % %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" + "format": "%(asctime)s | %(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | % %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" }, }, "filters": { From 8dfa33844de3a45a499f5a49494566eb0dcfbeab Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 12:07:24 +0800 Subject: [PATCH 10/16] feat: add chat_time --- src/memos/api/middleware/request_context.py | 27 ++++++++++++++------- 1 file changed, 18 insertions(+), 9 deletions(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index bdcbcc004..5fdd94765 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -6,6 +6,7 @@ from collections.abc import Callable +from fastapi.responses import StreamingResponse from starlette.middleware.base import BaseHTTPMiddleware from starlette.requests import Request from starlette.responses import Response @@ -15,6 +16,20 @@ from memos.context.context import RequestContext, generate_trace_id, set_request_context +async def _tee_stream( + original: StreamingResponse, +) -> str: + chunks = [] + + async for chunk in original.body_iterator: + chunks.append(chunk) + yield chunk + + body_str = "".join(chunks) + + return body_str + + logger = memos.log.get_logger(__name__) @@ -67,21 +82,15 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: # Process the request response = await call_next(request) end_time = time.time() - - try: - print(f"response.json(): {response}") - response_json = response.json() - except Exception as e: - response_json = None - logger.error(f"Error getting response body: {e}") + content = await _tee_stream(response) if response.status_code == 200: logger.info( - f"Request completed: {request.url.path}, response: {response_json}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + f"Request completed: {request.url.path}, content: {content}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" ) else: logger.error( - f"Request Failed: {request.url.path}, response: {response_json}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + f"Request Failed: {request.url.path}, content: {content}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" ) return response From a91e3e260f2ccaf92c0f61e8c71142498a04559e Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 12:50:07 +0800 Subject: [PATCH 11/16] feat: add chat_time --- src/memos/api/middleware/request_context.py | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index 5fdd94765..a26d2c2aa 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -18,16 +18,16 @@ async def _tee_stream( original: StreamingResponse, -) -> str: +) -> StreamingResponse: chunks = [] async for chunk in original.body_iterator: chunks.append(chunk) yield chunk - body_str = "".join(chunks) + body_str = "".join(chunks).decode("utf-8", errors="replace") - return body_str + logger.info(f"Response content: {body_str}") logger = memos.log.get_logger(__name__) From 5b962e26cac70a4bde33e0198d2398e40cc4c55d Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 13:22:45 +0800 Subject: [PATCH 12/16] feat: update log --- src/memos/api/middleware/request_context.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index a26d2c2aa..32ce1ccec 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -82,7 +82,7 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: # Process the request response = await call_next(request) end_time = time.time() - content = await _tee_stream(response) + content = _tee_stream(response) if response.status_code == 200: logger.info( From 69a6e9a7eac5bb2181362e4e7986425a1dd87da7 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 13:34:48 +0800 Subject: [PATCH 13/16] feat: update log --- src/memos/api/middleware/request_context.py | 11 ++++++++++- 1 file changed, 10 insertions(+), 1 deletion(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index 32ce1ccec..76bd8f77a 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -82,7 +82,16 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: # Process the request response = await call_next(request) end_time = time.time() - content = _tee_stream(response) + if isinstance(response, StreamingResponse): + response.body_iterator = _tee_stream(response) + content = "Streaming response" + else: + try: + content = ( + response.body.decode("utf-8") if hasattr(response, "body") else str(response) + ) + except Exception as e: + content = f"Unable to decode response content: {e!s}" if response.status_code == 200: logger.info( From d325a3119369b573cf1bfa90d04fbf3561bfddb6 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 15:03:46 +0800 Subject: [PATCH 14/16] feat: update log --- src/memos/api/routers/server_router.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/memos/api/routers/server_router.py b/src/memos/api/routers/server_router.py index a332de583..8a2f0a968 100644 --- a/src/memos/api/routers/server_router.py +++ b/src/memos/api/routers/server_router.py @@ -237,6 +237,7 @@ def search_memories(search_req: APISearchRequest): } ) + logger.info(f"search_memories response data: {memories_result}") return SearchResponse( message="Search completed successfully", data=memories_result, @@ -285,6 +286,7 @@ def add_memories(add_req: APIADDRequest): } for memory_id, memory in zip(mem_id_list, flattened_memories, strict=False) ] + logger.info(f"add_memories response data: {response_data}") return MemoryResponse( message="Memory added successfully", data=response_data, From f0e5f5cc5e07b82c1bf1277e88c5b93713bfd310 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 15:34:46 +0800 Subject: [PATCH 15/16] feat: update log --- src/memos/api/middleware/request_context.py | 33 ++++++++++----------- src/memos/context/context.py | 4 +-- src/memos/log.py | 2 +- 3 files changed, 18 insertions(+), 21 deletions(-) diff --git a/src/memos/api/middleware/request_context.py b/src/memos/api/middleware/request_context.py index 76bd8f77a..a7d0dc967 100644 --- a/src/memos/api/middleware/request_context.py +++ b/src/memos/api/middleware/request_context.py @@ -80,26 +80,23 @@ async def dispatch(self, request: Request, call_next: Callable) -> Response: logger.info(f"Request started, params: {params_log}, headers: {request.headers}") # Process the request - response = await call_next(request) - end_time = time.time() - if isinstance(response, StreamingResponse): - response.body_iterator = _tee_stream(response) - content = "Streaming response" - else: - try: - content = ( - response.body.decode("utf-8") if hasattr(response, "body") else str(response) - ) - except Exception as e: - content = f"Unable to decode response content: {e!s}" + try: + response = await call_next(request) + end_time = time.time() - if response.status_code == 200: - logger.info( - f"Request completed: {request.url.path}, content: {content}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" - ) - else: + if response.status_code == 200: + logger.info( + f"Request completed: {request.url.path}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + ) + else: + logger.error( + f"Request Failed: {request.url.path}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + ) + except Exception as e: + end_time = time.time() logger.error( - f"Request Failed: {request.url.path}, content: {content}, status: {response.status_code}, cost: {(end_time - start_time) * 1000:.2f}ms" + f"Request Exception Error: {e}, cost: {(end_time - start_time) * 1000:.2f}ms" ) + raise e return response diff --git a/src/memos/context/context.py b/src/memos/context/context.py index 2eecca92c..d6a0f3bf1 100644 --- a/src/memos/context/context.py +++ b/src/memos/context/context.py @@ -133,7 +133,7 @@ def get_current_user_type() -> str | None: context = _request_context.get() if context: return context.get("user_type") - return "normal" + return "opensource" def get_current_user_name() -> str | None: @@ -143,7 +143,7 @@ def get_current_user_name() -> str | None: context = _request_context.get() if context: return context.get("user_name") - return "unknown" + return "memos" def get_current_context() -> RequestContext | None: diff --git a/src/memos/log.py b/src/memos/log.py index 8113f098e..dac79b4af 100644 --- a/src/memos/log.py +++ b/src/memos/log.py @@ -171,7 +171,7 @@ def close(self): "disable_existing_loggers": False, "formatters": { "standard": { - "format": "%(asctime)s | %(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s |%(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(asctime)s | %(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "no_datetime": { "format": "%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" From 7fc8c052fc95b4ace4b32b68f02dc51d393df7b8 Mon Sep 17 00:00:00 2001 From: harvey_xiang Date: Fri, 24 Oct 2025 15:38:35 +0800 Subject: [PATCH 16/16] feat: update log --- src/memos/log.py | 7 ++++--- 1 file changed, 4 insertions(+), 3 deletions(-) diff --git a/src/memos/log.py b/src/memos/log.py index dac79b4af..d46bfa7f5 100644 --- a/src/memos/log.py +++ b/src/memos/log.py @@ -50,6 +50,7 @@ def filter(self, record): record.env = get_current_env() record.user_type = get_current_user_type() record.user_name = get_current_user_name() + record.api_path = get_current_api_path() except Exception: record.trace_id = "trace-id" record.env = "prod" @@ -171,13 +172,13 @@ def close(self): "disable_existing_loggers": False, "formatters": { "standard": { - "format": "%(asctime)s | %(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(asctime)s | %(trace_id)s | %(api_path)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "no_datetime": { - "format": "%(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" + "format": "%(trace_id)s | %(api_path)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(funcName)s - %(message)s" }, "simplified": { - "format": "%(asctime)s | %(trace_id)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | % %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" + "format": "%(asctime)s | %(trace_id)s | %(api_path)s | env=%(env)s | user_type=%(user_type)s | user_name=%(user_name)s | % %(levelname)s | %(filename)s:%(lineno)d: %(funcName)s | %(message)s" }, }, "filters": {