增加sqlalchemy后端，优化日志结构

2026-04-07 20:22:25 +08:00
parent c377264610
commit ba73b30a04
23 changed files with 1586 additions and 308 deletions
@@ -10,6 +10,8 @@ import pytest
 import httpx

 from sync_state_machine.datasource.api.client import ApiClient
+from sync_state_machine.datasource.api.datasource import ApiDataSource
+from sync_state_machine.logging import clear_scope_display_names, set_scope_display_name


 class _FakeResponse:
@@ -50,6 +52,25 @@ class _FailingAsyncClient:
        self.closed = True


+class _FakeCollection:
+    def __init__(self, scope: str) -> None:
+        self.scope = scope
+
+    def set_state_machine_runtime(self, runtime) -> None:
+        del runtime
+
+
+class _FakeProjectNode:
+    node_type = "project"
+
+    def __init__(self, data_id: str, name: str) -> None:
+        self.data_id = data_id
+        self._data = {"name": name}
+
+    def get_data(self) -> dict:
+        return dict(self._data)
+
+
@pytest.mark.asyncio
 async def test_api_client_global_rate_limit_applies_to_concurrent_requests() -> None:
    client = ApiClient(
@@ -120,6 +141,78 @@ async def test_api_client_logs_one_line_request_summary_in_debug_mode(caplog: py
    assert "🔎 ApiClient request: method=GET endpoint=/ping elapsed=" in caplog.text


+@pytest.mark.asyncio
+async def test_api_client_request_summary_includes_session_label_with_scope_fallback(
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    clear_scope_display_names()
+    client = ApiClient(
+        base_url="http://example.com",
+        uid="uid",
+        secret="secret",
+        debug=True,
+    )
+    logger_name = "sync_state_machine.datasource.api.client"
+    fake_client = _FakeAsyncClient()
+    client._client = fake_client
+    client.set_scope("project_id:project-1")
+
+    with caplog.at_level(logging.INFO, logger=logger_name):
+        await client.request("GET", "/ping")
+
+    assert "session=project_id:project-1 method=GET endpoint=/ping" in caplog.text
+
+    caplog.clear()
+    client.set_session_label("project:Alpha")
+
+    with caplog.at_level(logging.INFO, logger=logger_name):
+        await client.request("GET", "/ping")
+
+    assert "session=project:Alpha method=GET endpoint=/ping" in caplog.text
+    clear_scope_display_names()
+
+
+@pytest.mark.asyncio
+async def test_api_client_request_summary_uses_registered_project_name_for_project_id_requests(
+    caplog: pytest.LogCaptureFixture,
+) -> None:
+    clear_scope_display_names()
+    set_scope_display_name("project_id:project-1", "project:Alpha")
+    client = ApiClient(
+        base_url="http://example.com",
+        uid="uid",
+        secret="secret",
+        debug=True,
+    )
+    logger_name = "sync_state_machine.datasource.api.client"
+    fake_client = _FakeAsyncClient()
+    client._client = fake_client
+    client.set_scope("global")
+
+    with caplog.at_level(logging.INFO, logger=logger_name):
+        await client.request("GET", "/supplier/list", params={"project_id": "project-1"})
+
+    clear_scope_display_names()
+    assert "session=project:Alpha method=GET endpoint=/supplier/list" in caplog.text
+
+
+def test_api_datasource_updates_client_session_label_from_project_node() -> None:
+    clear_scope_display_names()
+    datasource = ApiDataSource(
+        base_url="http://example.com",
+        uid="uid",
+        secret="secret",
+        debug=True,
+    )
+
+    datasource.set_collection(_FakeCollection("project_id:project-1"))
+    assert datasource.client.get_log_session_label() == "project_id:project-1"
+
+    datasource._on_node_loaded(None, _FakeProjectNode(data_id="project-1", name="Alpha"))
+    assert datasource.client.get_log_session_label() == "project:Alpha"
+    clear_scope_display_names()
+
+
@pytest.mark.asyncio
 async def test_api_client_get_signature_keeps_list_params_in_signature_source() -> None:
    client = ApiClient(
@@ -0,0 +1,147 @@
+from __future__ import annotations
+
+from pathlib import Path
+
+import pytest
+from sqlalchemy.dialects import mysql
+from sqlalchemy.schema import CreateTable
+
+from sync_state_machine.common.binding import BindingManager
+from sync_state_machine.common.collection import DataCollection
+from sync_state_machine.common.persistence import PersistenceBackend, create_persistence_backend
+from sync_state_machine.common.sqlalchemy_backend import SQLAlchemyPersistenceBackend
+from sync_state_machine.config.persist_config import PersistConfig
+from tests.fixtures.mock_domain import build_project_node, register_test_domain
+
+
+def test_persist_config_accepts_sqlalchemy_url_only() -> None:
+    cfg = PersistConfig(
+        backend="sqlalchemy",
+        url="postgresql+asyncpg://user:pass@localhost:5432/persist_db",
+    )
+
+    assert cfg.resolved_url() == "postgresql+asyncpg://user:pass@localhost:5432/persist_db"
+    assert cfg.resolved_db_path() is None
+    assert cfg.wipe_file_path() is None
+    assert cfg.display_target() == "postgresql+asyncpg://user:pass@localhost:5432/persist_db"
+
+
+def test_persist_config_keeps_sqlite_db_path_compatible() -> None:
+    cfg = PersistConfig(backend="sqlite", db_path="runtime/test.db")
+
+    assert cfg.resolved_url() == "sqlite+aiosqlite:///runtime/test.db"
+    assert cfg.resolved_db_path() == "runtime/test.db"
+    assert cfg.wipe_file_path() == "runtime/test.db"
+    assert cfg.display_target() == "runtime/test.db"
+
+
+@pytest.mark.asyncio
+async def test_sqlalchemy_backend_sqlite_url_creates_schema_and_persists(tmp_path: Path) -> None:
+    register_test_domain()
+
+    db_path = tmp_path / "sqlalchemy_persist.db"
+    cfg = PersistConfig(backend="sqlalchemy", url=f"sqlite+aiosqlite:///{db_path}")
+    backend = create_persistence_backend(cfg)
+
+    assert isinstance(backend, SQLAlchemyPersistenceBackend)
+
+    await backend.initialize()
+
+    local_collection = DataCollection("local", scope="scope-a", persistence=backend, auto_persist=False)
+    bindings = BindingManager(backend, auto_persist=False, scope="scope-a")
+
+    node = build_project_node("node-1", "project-1", name="Project 1", code="P1")
+    await local_collection.add(node)
+    await local_collection.persist()
+    await bindings.bind("test_project", node.node_id, "remote-1")
+    await bindings.persist()
+
+    reloaded = DataCollection("local", scope="scope-a", persistence=backend, auto_persist=False)
+    await reloaded.load_from_persistence()
+    loaded_nodes = reloaded.filter(node_type="test_project")
+    assert len(loaded_nodes) == 1
+    assert loaded_nodes[0].data_id == "project-1"
+
+    reloaded_bindings = BindingManager(backend, auto_persist=False, scope="scope-a")
+    await reloaded_bindings.load_from_persistence("test_project")
+    assert await reloaded_bindings.get_remote_id("test_project", "node-1") == "remote-1"
+
+    columns, rows = PersistenceBackend.query_records(
+        backend="sqlite",
+        db_path=str(db_path),
+        sql="PRAGMA index_list('nodes')",
+    )
+    assert columns == ["seq", "name", "unique", "origin", "partial"]
+    assert any(row["name"] == "idx_nodes_scope_type_node_id" for row in rows)
+
+    sqlalchemy_columns, sqlalchemy_rows = PersistenceBackend.query_records(
+        backend="sqlalchemy",
+        url=f"sqlite+aiosqlite:///{db_path}",
+        sql="SELECT scope, collection_id, COUNT(1) AS count FROM nodes GROUP BY scope, collection_id ORDER BY scope, collection_id",
+    )
+    assert sqlalchemy_columns == ["scope", "collection_id", "count"]
+    assert sqlalchemy_rows == [{"scope": "scope-a", "collection_id": "local", "count": 1}]
+
+    sqlalchemy_summary = PersistenceBackend.records_summary(
+        backend="sqlalchemy",
+        url=f"sqlite+aiosqlite:///{db_path}",
+    )
+    assert any(item["name"] == "nodes" for item in sqlalchemy_summary["tables"])
+    assert any(item["name"] == "bindings" for item in sqlalchemy_summary["tables"])
+
+    await backend.close()
+
+
+@pytest.mark.asyncio
+async def test_sqlalchemy_backend_bulk_replace_chunks_delete_batches(tmp_path: Path) -> None:
+    register_test_domain()
+
+    db_path = tmp_path / "sqlalchemy_chunked_persist.db"
+    cfg = PersistConfig(backend="sqlalchemy", url=f"sqlite+aiosqlite:///{db_path}")
+    backend = create_persistence_backend(cfg)
+
+    assert isinstance(backend, SQLAlchemyPersistenceBackend)
+
+    backend.bulk_delete_batch_size = 2
+    await backend.initialize()
+
+    collection = DataCollection("local", scope="scope-a", persistence=backend, auto_persist=False)
+    for index in range(5):
+        await collection.add(build_project_node(f"node-{index}", f"project-{index}", name=f"Project {index}", code=f"P{index}"))
+    await collection.persist()
+
+    refreshed = DataCollection("local", scope="scope-a", persistence=backend, auto_persist=False)
+    for index in range(5):
+        await refreshed.add(
+            build_project_node(f"node-{index}", f"project-{index}-updated", name=f"Project {index} Updated", code=f"Q{index}")
+        )
+    await refreshed.persist()
+
+    reloaded = DataCollection("local", scope="scope-a", persistence=backend, auto_persist=False)
+    await reloaded.load_from_persistence()
+    loaded_nodes = sorted(reloaded.filter(node_type="test_project"), key=lambda item: item.node_id)
+
+    assert len(loaded_nodes) == 5
+    assert [node.data_id for node in loaded_nodes] == [f"project-{index}-updated" for index in range(5)]
+
+    await backend.close()
+
+
+def test_sqlalchemy_backend_mysql_ddl_uses_varchar_for_keyed_columns() -> None:
+    backend = SQLAlchemyPersistenceBackend("mysql+aiomysql://root:123456@127.0.0.1/ecm_sync_system?charset=utf8mb4")
+
+    nodes_sql = str(CreateTable(backend.nodes).compile(dialect=mysql.dialect()))
+    bindings_sql = str(CreateTable(backend.bindings).compile(dialect=mysql.dialect()))
+
+    assert "collection_id VARCHAR(255) NOT NULL" in nodes_sql
+    assert "scope VARCHAR(255) NOT NULL" in nodes_sql
+    assert "node_id VARCHAR(255) NOT NULL" in nodes_sql
+    assert "node_type VARCHAR(128) NOT NULL" in nodes_sql
+    assert "data_id VARCHAR(255)" in nodes_sql
+    assert "bind_data_id VARCHAR(255)" in nodes_sql
+    assert "TEXT NOT NULL" not in nodes_sql
+
+    assert "scope VARCHAR(255) NOT NULL" in bindings_sql
+    assert "node_type VARCHAR(128) NOT NULL" in bindings_sql
+    assert "local_id VARCHAR(255) NOT NULL" in bindings_sql
+    assert "remote_id VARCHAR(255)" in bindings_sql
@@ -6,7 +6,7 @@ from io import StringIO
 import pytest

 from sync_state_machine.pipeline.summary_report import print_pipeline_summary
-from sync_state_machine.logging import get_scope_logger
+from sync_state_machine.logging import clear_scope_display_names, get_scope_logger, set_scope_display_name


 class _FakeBindingManager:
@@ -79,7 +79,57 @@ async def test_pipeline_summary_omits_diff_schemas_column() -> None:
    assert "None/'2025-11-14'" in output


+@pytest.mark.asyncio
+async def test_pipeline_summary_only_prefixes_headers_for_scoped_logger() -> None:
+    clear_scope_display_names()
+    set_scope_display_name("project_id:p1", "project:Alpha")
+    stream = StringIO()
+    base_logger = logging.getLogger("sync_state_machine.tests.summary_report_scoped")
+    base_logger.handlers.clear()
+    base_logger.setLevel(logging.INFO)
+    base_logger.propagate = False
+
+    handler = logging.StreamHandler(stream)
+    handler.setFormatter(logging.Formatter("%(message)s"))
+    base_logger.addHandler(handler)
+
+    try:
+        scoped_logger = get_scope_logger("project_id:p1", "tests.summary_report_scoped")
+        await print_pipeline_summary(
+            logger=scoped_logger,
+            node_types=["project"],
+            binding_manager=_FakeBindingManager(),
+            local_datasource=_FakeDataSource(),
+            remote_datasource=_FakeDataSource(),
+            local_collection=_FakeCollection(),
+            remote_collection=_FakeCollection(),
+            consistency_by_type={
+                "project": {
+                    "checked_pairs": 1,
+                    "mismatch_count": 0,
+                    "fields": [],
+                }
+            },
+            stats={
+                "loaded": 1,
+                "synced": 0,
+                "failed": 0,
+                "post_check_passed": True,
+            },
+        )
+    finally:
+        base_logger.removeHandler(handler)
+        clear_scope_display_names()
+
+    lines = [line for line in stream.getvalue().splitlines() if line.strip()]
+    assert any(line.startswith("[project:Alpha] 📊 Local Summary") for line in lines)
+    assert any(line == "Node Type                    Bound/Rec/Load   Create(S/F/T)    Update(S/F/T)    Delete(S/F/T)    Consistent(S/F/T) " for line in lines)
+    assert not any(line.startswith("[project:Alpha] Node Type") for line in lines)
+    assert not any(line.startswith("[project:Alpha] TOTAL") for line in lines)
+
+
 def test_scope_logger_prefixes_messages() -> None:
+    clear_scope_display_names()
    stream = StringIO()
    base_logger = logging.getLogger("sync_state_machine.tests.scope_logger")
    base_logger.handlers.clear()
@@ -96,4 +146,27 @@ def test_scope_logger_prefixes_messages() -> None:
    finally:
        base_logger.removeHandler(handler)

-    assert stream.getvalue().strip() == "[project_id:p1] Strategy start: project"
+    assert stream.getvalue().strip() == "[project_id:p1] Strategy start: project"
+
+
+def test_scope_logger_uses_registered_display_name() -> None:
+    clear_scope_display_names()
+    set_scope_display_name("project_id:p1", "project:Alpha")
+    stream = StringIO()
+    base_logger = logging.getLogger("sync_state_machine.tests.scope_logger_display")
+    base_logger.handlers.clear()
+    base_logger.setLevel(logging.INFO)
+    base_logger.propagate = False
+
+    handler = logging.StreamHandler(stream)
+    handler.setFormatter(logging.Formatter("%(message)s"))
+    base_logger.addHandler(handler)
+
+    try:
+        scoped_logger = get_scope_logger("project_id:p1", "tests.scope_logger_display")
+        scoped_logger.info("Strategy start: project")
+    finally:
+        base_logger.removeHandler(handler)
+        clear_scope_display_names()
+
+    assert stream.getvalue().strip() == "[project:Alpha] Strategy start: project"