fix(cli): daemon backend logs, serve timestamps, upgrade journal

flocks/cli/commands/update.py

@@ -9,6 +9,8 @@
 from rich.panel import Panel
 from rich.table import Table
 
+from flocks.utils.log import append_upgrade_text_log
+
 console = Console()
 
 
@@ -39,6 +41,7 @@ async def _update(check: bool, yes: bool, force: bool = False, region: str | Non
         info = await check_update(region=region)
 
     if info.error:
+        append_upgrade_text_log(f"ERROR version_check: {info.error}")
         console.print(f"[red]检查失败：{info.error}[/red]")
         raise typer.Exit(1)
 
@@ -76,6 +79,7 @@ async def _update(check: bool, yes: bool, force: bool = False, region: str | Non
             prompt = "\n当前已是最新版本，是否仍强制重新安装？"
         confirmed = typer.confirm(prompt, default=False)
         if not confirmed:
+            append_upgrade_text_log("INFO update_cancelled user_declined")
             console.print("[yellow]已取消[/yellow]")
             return
 
@@ -131,6 +135,7 @@ def _finish_active(success: bool = True) -> None:
             console.print(f"[cyan][{step}/{total_steps}] {label}...[/cyan]  ", end="")
             active_stage = progress.stage
 
+    append_upgrade_text_log(f"OK cli_update_completed version={version_to_apply}")
     console.print(f"\n[green]✓ 升级完成 → v{version_to_apply}[/green]")
     console.print("[dim]如有后台服务正在运行，请执行 [bold]flocks restart[/bold] 重启服务[/dim]")
 

flocks/cli/main.py

@@ -8,7 +8,7 @@
 import os
 import sys
 from pathlib import Path
-from typing import Optional
+from typing import Any, Optional
 
 import typer
 from dotenv import load_dotenv
@@ -291,6 +291,21 @@ def logs(
         _handle_service_error(error)
 
 
+def _uvicorn_log_config() -> dict[str, Any]:
+    """Uvicorn logging with wall-clock timestamps (visible in ``backend.log`` when daemonized)."""
+    import copy
+
+    from uvicorn.config import LOGGING_CONFIG
+
+    cfg = copy.deepcopy(LOGGING_CONFIG)
+    stamp_fmt = "%Y-%m-%d %H:%M:%S"
+    for name in ("default", "access"):
+        formatter = cfg["formatters"][name]
+        formatter["fmt"] = "%(asctime)s | " + formatter["fmt"]
+        formatter["datefmt"] = stamp_fmt
+    return cfg
+
+
 @app.command(hidden=True)
 def serve(
     host: str = typer.Option("127.0.0.1", "--host", "-h", help="Server host"),
@@ -313,6 +328,7 @@ def serve(
         port=port,
         reload=reload,
         log_level="info",
+        log_config=_uvicorn_log_config(),
     )
 
 

flocks/cli/service_manager.py

@@ -749,6 +749,7 @@ def start_backend(config: ServiceConfig, console) -> None:
     backend_env = os.environ.copy()
     backend_env["_FLOCKS_WEBUI_HOST"] = config.frontend_host
     backend_env["_FLOCKS_WEBUI_PORT"] = str(config.frontend_port)
+    backend_env["PYTHONUNBUFFERED"] = "1"
 
     console.print("[flocks] 启动后端服务...")
     process = _spawn_process(
@@ -772,9 +773,11 @@ def start_backend(config: ServiceConfig, console) -> None:
         wait_for_http(
             [backend_access_base_url(config)],
             "后端服务",
+            delay=3.0,
             validator=_is_running_status_response,
         )
     except ServiceError:
+        _emit_service_log_tail(console, paths.backend_log, "后端")
         stop_one(config.backend_port, paths.backend_pid, "后端", console)
         raise
 
@@ -882,6 +885,7 @@ def start_frontend(config: ServiceConfig, console) -> None:
     try:
         wait_for_http([config.frontend_url], "WebUI")
     except ServiceError:
+        _emit_service_log_tail(console, paths.frontend_log, "WebUI")
         stop_one(config.frontend_port, paths.frontend_pid, "WebUI", console)
         raise
 
@@ -1277,6 +1281,28 @@ def tail_lines(path: Path, lines: int) -> list[str]:
         return [line.rstrip("\n") for line in deque(handle, maxlen=max(lines, 0))]
 
 
+def _emit_service_log_tail(console, log_path: Path, service_label: str, lines: int = 40) -> None:
+    """Print the last *lines* lines of *log_path* to help diagnose failed daemon startups."""
+    if lines <= 0:
+        return
+    if not log_path.exists():
+        console.print(
+            f"[dim][flocks] {service_label} 日志文件尚不存在（{log_path}），"
+            "子进程可能启动即退出。[/dim]",
+        )
+        return
+    try:
+        excerpt = tail_lines(log_path, lines)
+    except OSError as exc:
+        console.print(f"[dim][flocks] 无法读取 {service_label} 日志: {exc}[/dim]")
+        return
+    if not excerpt:
+        return
+    console.print(f"[yellow][flocks] {service_label} 近期日志（最后 {len(excerpt)} 行）:[/yellow]")
+    for line in excerpt:
+        console.print(f"[dim]{line}[/dim]")
+
+
 def append_unique_pids(existing: Iterable[int], additions: Iterable[int]) -> list[int]:
     """Return a deduplicated pid list preserving order."""
     result: list[int] = []

flocks/updater/updater.py

@@ -62,6 +62,13 @@
 log = Log.create(service="updater")
 
 
+def _record_update_journal(message: str) -> None:
+    """Append a human-readable line to ``update.log`` (see ``append_upgrade_text_log``)."""
+    from flocks.utils.log import append_upgrade_text_log
+
+    append_upgrade_text_log(message)
+
+
 @dataclass(frozen=True)
 class UpdateMirrorProfile:
     """Resolved download/runtime mirror settings for a single upgrade request."""
@@ -1903,9 +1910,11 @@ async def perform_update(
     except Exception as exc:
         shutil.rmtree(tmp_dir, ignore_errors=True)
         log.error("updater.download.all_failed", {"error": str(exc)})
+        _dl_msg = "Failed to download the update. Please check your network connection."
+        _record_update_journal(f"ERROR {_dl_msg} ({exc})")
         yield UpdateProgress(
             stage="error",
-            message="Failed to download the update. Please check your network connection.",
+            message=_dl_msg,
             success=False,
         )
         return
@@ -1945,6 +1954,7 @@ async def perform_update(
         msg = f"Failed to extract files: {exc}"
         if backup_path:
             msg += f"\nRestore from backup: {backup_path}"
+        _record_update_journal(f"ERROR {msg}")
         yield UpdateProgress(stage="error", message=msg, success=False)
         return
 
@@ -1965,9 +1975,11 @@ async def perform_update(
             )
             if code != 0:
                 shutil.rmtree(tmp_dir, ignore_errors=True)
+                _fe_dep = f"Frontend dependency install failed: {err}"
+                _record_update_journal(f"ERROR {_fe_dep}")
                 yield UpdateProgress(
                     stage="error",
-                    message=f"Frontend dependency install failed: {err}",
+                    message=_fe_dep,
                     success=False,
                 )
                 return
@@ -1981,9 +1993,11 @@ async def perform_update(
             )
             if code != 0:
                 shutil.rmtree(tmp_dir, ignore_errors=True)
+                _fe_build = f"Frontend build failed: {err}"
+                _record_update_journal(f"ERROR {_fe_build}")
                 yield UpdateProgress(
                     stage="error",
-                    message=f"Frontend build failed: {err}",
+                    message=_fe_build,
                     success=False,
                 )
                 return
@@ -1997,9 +2011,11 @@ async def perform_update(
         dist_index = staged_webui_dir / "dist" / "index.html"
         if not dist_index.exists():
             shutil.rmtree(tmp_dir, ignore_errors=True)
+            _fe_miss = "Frontend build output is missing; upgrade aborted before cutover."
+            _record_update_journal(f"ERROR {_fe_miss}")
             yield UpdateProgress(
                 stage="error",
-                message="Frontend build output is missing; upgrade aborted before cutover.",
+                message=_fe_miss,
                 success=False,
             )
             return
@@ -2092,6 +2108,7 @@ async def _restore_after_apply_failure() -> None:
         )
         if sys.platform == "win32":
             hint = "Dependency sync failed: uv is required to refresh the Windows project runtime."
+        _record_update_journal(f"ERROR {hint}")
         yield UpdateProgress(stage="error", message=hint, success=False)
         return
 
@@ -2203,7 +2220,7 @@ async def _restore_after_apply_failure() -> None:
             handover_active = False
         yield UpdateProgress(
             stage="error",
-            message=f"Failed to build restart command: {exc}",
+            message=_rb_msg,
             success=False,
         )
         return
@@ -2234,7 +2251,7 @@ async def _restore_after_apply_failure() -> None:
                 handover_active = False
             yield UpdateProgress(
                 stage="error",
-                message=f"Failed to restart service: {exc}",
+                message=_rs_win,
                 success=False,
             )
             return
@@ -2252,7 +2269,7 @@ async def _restore_after_apply_failure() -> None:
             handover_active = False
         yield UpdateProgress(
             stage="error",
-            message=f"Failed to restart service: {exc}",
+            message=_rs_unix,
             success=False,
         )
         return

flocks/utils/log.py

@@ -33,6 +33,25 @@ def get_log_dir() -> Path:
     return _log_dir()
 
 
+def append_upgrade_text_log(message: str) -> None:
+    """Append timestamped lines to ``update.log`` under the configured log directory.
+
+    Used for upgrade flows so errors remain on disk when the process had no TTY
+    or when structured ``Log`` output went to a different file than ``backend.log``.
+    """
+    try:
+        log_dir = _log_dir()
+        log_dir.mkdir(parents=True, exist_ok=True)
+        path = log_dir / "update.log"
+        stamp = datetime.now().strftime("%Y-%m-%d %H:%M:%S")
+        normalized = message.replace("\r\n", "\n").replace("\r", "\n")
+        with path.open("a", encoding="utf-8") as handle:
+            for segment in normalized.split("\n"):
+                handle.write(f"{stamp} | {segment}\n")
+    except OSError:
+        return
+
+
 # Log levels - matches TypeScript exactly
 class LogLevel:
     """Log levels"""

tests/cli/test_service_manager.py

@@ -767,11 +767,14 @@ def test_start_backend_writes_runtime_metadata(monkeypatch, tmp_path: Path) -> N
         "resolve_flocks_cli_command",
         lambda root=None: ["python", "-m", "flocks.cli.main"],
     )
-    monkeypatch.setattr(
-        service_manager,
-        "_spawn_process",
-        lambda *_args, **_kwargs: SimpleNamespace(pid=2468),
-    )
+    spawn_env: dict[str, str] | None = None
+
+    def _capture_spawn(*_args, **kwargs) -> SimpleNamespace:
+        nonlocal spawn_env
+        spawn_env = kwargs.get("env")
+        return SimpleNamespace(pid=2468)
+
+    monkeypatch.setattr(service_manager, "_spawn_process", _capture_spawn)
 
     service_manager.start_backend(service_manager.ServiceConfig(), console)
 
@@ -795,9 +798,11 @@ def test_start_backend_writes_runtime_metadata(monkeypatch, tmp_path: Path) -> N
         "urls": ["http://127.0.0.1:8000"],
         "name": "后端服务",
         "attempts": 30,
-        "delay": 1.0,
+        "delay": 3.0,
         "validator": service_manager._is_running_status_response,
     }]
+    assert spawn_env is not None
+    assert spawn_env.get("PYTHONUNBUFFERED") == "1"
 
 
 def test_start_backend_rolls_back_when_probe_fails(monkeypatch, tmp_path: Path) -> None:
@@ -812,6 +817,7 @@ def test_start_backend_rolls_back_when_probe_fails(monkeypatch, tmp_path: Path)
     )
     paths.run_dir.mkdir(parents=True)
     paths.log_dir.mkdir(parents=True)
+    paths.backend_log.write_text("line1\nline2\nboot failed here\n", encoding="utf-8")
     console = DummyConsole()
     stop_calls: list[tuple[int, Path, str]] = []
 
@@ -845,6 +851,9 @@ def test_start_backend_rolls_back_when_probe_fails(monkeypatch, tmp_path: Path)
         service_manager.start_backend(service_manager.ServiceConfig(), console)
 
     assert stop_calls == [(8000, paths.backend_pid, "后端")]
+    joined = "\n".join(console.messages)
+    assert "近期日志" in joined
+    assert "boot failed here" in joined
 
 
 def test_start_backend_reports_started_after_probe_succeeds(monkeypatch, tmp_path: Path) -> None:

tests/cli/test_uvicorn_log_config.py

@@ -0,0 +1,11 @@
+"""Uvicorn log config used by ``flocks serve``."""
+
+from flocks.cli import main as cli_main
+
+
+def test_uvicorn_log_config_adds_asctime_to_formatters() -> None:
+    cfg = cli_main._uvicorn_log_config()
+    assert "%(asctime)s |" in cfg["formatters"]["default"]["fmt"]
+    assert "%(asctime)s |" in cfg["formatters"]["access"]["fmt"]
+    assert cfg["formatters"]["default"]["datefmt"] == "%Y-%m-%d %H:%M:%S"
+    assert cfg["formatters"]["access"]["datefmt"] == "%Y-%m-%d %H:%M:%S"

tests/utils/test_append_upgrade_log.py

@@ -0,0 +1,18 @@
+"""Tests for ``append_upgrade_text_log``."""
+
+import re
+from pathlib import Path
+
+from flocks.utils.log import append_upgrade_text_log
+
+
+def test_append_upgrade_text_log_writes_timestamped_lines(monkeypatch, tmp_path: Path) -> None:
+    monkeypatch.setenv("FLOCKS_LOG_DIR", str(tmp_path))
+    append_upgrade_text_log("first line")
+    append_upgrade_text_log("a\nb")
+    text = (tmp_path / "update.log").read_text(encoding="utf-8")
+    lines = text.strip().splitlines()
+    assert len(lines) == 3
+    assert re.match(r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} \| first line$", lines[0])
+    assert re.match(r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} \| a$", lines[1])
+    assert re.match(r"^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} \| b$", lines[2])