Merge pull request #922 from inclusionAI/fix/gateway-log-growth-no-script

Fix gateway launchd log growth

Author: ahgpt

aworld-cli/src/aworld_cli/gateway_cli.py

@@ -20,7 +20,11 @@
 from aworld_gateway.config import GatewayConfig
 from aworld_gateway.http.artifact_service import ArtifactService
 from aworld_gateway.http.server import create_gateway_app
-from aworld_gateway.logging import configure_gateway_logging, get_gateway_logger
+from aworld_gateway.logging import (
+    GATEWAY_CONSOLE_LOG_ENV,
+    configure_gateway_logging,
+    get_gateway_logger,
+)
 from aworld_gateway.registry import ChannelRegistry
 from aworld_gateway.router import GatewayRouter, LocalCliAgentBackend
 from aworld_gateway.runtime import GatewayRuntime
@@ -190,18 +194,27 @@ def _build_artifact_service(
     )
 
 
-def _enable_aworld_console_logging_for_gateway() -> None:
-    os.environ["AWORLD_DISABLE_CONSOLE_LOG"] = "false"
+def _suppress_gateway_console_logging() -> None:
+    os.environ["AWORLD_DISABLE_CONSOLE_LOG"] = "true"
+    os.environ[GATEWAY_CONSOLE_LOG_ENV] = "false"
 
     try:
         from aworld.logs import util as log_util
     except Exception:
         return
 
     aworld_logger = getattr(log_util, "logger", None)
-    if aworld_logger is None or not getattr(aworld_logger, "disable_console", False):
+    if aworld_logger is None or getattr(aworld_logger, "disable_console", False):
         return
 
+    log_id = getattr(aworld_logger, "log_id", None)
+    bound_logger = getattr(aworld_logger, "_logger", None)
+    if log_id is not None and bound_logger is not None:
+        try:
+            bound_logger.remove(log_id)
+        except Exception:
+            pass
+
     file_log_config = getattr(aworld_logger, "file_log_config", None)
     if isinstance(file_log_config, dict):
         file_log_config = dict(file_log_config)
@@ -211,11 +224,18 @@ def _enable_aworld_console_logging_for_gateway() -> None:
         name=getattr(aworld_logger, "name", "AWorld"),
         console_level=getattr(aworld_logger, "console_level", "INFO"),
         formatter=getattr(aworld_logger, "formater", None),
-        disable_console=False,
+        disable_console=True,
         file_log_config=file_log_config,
     )
 
 
+def _restore_env_var(name: str, previous_value: str | None) -> None:
+    if previous_value is None:
+        os.environ.pop(name, None)
+    else:
+        os.environ[name] = previous_value
+
+
 def _configure_gateway_file_logging(*, base_dir: Path) -> Path:
     log_path = (base_dir / "logs" / "gateway.log").resolve()
     os.environ["AWORLD_GATEWAY_LOG_PATH"] = str(log_path)
@@ -261,59 +281,69 @@ async def serve_gateway(
     agent_files: list[str] | None,
 ) -> None:
     resolved_base_dir = Path.cwd() if base_dir is None else Path(base_dir)
-    gateway_log_path = _configure_gateway_file_logging(base_dir=resolved_base_dir)
-    gateway_logger = get_gateway_logger("cli")
-    _enable_aworld_console_logging_for_gateway()
-    enable_quiet_gateway_boot()
-    gateway_logger.info(
-        "Gateway server boot starting "
-        f"base_dir={resolved_base_dir.resolve()} log_path={gateway_log_path}"
-    )
-
-    from aworld_cli.main import load_all_agents
-
-    await load_all_agents(
-        remote_backends=remote_backends,
-        local_dirs=local_dirs,
-        agent_files=agent_files,
-    )
-
-    config = GatewayConfigLoader(base_dir=resolved_base_dir).load_or_init()
-    artifact_service = _build_artifact_service(base_dir=resolved_base_dir, config=config)
-    router = GatewayRouter(
-        session_binding=SessionBinding(),
-        agent_resolver=AgentResolver(default_agent_id=config.default_agent_id),
-        agent_backend=LocalCliAgentBackend(),
-    )
-    runtime = GatewayRuntime(
-        config=config,
-        registry=ChannelRegistry(),
-        router=router,
-        artifact_service=artifact_service,
-    )
-
-    await runtime.start()
-    gateway_logger.info(
-        "Gateway runtime started "
-        f"host={config.gateway.host} port={config.gateway.port}"
-    )
-    telegram_adapter = runtime.get_started_channel("telegram")
-    app = create_gateway_app(
-        runtime_status=runtime.status(),
-        artifact_service=artifact_service,
-        telegram_adapter=telegram_adapter,
-        telegram_webhook_path=config.channels.telegram.webhook_path,
-    )
-    uvicorn_config = uvicorn.Config(
-        app=app,
-        host=config.gateway.host,
-        port=config.gateway.port,
-    )
-    server = uvicorn.Server(uvicorn_config)
-
+    previous_disable_console_log = os.environ.get("AWORLD_DISABLE_CONSOLE_LOG")
+    previous_gateway_console_log = os.environ.get(GATEWAY_CONSOLE_LOG_ENV)
+    gateway_log_path: Path | None = None
+    _suppress_gateway_console_logging()
     try:
-        await server.serve()
+        gateway_log_path = _configure_gateway_file_logging(base_dir=resolved_base_dir)
+        gateway_logger = get_gateway_logger("cli")
+        enable_quiet_gateway_boot()
+        gateway_logger.info(
+            "Gateway server boot starting "
+            f"base_dir={resolved_base_dir.resolve()} log_path={gateway_log_path}"
+        )
+
+        from aworld_cli.main import load_all_agents
+
+        await load_all_agents(
+            remote_backends=remote_backends,
+            local_dirs=local_dirs,
+            agent_files=agent_files,
+        )
+
+        config = GatewayConfigLoader(base_dir=resolved_base_dir).load_or_init()
+        artifact_service = _build_artifact_service(base_dir=resolved_base_dir, config=config)
+        router = GatewayRouter(
+            session_binding=SessionBinding(),
+            agent_resolver=AgentResolver(default_agent_id=config.default_agent_id),
+            agent_backend=LocalCliAgentBackend(),
+        )
+        runtime = GatewayRuntime(
+            config=config,
+            registry=ChannelRegistry(),
+            router=router,
+            artifact_service=artifact_service,
+        )
+
+        await runtime.start()
+        gateway_logger.info(
+            "Gateway runtime started "
+            f"host={config.gateway.host} port={config.gateway.port}"
+        )
+        telegram_adapter = runtime.get_started_channel("telegram")
+        app = create_gateway_app(
+            runtime_status=runtime.status(),
+            artifact_service=artifact_service,
+            telegram_adapter=telegram_adapter,
+            telegram_webhook_path=config.channels.telegram.webhook_path,
+        )
+        uvicorn_config = uvicorn.Config(
+            app=app,
+            host=config.gateway.host,
+            port=config.gateway.port,
+            log_level=str(os.getenv("AWORLD_GATEWAY_UVICORN_LOG_LEVEL") or "warning"),
+        )
+        server = uvicorn.Server(uvicorn_config)
+
+        try:
+            await server.serve()
+        finally:
+            gateway_logger.info("Gateway runtime stopping")
+            await runtime.stop()
+            gateway_logger.info("Gateway runtime stopped")
     finally:
-        gateway_logger.info("Gateway runtime stopping")
-        await runtime.stop()
-        gateway_logger.info("Gateway runtime stopped")
+        _restore_env_var("AWORLD_DISABLE_CONSOLE_LOG", previous_disable_console_log)
+        _restore_env_var(GATEWAY_CONSOLE_LOG_ENV, previous_gateway_console_log)
+        if gateway_log_path is not None:
+            configure_gateway_logging(log_path=gateway_log_path)

aworld_gateway/channels/wechat/connector.py

@@ -127,7 +127,8 @@ async def _default_post_json(
     timeout_ms: int,
 ) -> dict[str, object]:
     request_summary = _summarize_wechat_request_payload(payload)
-    logger.info(
+    log_success = logger.debug if endpoint == EP_GET_UPDATES else logger.info
+    log_success(
         "WeChat API request "
         f"endpoint={endpoint} timeout_ms={timeout_ms}"
         f"{f' {request_summary}' if request_summary else ''}"
@@ -149,7 +150,7 @@ async def _default_post_json(
                 )
                 raise RuntimeError(f"iLink POST {endpoint} HTTP {response.status}: {raw[:200]}")
             data = json.loads(raw)
-            logger.info(
+            log_success(
                 "WeChat API response "
                 f"endpoint={endpoint} http_status={getattr(response, 'status', 'unknown')} "
                 f"ret={data.get('ret', 'missing')} "

aworld_gateway/logging.py

@@ -6,7 +6,16 @@
 from pathlib import Path
 
 GATEWAY_LOGGER_NAME = "aworld.gateway"
+GATEWAY_CONSOLE_LOG_ENV = "AWORLD_GATEWAY_CONSOLE_LOG"
 _GATEWAY_HANDLER_MARKER = "_aworld_gateway_file_handler"
+_FALSEY_VALUES = {"0", "false", "no", "off"}
+
+
+def _is_gateway_console_log_enabled() -> bool:
+    configured = str(os.getenv(GATEWAY_CONSOLE_LOG_ENV) or "").strip().lower()
+    if configured in _FALSEY_VALUES:
+        return False
+    return True
 
 
 def resolve_gateway_log_path(log_path: Path | str | None = None) -> Path:
@@ -30,7 +39,7 @@ def configure_gateway_logging(*, log_path: Path | str | None = None) -> Path:
 
     gateway_root_logger = logging.getLogger(GATEWAY_LOGGER_NAME)
     gateway_root_logger.setLevel(logging.INFO)
-    gateway_root_logger.propagate = True
+    gateway_root_logger.propagate = _is_gateway_console_log_enabled()
 
     for handler in list(gateway_root_logger.handlers):
         if not getattr(handler, _GATEWAY_HANDLER_MARKER, False):

tests/gateway/test_gateway_status_command.py

@@ -2,6 +2,7 @@
 
 import asyncio
 import importlib
+import logging
 import os
 import sys
 from types import ModuleType
@@ -51,7 +52,7 @@ def test_gateway_channels_list_contains_placeholder_channels(
     assert rows["web"]["implemented"] is False
 
 
-def test_enable_aworld_console_logging_for_gateway_reconfigures_disabled_logger(
+def test_suppress_gateway_console_logging_reconfigures_enabled_logger(
     monkeypatch: pytest.MonkeyPatch,
 ) -> None:
     class FakeLogger:
@@ -83,15 +84,31 @@ def __init__(
 
     import aworld.logs.util as log_util
 
-    fake_logger = FakeLogger(disable_console=True)
+    fake_logger = FakeLogger(disable_console=False)
     monkeypatch.setattr(log_util, "logger", fake_logger)
-    monkeypatch.setenv("AWORLD_DISABLE_CONSOLE_LOG", "true")
+    monkeypatch.setenv("AWORLD_DISABLE_CONSOLE_LOG", "false")
+    monkeypatch.delenv("AWORLD_GATEWAY_CONSOLE_LOG", raising=False)
+
+    gateway_cli._suppress_gateway_console_logging()
+
+    assert os.environ["AWORLD_DISABLE_CONSOLE_LOG"] == "true"
+    assert os.environ["AWORLD_GATEWAY_CONSOLE_LOG"] == "false"
+    assert fake_logger.disable_console is True
+    assert fake_logger.calls[-1]["disable_console"] is True
+
+
+def test_configure_gateway_file_logging_can_suppress_console_propagation(
+    monkeypatch: pytest.MonkeyPatch,
+    tmp_path: Path,
+) -> None:
+    monkeypatch.setenv("AWORLD_GATEWAY_CONSOLE_LOG", "false")
+
+    gateway_cli._configure_gateway_file_logging(base_dir=tmp_path)
 
-    gateway_cli._enable_aworld_console_logging_for_gateway()
+    assert logging.getLogger("aworld.gateway").propagate is False
 
-    assert os.environ["AWORLD_DISABLE_CONSOLE_LOG"] == "false"
-    assert fake_logger.disable_console is False
-    assert fake_logger.calls[-1]["disable_console"] is False
+    monkeypatch.setenv("AWORLD_GATEWAY_CONSOLE_LOG", "true")
+    gateway_cli._configure_gateway_file_logging(base_dir=tmp_path)
 
 
 def test_configure_gateway_file_logging_writes_to_dedicated_gateway_log(
@@ -136,7 +153,7 @@ def test_get_gateway_logger_returns_named_child_logger(
     assert logger.name == f"{GATEWAY_LOGGER_NAME}.child_component"
 
 
-def test_serve_gateway_enables_console_logging_before_loading_agents(
+def test_serve_gateway_suppresses_console_logging_before_loading_agents(
     monkeypatch: pytest.MonkeyPatch,
     tmp_path: Path,
 ) -> None:
@@ -145,6 +162,7 @@ def test_serve_gateway_enables_console_logging_before_loading_agents(
 
     async def fake_load_all_agents(*, remote_backends, local_dirs, agent_files):
         observed["disable_console_env"] = os.environ.get("AWORLD_DISABLE_CONSOLE_LOG", "")
+        observed["gateway_console_env"] = os.environ.get("AWORLD_GATEWAY_CONSOLE_LOG", "")
         observed["quiet_boot_env"] = os.environ.get("AWORLD_GATEWAY_QUIET_BOOT", "")
         raise RuntimeError("stop after env check")
 
@@ -163,7 +181,8 @@ async def fake_load_all_agents(*, remote_backends, local_dirs, agent_files):
             )
         )
 
-    assert observed["disable_console_env"] == "false"
+    assert observed["disable_console_env"] == "true"
+    assert observed["gateway_console_env"] == "false"
     assert observed["quiet_boot_env"] == "true"
 
 
@@ -311,11 +330,12 @@ def get_started_channel(self, channel_name: str):
             return telegram_adapter
 
     class FakeUvicornConfig:
-        def __init__(self, *, app, host, port):
+        def __init__(self, *, app, host, port, log_level):
             calls["uvicorn_config"] = {
                 "app": app,
                 "host": host,
                 "port": port,
+                "log_level": log_level,
             }
 
     class FakeUvicornServer:
@@ -434,8 +454,9 @@ def get_started_channel(self, channel_name: str):
             return None
 
     class FakeUvicornConfig:
-        def __init__(self, *, app, host, port):
+        def __init__(self, *, app, host, port, log_level):
             calls["uvicorn_app"] = app
+            calls["uvicorn_log_level"] = log_level
 
     class FakeUvicornServer:
         def __init__(self, config):