diff --git a/backend/src/api/routes/__tests__/test_dataset_review_api.py b/backend/src/api/routes/__tests__/test_dataset_review_api.py index 0b9716b3..4f031484 100644 --- a/backend/src/api/routes/__tests__/test_dataset_review_api.py +++ b/backend/src/api/routes/__tests__/test_dataset_review_api.py @@ -6,7 +6,7 @@ from datetime import UTC, datetime import pytest from types import SimpleNamespace -from unittest.mock import MagicMock, patch +from unittest.mock import AsyncMock, MagicMock, patch from fastapi.testclient import TestClient @@ -538,7 +538,7 @@ def test_orchestrator_start_session_preserves_partial_recovery( ) fake_extractor = MagicMock() fake_extractor.parse_superset_link.return_value = parsed_context - fake_extractor.recover_imported_filters.return_value = [] + fake_extractor.recover_imported_filters = AsyncMock(return_value=[]) fake_extractor.client.get_dataset_detail.return_value = { "id": 42, "sql": "", @@ -597,7 +597,7 @@ def test_orchestrator_start_session_bootstraps_recovery_state( ) fake_extractor = MagicMock() fake_extractor.parse_superset_link.return_value = parsed_context - fake_extractor.recover_imported_filters.return_value = [ + fake_extractor.recover_imported_filters = AsyncMock(return_value=[ { "filter_name": "country", "display_name": "Country", @@ -615,7 +615,7 @@ def test_orchestrator_start_session_bootstraps_recovery_state( "recovery_status": "recovered", "notes": "Recovered from permalink state", } - ] + ]) fake_extractor.client.get_dataset_detail.return_value = { "id": 42, "sql": "select * from sales where country in {{ filter_values('country') }}", diff --git a/backend/src/api/routes/admin.py b/backend/src/api/routes/admin.py index d6ffebb4..78adb5f7 100644 --- a/backend/src/api/routes/admin.py +++ b/backend/src/api/routes/admin.py @@ -154,25 +154,17 @@ async def delete_user( _=Depends(has_permission("admin:users", "WRITE")), ): with belief_scope("api.admin.delete_user"): - logger.info( - f"[DEBUG] Attempting to delete user context={{'user_id': '{user_id}'}}" - ) + logger.reason("Attempting to delete user", payload={"user_id": user_id}) repo = AuthRepository(db) user = repo.get_user_by_id(user_id) if not user: - logger.warning( - f"[DEBUG] User not found for deletion context={{'user_id': '{user_id}'}}" - ) + logger.explore("User not found for deletion", payload={"user_id": user_id}, error="User does not exist") raise HTTPException(status_code=404, detail="User not found") - logger.info( - f"[DEBUG] Found user to delete context={{'username': '{user.username}'}}" - ) + logger.reflect("Found user to delete", payload={"username": user.username}) db.delete(user) db.commit() - logger.info( - f"[DEBUG] Successfully deleted user context={{'user_id': '{user_id}'}}" - ) + logger.reflect("Successfully deleted user", payload={"user_id": user_id}) return None diff --git a/backend/src/api/routes/assistant/_tool_llm_validation.py b/backend/src/api/routes/assistant/_tool_llm_validation.py index 7b1faa0c..5c15dd69 100644 --- a/backend/src/api/routes/assistant/_tool_llm_validation.py +++ b/backend/src/api/routes/assistant/_tool_llm_validation.py @@ -88,7 +88,7 @@ async def handle_run_llm_validation( screenshot_enabled=True, ) try: - task = validation_svc.create_task(task_payload) + task = await validation_svc.create_task(task_payload) except ValueError as e: raise HTTPException(status_code=422, detail=str(e)) logger.info( diff --git a/backend/src/api/routes/dashboards/_action_routes.py b/backend/src/api/routes/dashboards/_action_routes.py index c15a1c80..103a9ac5 100644 --- a/backend/src/api/routes/dashboards/_action_routes.py +++ b/backend/src/api/routes/dashboards/_action_routes.py @@ -44,9 +44,7 @@ async def migrate_dashboards( f"source={request.source_env_id}, target={request.target_env_id}, count={len(request.dashboard_ids)}", ): if not request.dashboard_ids: - logger.error( - "[migrate_dashboards][Coherence:Failed] No dashboard IDs provided" - ) + logger.explore("No dashboard IDs provided for migrate_dashboards", error="At least one dashboard ID must be provided") raise HTTPException( status_code=400, detail="At least one dashboard ID must be provided" ) @@ -60,14 +58,10 @@ async def migrate_dashboards( ) if not source_env: - logger.error( - f"[migrate_dashboards][Coherence:Failed] Source environment not found: {request.source_env_id}" - ) + logger.explore("Source environment not found for migrate_dashboards", payload={"source_env_id": request.source_env_id}, error=f"Source environment not found: {request.source_env_id}") raise HTTPException(status_code=404, detail="Source environment not found") if not target_env: - logger.error( - f"[migrate_dashboards][Coherence:Failed] Target environment not found: {request.target_env_id}" - ) + logger.explore("Target environment not found for migrate_dashboards", payload={"target_env_id": request.target_env_id}, error=f"Target environment not found: {request.target_env_id}") raise HTTPException(status_code=404, detail="Target environment not found") try: @@ -83,16 +77,12 @@ async def migrate_dashboards( plugin_id="superset-migration", params=task_params ) - logger.info( - f"[migrate_dashboards][Coherence:OK] Migration task created: {task_obj.id} for {len(request.dashboard_ids)} dashboards" - ) + logger.reflect("Migration task created", payload={"task_id": str(task_obj.id), "dashboard_count": len(request.dashboard_ids)}) return TaskResponse(task_id=str(task_obj.id)) except Exception as e: - logger.error( - f"[migrate_dashboards][Coherence:Failed] Failed to create migration task: {e}" - ) + logger.explore("Failed to create migration task", error=str(e)) raise HTTPException( status_code=503, detail=f"Failed to create migration task: {e!s}" ) @@ -124,9 +114,7 @@ async def backup_dashboards( f"env={request.env_id}, count={len(request.dashboard_ids)}, schedule={request.schedule}", ): if not request.dashboard_ids: - logger.error( - "[backup_dashboards][Coherence:Failed] No dashboard IDs provided" - ) + logger.explore("No dashboard IDs provided for backup_dashboards", error="At least one dashboard ID must be provided") raise HTTPException( status_code=400, detail="At least one dashboard ID must be provided" ) @@ -135,9 +123,7 @@ async def backup_dashboards( env = next((e for e in environments if e.id == request.env_id), None) if not env: - logger.error( - f"[backup_dashboards][Coherence:Failed] Environment not found: {request.env_id}" - ) + logger.explore("Environment not found for backup_dashboards", payload={"env_id": request.env_id}, error=f"Environment not found: {request.env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -151,16 +137,12 @@ async def backup_dashboards( plugin_id="superset-backup", params=task_params ) - logger.info( - f"[backup_dashboards][Coherence:OK] Backup task created: {task_obj.id} for {len(request.dashboard_ids)} dashboards" - ) + logger.reflect("Backup task created", payload={"task_id": str(task_obj.id), "dashboard_count": len(request.dashboard_ids)}) return TaskResponse(task_id=str(task_obj.id)) except Exception as e: - logger.error( - f"[backup_dashboards][Coherence:Failed] Failed to create backup task: {e}" - ) + logger.explore("Failed to create backup task", error=str(e)) raise HTTPException( status_code=503, detail=f"Failed to create backup task: {e!s}" ) diff --git a/backend/src/api/routes/dashboards/_detail_routes.py b/backend/src/api/routes/dashboards/_detail_routes.py index d0b90667..8a5095a0 100644 --- a/backend/src/api/routes/dashboards/_detail_routes.py +++ b/backend/src/api/routes/dashboards/_detail_routes.py @@ -64,14 +64,10 @@ async def get_database_mappings( target_env = next((e for e in environments if e.id == target_env_id), None) if not source_env: - logger.error( - f"[get_database_mappings][Coherence:Failed] Source environment not found: {source_env_id}" - ) + logger.explore("Source environment not found for get_database_mappings", payload={"source_env_id": source_env_id}, error=f"Source environment not found: {source_env_id}") raise HTTPException(status_code=404, detail="Source environment not found") if not target_env: - logger.error( - f"[get_database_mappings][Coherence:Failed] Target environment not found: {target_env_id}" - ) + logger.explore("Target environment not found for get_database_mappings", payload={"target_env_id": target_env_id}, error=f"Target environment not found: {target_env_id}") raise HTTPException(status_code=404, detail="Target environment not found") try: @@ -90,16 +86,12 @@ async def get_database_mappings( for s in suggestions ] - logger.info( - f"[get_database_mappings][Coherence:OK] Returning {len(mappings)} database mapping suggestions" - ) + logger.reflect("Returning database mapping suggestions", payload={"count": len(mappings)}) return DatabaseMappingsResponse(mappings=mappings) except Exception as e: - logger.error( - f"[get_database_mappings][Coherence:Failed] Failed to get database mappings: {e}" - ) + logger.explore("Failed to get database mappings", error=str(e)) raise HTTPException( status_code=503, detail=f"Failed to get database mappings: {e!s}" ) @@ -127,9 +119,7 @@ async def get_dashboard_detail( environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error( - f"[get_dashboard_detail][Coherence:Failed] Environment not found: {env_id}" - ) + logger.explore("Environment not found for get_dashboard_detail", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -150,16 +140,12 @@ async def get_dashboard_detail( dashboard_ref, client ) detail = await client.get_dashboard_detail(dashboard_id) - logger.info( - f"[get_dashboard_detail][Coherence:OK] Dashboard ref={dashboard_ref} resolved_id={dashboard_id}: {detail.get('chart_count', 0)} charts, {detail.get('dataset_count', 0)} datasets" - ) + logger.reflect("Dashboard detail retrieved", payload={"dashboard_ref": dashboard_ref, "dashboard_id": dashboard_id, "chart_count": detail.get("chart_count", 0), "dataset_count": detail.get("dataset_count", 0)}) return DashboardDetailResponse(**detail) except HTTPException: raise except Exception as e: - logger.error( - f"[get_dashboard_detail][Coherence:Failed] Failed to fetch dashboard detail: {e}" - ) + logger.explore("Failed to fetch dashboard detail", payload={"dashboard_ref": dashboard_ref}, error=str(e)) raise HTTPException( status_code=503, detail=f"Failed to fetch dashboard detail: {e!s}" ) @@ -195,18 +181,14 @@ async def get_dashboard_tasks_history( environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error( - f"[get_dashboard_tasks_history][Coherence:Failed] Environment not found: {env_id}" - ) + logger.explore("Environment not found for get_dashboard_tasks_history", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") client = SupersetClient(env) dashboard_id = await _resolve_dashboard_id_from_ref_async( dashboard_ref, client ) else: - logger.error( - "[get_dashboard_tasks_history][Coherence:Failed] Non-numeric dashboard ref requires env_id" - ) + logger.explore("Non-numeric dashboard ref requires env_id", payload={"dashboard_ref": dashboard_ref}, error="Non-numeric dashboard ref requires env_id") raise HTTPException( status_code=400, detail="env_id is required when dashboard reference is a slug", @@ -259,9 +241,7 @@ async def get_dashboard_tasks_history( ) ) - logger.info( - f"[get_dashboard_tasks_history][Coherence:OK] Found {len(items)} tasks for dashboard_ref={dashboard_ref}, dashboard_id={dashboard_id}" - ) + logger.reflect("Dashboard tasks history retrieved", payload={"task_count": len(items), "dashboard_ref": dashboard_ref, "dashboard_id": dashboard_id}) return DashboardTaskHistoryResponse(dashboard_id=dashboard_id, items=items) finally: if client is not None: @@ -292,9 +272,7 @@ async def get_dashboard_thumbnail( environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error( - f"[get_dashboard_thumbnail][Coherence:Failed] Environment not found: {env_id}" - ) + logger.explore("Environment not found for get_dashboard_thumbnail", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -338,9 +316,7 @@ async def get_dashboard_thumbnail( if matched: digest = matched.group(1) except DashboardNotFoundError: - logger.warning( - "[get_dashboard_thumbnail][Fallback] cache_dashboard_screenshot endpoint unavailable, fallback to dashboard.thumbnail_url" - ) + logger.explore("cache_dashboard_screenshot endpoint unavailable, fallback to thumbnail_url", payload={"dashboard_id": dashboard_id}, error="cache_dashboard_screenshot not available") if not digest: dashboard_payload = await async_client.request( @@ -392,16 +368,12 @@ async def get_dashboard_thumbnail( content_type = thumb_response.headers.get("Content-Type", "image/png") return Response(content=thumb_response.content, media_type=content_type) except DashboardNotFoundError as e: - logger.error( - f"[get_dashboard_thumbnail][Coherence:Failed] Dashboard not found for thumbnail: {e}" - ) + logger.explore("Dashboard not found for thumbnail", payload={"dashboard_ref": dashboard_ref}, error=str(e)) raise HTTPException(status_code=404, detail="Dashboard thumbnail not found") except HTTPException: raise except Exception as e: - logger.error( - f"[get_dashboard_thumbnail][Coherence:Failed] Failed to fetch dashboard thumbnail: {e}" - ) + logger.explore("Failed to fetch dashboard thumbnail", payload={"dashboard_ref": dashboard_ref}, error=str(e)) raise HTTPException( status_code=503, detail=f"Failed to fetch dashboard thumbnail: {e!s}", diff --git a/backend/src/api/routes/dashboards/_listing_routes.py b/backend/src/api/routes/dashboards/_listing_routes.py index b2c99ab5..5c5d23e6 100644 --- a/backend/src/api/routes/dashboards/_listing_routes.py +++ b/backend/src/api/routes/dashboards/_listing_routes.py @@ -72,16 +72,16 @@ async def get_dashboards( f"page_context={page_context}, applyp={apply_profile_default}, overhide={override_show_all}", ): if page < 1: - logger.error(f"[get_dashboards][Coherence:Failed] Invalid page: {page}") + logger.explore("Invalid page parameter", payload={"page": page}, error="Page must be >= 1") raise HTTPException(status_code=400, detail="Page must be >= 1") if page_size < 1 or page_size > 100: - logger.error(f"[get_dashboards][Coherence:Failed] Invalid page_size: {page_size}") + logger.explore("Invalid page_size parameter", payload={"page_size": page_size}, error="Page size must be between 1 and 100") raise HTTPException(status_code=400, detail="Page size must be between 1 and 100") environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error(f"[get_dashboards][Coherence:Failed] Environment not found: {env_id}") + logger.explore("Environment not found for get_dashboards", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") bound_username: str | None = None @@ -360,10 +360,13 @@ async def get_dashboards( end_idx = start_idx + page_size paginated_dashboards = dashboards[start_idx:end_idx] - logger.info( - f"[get_dashboards][Coherence:OK] Returning {len(paginated_dashboards)} dashboards " - f"(page {page}/{total_pages}, total: {total}, profile_filter_applied={effective_profile_filter.applied})" - ) + logger.reflect("Returning paginated dashboards", payload={ + "count": len(paginated_dashboards), + "page": page, + "total_pages": total_pages, + "total": total, + "profile_filter_applied": effective_profile_filter.applied, + }) response_dashboards = _project_dashboard_response_items( paginated_dashboards @@ -381,9 +384,7 @@ async def get_dashboards( except HTTPException: raise except Exception as e: - logger.error( - f"[get_dashboards][Coherence:Failed] Failed to fetch dashboards: {e}" - ) + logger.explore("Failed to fetch dashboards", error=str(e)) raise HTTPException( status_code=503, detail=f"Failed to fetch dashboards: {e!s}" ) diff --git a/backend/src/api/routes/datasets.py b/backend/src/api/routes/datasets.py index 4d712608..df80341a 100644 --- a/backend/src/api/routes/datasets.py +++ b/backend/src/api/routes/datasets.py @@ -168,7 +168,7 @@ async def get_dataset_ids( environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error(f"[get_dataset_ids][Coherence:Failed] Environment not found: {env_id}") + logger.explore("Environment not found for get_dataset_ids", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -188,12 +188,12 @@ async def get_dataset_ids( # Extract and return just the IDs dataset_ids = [d['id'] for d in datasets] - logger.info(f"[get_dataset_ids][Coherence:OK] Returning {len(dataset_ids)} dataset IDs") + logger.reflect("Returning dataset IDs", payload={"count": len(dataset_ids)}) return {"dataset_ids": dataset_ids} except Exception as e: - logger.error(f"[get_dataset_ids][Coherence:Failed] Failed to fetch dataset IDs: {e}") + logger.explore("Failed to fetch dataset IDs", error=str(e)) raise HTTPException(status_code=503, detail=f"Failed to fetch dataset IDs: {e!s}") # #endregion get_dataset_ids @@ -222,17 +222,17 @@ async def get_datasets( with belief_scope("get_datasets", f"env_id={env_id}, search={search}, filter={filter}, page={page}, page_size={page_size}"): # Validate pagination parameters if page < 1: - logger.error(f"[get_datasets][Coherence:Failed] Invalid page: {page}") + logger.explore("Invalid page parameter", payload={"page": page}, error="Page must be >= 1") raise HTTPException(status_code=400, detail="Page must be >= 1") if page_size < 1 or page_size > 100: - logger.error(f"[get_datasets][Coherence:Failed] Invalid page_size: {page_size}") + logger.explore("Invalid page_size parameter", payload={"page_size": page_size}, error="Page size must be between 1 and 100") raise HTTPException(status_code=400, detail="Page size must be between 1 and 100") # Validate environment exists environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error(f"[get_datasets][Coherence:Failed] Environment not found: {env_id}") + logger.explore("Environment not found for get_datasets", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -298,7 +298,7 @@ async def get_datasets( # Slice datasets for current page paginated_datasets = datasets[start_idx:end_idx] - logger.info(f"[get_datasets][Coherence:OK] Returning {len(paginated_datasets)} datasets (page {page}/{total_pages}, total: {total}, stats: total={stats.total} unmapped={stats.unmapped_count} mapped={stats.mapped_count} linked={stats.linked_count})") + logger.reflect("Returning paginated datasets", payload={"count": len(paginated_datasets), "page": page, "total_pages": total_pages, "total": total, "stats": {"total": stats.total, "unmapped": stats.unmapped_count, "mapped": stats.mapped_count, "linked": stats.linked_count}}) return DatasetsResponse( datasets=paginated_datasets, @@ -310,7 +310,7 @@ async def get_datasets( ) except Exception as e: - logger.error(f"[get_datasets][Coherence:Failed] Failed to fetch datasets: {e}") + logger.explore("Failed to fetch datasets", error=str(e)) raise HTTPException(status_code=503, detail=f"Failed to fetch datasets: {e!s}") # #endregion get_datasets @@ -345,12 +345,12 @@ async def map_columns( with belief_scope("map_columns", f"env={request.env_id}, count={len(request.dataset_ids)}, source={request.source_type}"): # Validate request if not request.dataset_ids: - logger.error("[map_columns][Coherence:Failed] No dataset IDs provided") + logger.explore("No dataset IDs provided for map_columns", error="At least one dataset ID must be provided") raise HTTPException(status_code=400, detail="At least one dataset ID must be provided") # Validate source type if request.source_type not in ['sqllab', 'xlsx']: - logger.error(f"[map_columns][Coherence:Failed] Invalid source type: {request.source_type}") + logger.explore("Invalid source type for map_columns", payload={"source_type": request.source_type}, error=f"Invalid source type: {request.source_type}") raise HTTPException(status_code=400, detail="Source type must be 'sqllab' or 'xlsx'") # Validate database_id for sqllab source @@ -362,7 +362,7 @@ async def map_columns( env = next((e for e in environments if e.id == request.env_id), None) if not env: - logger.error(f"[map_columns][Coherence:Failed] Environment not found: {request.env_id}") + logger.explore("Environment not found for map_columns", payload={"env_id": request.env_id}, error=f"Environment not found: {request.env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -381,12 +381,12 @@ async def map_columns( params=task_params ) - logger.info(f"[map_columns][Coherence:OK] Mapping task created: {task_obj.id} for {len(request.dataset_ids)} datasets") + logger.reflect("Mapping task created", payload={"task_id": str(task_obj.id), "dataset_count": len(request.dataset_ids)}) return TaskResponse(task_id=str(task_obj.id)) except Exception as e: - logger.error(f"[map_columns][Coherence:Failed] Failed to create mapping task: {e}") + logger.explore("Failed to create mapping task", error=str(e)) raise HTTPException(status_code=503, detail=f"Failed to create mapping task: {e!s}") # #endregion map_columns @@ -419,7 +419,7 @@ async def generate_docs( with belief_scope("generate_docs", f"env={request.env_id}, count={len(request.dataset_ids)}, provider={request.llm_provider}"): # Validate request if not request.dataset_ids: - logger.error("[generate_docs][Coherence:Failed] No dataset IDs provided") + logger.explore("No dataset IDs provided for generate_docs", error="At least one dataset ID must be provided") raise HTTPException(status_code=400, detail="At least one dataset ID must be provided") # Validate environment exists @@ -427,7 +427,7 @@ async def generate_docs( env = next((e for e in environments if e.id == request.env_id), None) if not env: - logger.error(f"[generate_docs][Coherence:Failed] Environment not found: {request.env_id}") + logger.explore("Environment not found for generate_docs", payload={"env_id": request.env_id}, error=f"Environment not found: {request.env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -444,12 +444,12 @@ async def generate_docs( params=task_params ) - logger.info(f"[generate_docs][Coherence:OK] Documentation generation task created: {task_obj.id} for {len(request.dataset_ids)} datasets") + logger.reflect("Documentation generation task created", payload={"task_id": str(task_obj.id), "dataset_count": len(request.dataset_ids)}) return TaskResponse(task_id=str(task_obj.id)) except Exception as e: - logger.error(f"[generate_docs][Coherence:Failed] Failed to create documentation generation task: {e}") + logger.explore("Failed to create documentation generation task", error=str(e)) raise HTTPException(status_code=503, detail=f"Failed to create documentation generation task: {e!s}") # #endregion generate_docs @@ -472,7 +472,7 @@ async def get_dataset_detail( environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error(f"[get_dataset_detail][Coherence:Failed] Environment not found: {env_id}") + logger.explore("Environment not found for get_dataset_detail", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -485,12 +485,12 @@ async def get_dataset_detail( db_obj = dataset_detail["database"] dataset_detail["database"] = db_obj.get("database_name", str(db_obj.get("id", ""))) - logger.info(f"[get_dataset_detail][Coherence:OK] Retrieved dataset {dataset_id} with {dataset_detail['column_count']} columns and {dataset_detail['linked_dashboard_count']} linked dashboards") + logger.reflect("Retrieved dataset detail", payload={"dataset_id": dataset_id, "column_count": dataset_detail["column_count"], "linked_dashboard_count": dataset_detail["linked_dashboard_count"]}) return DatasetDetailResponse(**dataset_detail) except Exception as e: - logger.error(f"[get_dataset_detail][Coherence:Failed] Failed to fetch dataset detail: {e}") + logger.explore("Failed to fetch dataset detail", payload={"dataset_id": dataset_id}, error=str(e)) raise HTTPException(status_code=503, detail=f"Failed to fetch dataset detail: {e!s}") # #endregion get_dataset_detail @@ -504,7 +504,7 @@ def _strip_html_tags(text: str) -> str: return text if re.search(r"<[^>]*>", text): cleaned = re.sub(r"<[^>]*>", "", text) - logger.warning("[_strip_html_tags] HTML tags detected and stripped from description") + logger.explore("HTML tags detected and stripped from description", payload={"function": "_strip_html_tags"}) return cleaned return text # #endregion _strip_html_tags @@ -534,14 +534,14 @@ async def update_column_description( # Validate and sanitize description description = _strip_html_tags(body.description) if len(description) > 2000: - logger.error(f"[update_column_description][Coherence:Failed] Description exceeds 2000 chars: {len(description)}") + logger.explore("Description exceeds maximum length for update_column_description", payload={"length": len(description)}, error="Description must not exceed 2000 characters") raise HTTPException(status_code=400, detail="Description must not exceed 2000 characters") # Validate environment environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error(f"[update_column_description][Coherence:Failed] Environment not found: {env_id}") + logger.explore("Environment not found for update_column_description", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -553,7 +553,7 @@ async def update_column_description( try: response = await client.get_dataset(dataset_id) except Exception as e: - logger.error(f"[update_column_description][Coherence:Failed] Superset GET failed: {e}") + logger.explore("Superset GET request failed for update_column_description", payload={"dataset_id": dataset_id}, error=str(e)) raise HTTPException(status_code=502, detail=f"Failed to fetch dataset from Superset: {e!s}") if isinstance(response, dict) and "result" in response: @@ -562,7 +562,7 @@ async def update_column_description( dataset = response if not dataset or not dataset.get("id"): - logger.error(f"[update_column_description][Coherence:Failed] Dataset {dataset_id} not found") + logger.explore("Dataset not found for update_column_description", payload={"dataset_id": dataset_id}, error=f"Dataset {dataset_id} not found") raise HTTPException(status_code=404, detail=f"Dataset {dataset_id} not found") # Find and modify the target column @@ -575,7 +575,7 @@ async def update_column_description( break if not found: - logger.error(f"[update_column_description][Coherence:Failed] Column {column_id} not found in dataset {dataset_id}") + logger.explore("Column not found for update_column_description", payload={"column_id": column_id, "dataset_id": dataset_id}, error=f"Column {column_id} not found") raise HTTPException(status_code=404, detail=f"Column {column_id} not found in dataset {dataset_id}") # PUT back with override_columns=false @@ -583,19 +583,16 @@ async def update_column_description( try: await client.update_dataset(dataset_id, put_payload, override_columns=False) except Exception as e: - logger.error(f"[update_column_description][Coherence:Failed] Superset PUT failed: {e}") + logger.explore("Superset PUT request failed for update_column_description", payload={"dataset_id": dataset_id}, error=str(e)) raise HTTPException(status_code=502, detail=f"Failed to update dataset in Superset: {e!s}") - logger.reflect( - f"Updated column {column_id} description for dataset {dataset_id}", - extra={"src": "update_column_description"}, - ) + logger.reflect("Column description updated", payload={"column_id": column_id, "dataset_id": dataset_id}) return {"success": True, "description": description} except HTTPException: raise except Exception as e: - logger.error(f"[update_column_description][Coherence:Failed] Unexpected error: {e}") + logger.explore("Unexpected error in update_column_description", payload={"dataset_id": dataset_id, "column_id": column_id}, error=str(e)) raise HTTPException(status_code=500, detail=f"Unexpected error: {e!s}") # #endregion update_column_description @@ -622,14 +619,14 @@ async def update_metric_description( # Validate and sanitize description description = _strip_html_tags(body.description) if len(description) > 2000: - logger.error(f"[update_metric_description][Coherence:Failed] Description exceeds 2000 chars: {len(description)}") + logger.explore("Description exceeds maximum length for update_metric_description", payload={"length": len(description)}, error="Description must not exceed 2000 characters") raise HTTPException(status_code=400, detail="Description must not exceed 2000 characters") # Validate environment environments = config_manager.get_environments() env = next((e for e in environments if e.id == env_id), None) if not env: - logger.error(f"[update_metric_description][Coherence:Failed] Environment not found: {env_id}") + logger.explore("Environment not found for update_metric_description", payload={"env_id": env_id}, error=f"Environment not found: {env_id}") raise HTTPException(status_code=404, detail="Environment not found") try: @@ -641,7 +638,7 @@ async def update_metric_description( try: response = await client.get_dataset(dataset_id) except Exception as e: - logger.error(f"[update_metric_description][Coherence:Failed] Superset GET failed: {e}") + logger.explore("Superset GET request failed for update_metric_description", payload={"dataset_id": dataset_id}, error=str(e)) raise HTTPException(status_code=502, detail=f"Failed to fetch dataset from Superset: {e!s}") if isinstance(response, dict) and "result" in response: @@ -650,7 +647,7 @@ async def update_metric_description( dataset = response if not dataset or not dataset.get("id"): - logger.error(f"[update_metric_description][Coherence:Failed] Dataset {dataset_id} not found") + logger.explore("Dataset not found for update_metric_description", payload={"dataset_id": dataset_id}, error=f"Dataset {dataset_id} not found") raise HTTPException(status_code=404, detail=f"Dataset {dataset_id} not found") # Find and modify the target metric @@ -663,26 +660,23 @@ async def update_metric_description( break if not found: - logger.error(f"[update_metric_description][Coherence:Failed] Metric {metric_id} not found in dataset {dataset_id}") + logger.explore("Metric not found for update_metric_description", payload={"metric_id": metric_id, "dataset_id": dataset_id}, error=f"Metric {metric_id} not found") raise HTTPException(status_code=404, detail=f"Metric {metric_id} not found in dataset {dataset_id}") # PUT back with override_columns=false try: await client.update_dataset(dataset_id, dataset, override_columns=False) except Exception as e: - logger.error(f"[update_metric_description][Coherence:Failed] Superset PUT failed: {e}") + logger.explore("Superset PUT request failed for update_metric_description", payload={"dataset_id": dataset_id}, error=str(e)) raise HTTPException(status_code=502, detail=f"Failed to update dataset in Superset: {e!s}") - logger.reflect( - f"Updated metric {metric_id} description for dataset {dataset_id}", - extra={"src": "update_metric_description"}, - ) + logger.reflect("Metric description updated", payload={"metric_id": metric_id, "dataset_id": dataset_id}) return {"success": True, "description": description} except HTTPException: raise except Exception as e: - logger.error(f"[update_metric_description][Coherence:Failed] Unexpected error: {e}") + logger.explore("Unexpected error in update_metric_description", payload={"dataset_id": dataset_id, "metric_id": metric_id}, error=str(e)) raise HTTPException(status_code=500, detail=f"Unexpected error: {e!s}") # #endregion update_metric_description diff --git a/backend/src/api/routes/git/_helpers.py b/backend/src/api/routes/git/_helpers.py index 185adb0a..8209c793 100644 --- a/backend/src/api/routes/git/_helpers.py +++ b/backend/src/api/routes/git/_helpers.py @@ -47,7 +47,7 @@ def _build_no_repo_status_payload() -> dict: # @PRE `error` is a non-HTTPException instance. # @POST Raises HTTPException(500) with route-specific context. def _handle_unexpected_git_route_error(route_name: str, error: Exception) -> None: - logger.error(f"[{route_name}][Coherence:Failed] {error}") + logger.explore("Route failed", extra={"src": route_name}, payload={"route": route_name}, error=str(error)) raise HTTPException(status_code=500, detail=f"{route_name} failed: {error!s}") # #endregion _handle_unexpected_git_route_error diff --git a/backend/src/api/routes/git/_repo_operations_routes.py b/backend/src/api/routes/git/_repo_operations_routes.py index d8894d67..2f5e3c94 100644 --- a/backend/src/api/routes/git/_repo_operations_routes.py +++ b/backend/src/api/routes/git/_repo_operations_routes.py @@ -205,9 +205,7 @@ async def get_repository_status_batch( "sync_status": "ERROR", } except Exception as e: - logger.error( - f"[get_repository_status_batch][Coherence:Failed] Failed for dashboard {dashboard_id}: {e}" - ) + logger.explore("Failed for dashboard in batch status", extra={"src": "get_repository_status_batch"}, payload={"dashboard_id": dashboard_id}, error=str(e)) statuses[str(dashboard_id)] = { **_build_no_repo_status_payload(), "sync_state": "ERROR", diff --git a/backend/src/api/routes/git/_repo_routes.py b/backend/src/api/routes/git/_repo_routes.py index d53bf60b..4f0a3e56 100644 --- a/backend/src/api/routes/git/_repo_routes.py +++ b/backend/src/api/routes/git/_repo_routes.py @@ -95,15 +95,11 @@ async def init_repository( db_repo.current_branch = "dev" db.commit() - logger.info( - f"[init_repository][Coherence:OK] Repository initialized for dashboard {dashboard_id}" - ) + logger.reflect("Repository initialized for dashboard", extra={"src": "init_repository"}, payload={"dashboard_id": dashboard_id}) return {"status": "success", "message": "Repository initialized"} except Exception as e: db.rollback() - logger.error( - f"[init_repository][Coherence:Failed] Failed to init repository: {e}" - ) + logger.explore("Failed to init repository", extra={"src": "init_repository"}, error=str(e)) if isinstance(e, HTTPException): raise _handle_unexpected_git_route_error("init_repository", e) diff --git a/backend/src/api/routes/settings.py b/backend/src/api/routes/settings.py index ba614c8c..209cc868 100755 --- a/backend/src/api/routes/settings.py +++ b/backend/src/api/routes/settings.py @@ -248,8 +248,9 @@ async def add_environment( try: await _validate_superset_connection_fast(env) except Exception as e: - logger.error( - f"[add_environment][Coherence:Failed] Connection validation failed: {e}" + logger.explore( + "Connection validation failed", + error=str(e), ) raise HTTPException( status_code=400, detail=f"Connection validation failed: {e}" @@ -291,8 +292,10 @@ async def update_environment( try: await _validate_superset_connection_fast(env_to_validate) except Exception as e: - logger.error( - f"[update_environment][Coherence:Failed] Connection validation failed: {e}" + logger.explore( + "Connection validation failed", + error=str(e), + payload={"environment_id": id}, ) raise HTTPException( status_code=400, detail=f"Connection validation failed: {e}" @@ -344,13 +347,16 @@ async def test_environment_connection( try: await _validate_superset_connection_fast(env) - logger.info( - f"[test_environment_connection][Coherence:OK] Connection successful for {id}" + logger.reflect( + "Connection test successful", + payload={"environment_id": id}, ) return {"status": "success", "message": "Connection successful"} except Exception as e: - logger.error( - f"[test_environment_connection][Coherence:Failed] Connection failed for {id}: {e}" + logger.explore( + "Connection test failed", + error=str(e), + payload={"environment_id": id}, ) return {"status": "error", "message": str(e)} diff --git a/backend/src/app.py b/backend/src/app.py index b10dc8d4..02510f84 100755 --- a/backend/src/app.py +++ b/backend/src/app.py @@ -81,11 +81,11 @@ async def lifespan(app: FastAPI): # Startup seed_trace_id() with belief_scope("startup_event"): - logger.info("🔐 Ensuring encryption key...") + logger.reason("Ensuring encryption key") ensure_encryption_key() - logger.info("🗄️ Initializing database tables (safety net)...") + logger.reason("Initializing database tables") init_db() - logger.info("👤 Bootstrapping admin user...") + logger.reason("Bootstrapping admin user") ensure_initial_admin_user() # Clean up stuck validation runs from previous backend lifetime # (runs left "running" in DB when the in-memory task queue was lost) @@ -101,19 +101,19 @@ async def lifespan(app: FastAPI): _r.finished_at = datetime.now(timezone.utc) _r.summary = "Force-stopped: backend restarted while run was in progress" logger.reason( - f"Force-stopped stuck run {_r.id} (policy={_r.policy_id})", - extra={"src": "app.startup", "run_id": _r.id}, + "Force-stopped stuck run", + payload={"run_id": _r.id, "policy_id": _r.policy_id}, ) _s.commit() _s.close() except Exception as _e: - logger.warning(f"Failed to clean up stuck validation runs: {_e}") - logger.info("⏰ Initializing AsyncJobRunner...") + logger.explore("Failed to clean up stuck validation runs", error=str(_e)) + logger.reason("Initializing AsyncJobRunner") get_async_job_runner() # Initialize singleton with running event loop BEFORE scheduler starts - logger.info("⏰ Starting scheduler...") + logger.reason("Starting scheduler") scheduler = get_scheduler_service() scheduler.start() - logger.info("✅ Application startup complete") + logger.reflect("Application startup complete") yield # Shutdown scheduler.stop() @@ -150,15 +150,14 @@ def ensure_initial_admin_user() -> None: username = os.getenv("INITIAL_ADMIN_USERNAME", "").strip() password = os.getenv("INITIAL_ADMIN_PASSWORD", "").strip() if not username or not password: - logger.warning( - "INITIAL_ADMIN_CREATE is enabled but INITIAL_ADMIN_USERNAME/INITIAL_ADMIN_PASSWORD is missing; skipping bootstrap." + logger.explore( + "INITIAL_ADMIN_CREATE enabled but credentials missing; skipping bootstrap" ) return # Warn about env-var password — visible via /proc to other processes - logger.warning( - "INITIAL_ADMIN_PASSWORD is set via environment variable. " - "This is visible to other processes on the same host. " - "Consider removing the env var after bootstrap." + logger.explore( + "INITIAL_ADMIN_PASSWORD set via env var — visible to other processes", + error="Security concern: password in environment variable", ) db = AuthSessionLocal() try: @@ -170,8 +169,9 @@ def ensure_initial_admin_user() -> None: db.refresh(admin_role) existing_user = db.query(User).filter(User.username == username).first() if existing_user: - logger.info( - "Initial admin bootstrap skipped: user '%s' already exists.", username + logger.reflect( + "Initial admin bootstrap skipped", + payload={"username": username}, ) return new_user = User( @@ -184,12 +184,13 @@ def ensure_initial_admin_user() -> None: new_user.roles.append(admin_role) db.add(new_user) db.commit() - logger.info( - "Initial admin user '%s' created from environment bootstrap.", username + logger.reason( + "Initial admin user created from environment bootstrap", + payload={"username": username}, ) except Exception as exc: db.rollback() - logger.error("Failed to bootstrap initial admin user: %s", exc) + logger.explore("Failed to bootstrap initial admin user", error=str(exc)) raise finally: db.close() @@ -216,7 +217,7 @@ def run_alembic_migrations() -> None: except Exception as exc: logger.explore( "Alembic migration failed — check migration chain or alembic.ini", - extra={"error": str(exc)}, + error=str(exc), ) raise @@ -240,18 +241,18 @@ from .core.auth.config import auth_config _session_secret = os.getenv("SESSION_SECRET_KEY", "").strip() if not _session_secret: _session_secret = auth_config.SECRET_KEY - logger.warning( - "SESSION_SECRET_KEY not set. Falling back to AUTH_SECRET_KEY. " - "Set a separate SESSION_SECRET_KEY in .env for production isolation." + logger.explore( + "SESSION_SECRET_KEY not set — falling back to AUTH_SECRET_KEY", + error="Missing SESSION_SECRET_KEY", ) app.add_middleware(SessionMiddleware, secret_key=_session_secret) # Configure CORS _allowed_origins_raw = os.getenv("ALLOWED_ORIGINS", "").strip() if not _allowed_origins_raw: - logger.warning( - "ALLOWED_ORIGINS not set. CORS will reject all cross-origin requests. " - "Set ALLOWED_ORIGINS to a comma-separated list of allowed origins." + logger.explore( + "ALLOWED_ORIGINS not set — CORS rejects all cross-origin requests", + error="Missing ALLOWED_ORIGINS", ) _allowed_origins = [] else: @@ -297,15 +298,15 @@ app.add_middleware(HSTSMiddleware) @app.exception_handler(Exception) async def global_exception_handler(request: Request, exc: Exception): client_host = request.client.host if request.client else "unknown" - logger.exception( - f"Unhandled exception: {request.method} {request.url.path}", - extra={ - "src": "app.exception_handler", - "path": request.url.path, + logger.explore( + "Unhandled exception", + payload={ "method": request.method, + "path": request.url.path, "query_params": dict(request.query_params), "client": client_host, }, + error=str(exc), ) return JSONResponse( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, @@ -321,7 +322,7 @@ async def global_exception_handler(request: Request, exc: Exception): @app.exception_handler(NetworkError) async def network_error_handler(request: Request, exc: NetworkError): with belief_scope("network_error_handler"): - logger.error(f"Network error: {exc}") + logger.explore("Network error", error=str(exc)) return HTTPException( status_code=503, detail="Environment unavailable. Please check if the Superset instance is running.", @@ -341,7 +342,7 @@ async def log_requests(request: Request, call_next): if not is_polling: import json as _json, logging as _lg if logger.isEnabledFor(_lg.INFO): - logger.info(f"Incoming request: {request.method} {request.url.path}") + logger.reason("Incoming request", payload={"method": request.method, "path": request.url.path}) else: _json.dump({"ts": __import__('datetime').datetime.now(__import__('datetime').UTC).isoformat(), "level": "INFO", "src": "log_requests", "marker": "REASON", @@ -353,7 +354,7 @@ async def log_requests(request: Request, call_next): response = await call_next(request) if not is_polling: if logger.isEnabledFor(_lg.INFO): - logger.info(f"Response status: {response.status_code} for {request.url.path}") + logger.reflect("Response", payload={"status": response.status_code, "path": request.url.path}) else: _json.dump({"ts": __import__('datetime').datetime.now(__import__('datetime').UTC).isoformat(), "level": "INFO", "src": "log_requests", "marker": "REFLECT", @@ -363,7 +364,7 @@ async def log_requests(request: Request, call_next): sys.stderr.flush() return response except NetworkError as e: - logger.error(f"Network error caught in middleware: {e}") + logger.explore("Network error caught in middleware", error=str(e)) raise HTTPException( status_code=503, detail="Environment unavailable. Please check if the Superset instance is running.", @@ -425,9 +426,10 @@ app.include_router(maintenance.maintenance_router) async def _authenticate_websocket(websocket: WebSocket, endpoint_name: str) -> bool: ws_token = websocket.query_params.get("token", "") if not ws_token: - logger.warning( - "WebSocket connection rejected: missing token", - extra={"endpoint": endpoint_name}, + logger.explore( + "WebSocket connection rejected", + payload={"endpoint": endpoint_name}, + error="Missing token", ) return False @@ -443,7 +445,7 @@ async def _authenticate_websocket(websocket: WebSocket, endpoint_name: str) -> b if isinstance(user, str) and user: logger.reason( "WebSocket authenticated via JWT", - extra={"endpoint": endpoint_name, "user": user}, + payload={"endpoint": endpoint_name, "user": user}, ) return True except Exception: @@ -463,7 +465,7 @@ async def _authenticate_websocket(websocket: WebSocket, endpoint_name: str) -> b if api_key and api_key.active: logger.reason( "WebSocket authenticated via API key", - extra={"endpoint": endpoint_name, "key_name": api_key.name}, + payload={"endpoint": endpoint_name, "key_name": api_key.name}, ) return True finally: @@ -472,9 +474,10 @@ async def _authenticate_websocket(websocket: WebSocket, endpoint_name: str) -> b logger.explore("API key validation failed in WebSocket auth", error="see traceback") pass - logger.warning( - "WebSocket connection rejected: invalid token", - extra={"endpoint": endpoint_name}, + logger.explore( + "WebSocket connection rejected", + payload={"endpoint": endpoint_name}, + error="Invalid token", ) return False # #endregion _authenticate_websocket @@ -537,7 +540,7 @@ async def websocket_endpoint( min_level = level_hierarchy.get(level_filter, 0) if level_filter else 0 logger.reason( "Accepted WebSocket log+status stream connection", - extra={ + payload={ "task_id": task_id, "source_filter": source_filter, "level_filter": level_filter, @@ -549,7 +552,7 @@ async def websocket_endpoint( status_queue = await task_manager.subscribe_status(task_id) logger.reason( "Subscribed WebSocket client to task log and status queues", - extra={"task_id": task_id}, + payload={"task_id": task_id}, ) def matches_filters(log_entry) -> bool: @@ -589,13 +592,13 @@ async def websocket_endpoint( await send_status_update(task) logger.reason( "Sent initial task status", - extra={"task_id": task_id, "status": str(task.status)}, + payload={"task_id": task_id, "status": str(task.status)}, ) # ── Replay initial logs ── logger.reason( "Starting task log stream replay and live forwarding", - extra={"task_id": task_id}, + payload={"task_id": task_id}, ) initial_logs = task_manager.get_task_logs(task_id) initial_sent = 0 @@ -607,7 +610,7 @@ async def websocket_endpoint( initial_sent += 1 logger.reflect( "Initial task log replay completed", - extra={ + payload={ "task_id": task_id, "replayed_logs": initial_sent, "total_available_logs": len(initial_logs), @@ -628,7 +631,7 @@ async def websocket_endpoint( await websocket.send_json(synthetic_log) logger.reason( "Replayed awaiting-input prompt to restored WebSocket client", - extra={"task_id": task_id, "task_status": task.status}, + payload={"task_id": task_id, "task_status": task.status}, ) # ── Main loop: listen on both log and status queues ── @@ -649,7 +652,7 @@ async def websocket_endpoint( if task_status in ("SUCCESS", "FAILED"): logger.reason( "Task reached terminal state via status broadcast; closing stream", - extra={"task_id": task_id, "status": task_status}, + payload={"task_id": task_id, "status": task_status}, ) await asyncio.sleep(2) raise StopIteration # exit the while loop @@ -663,7 +666,7 @@ async def websocket_endpoint( await websocket.send_json(log_dict) logger.reflect( "Forwarded task log entry to WebSocket client", - extra={ + payload={ "task_id": task_id, "level": log_dict.get("level"), }, @@ -674,7 +677,7 @@ async def websocket_endpoint( ): logger.reason( "Observed terminal task log entry; delaying to preserve client visibility", - extra={"task_id": task_id, "message": result.message}, + payload={"task_id": task_id, "message": result.message}, ) await asyncio.sleep(2) except (WebSocketDisconnect, StopIteration) as _ws_exc: @@ -686,12 +689,13 @@ async def websocket_endpoint( pass logger.reason( "WebSocket client disconnected or stream ended", - extra={"task_id": task_id}, + payload={"task_id": task_id}, ) except Exception as exc: logger.explore( "WebSocket log+status streaming encountered an unexpected failure", - extra={"task_id": task_id, "error": str(exc)}, + payload={"task_id": task_id}, + error=str(exc), ) raise finally: @@ -699,7 +703,7 @@ async def websocket_endpoint( task_manager.unsubscribe_status(task_id, status_queue) logger.reflect( "Released WebSocket log and status queue subscriptions", - extra={"task_id": task_id}, + payload={"task_id": task_id}, ) # #endregion websocket_endpoint @@ -736,14 +740,14 @@ async def task_events_websocket(websocket: WebSocket): await websocket.send_json(event) logger.reflect( "Forwarded task event to global client", - extra={"task_id": event.get("task_id")}, + payload={"task_id": event.get("task_id")}, ) except WebSocketDisconnect: logger.reason("Global task events client disconnected") except Exception as exc: logger.explore( "Global task events streaming failed", - extra={"error": str(exc)}, + error=str(exc), ) raise finally: @@ -784,14 +788,14 @@ async def maintenance_events_websocket(websocket: WebSocket): await websocket.send_json(event) logger.reflect( "Forwarded maintenance event to client", - extra={"event_type": event.get("type"), "maintenance_id": event.get("maintenance_id")}, + payload={"event_type": event.get("type"), "maintenance_id": event.get("maintenance_id")}, ) except WebSocketDisconnect: logger.reason("Maintenance events client disconnected") except Exception as exc: logger.explore( "Maintenance events streaming failed", - extra={"error": str(exc)}, + error=str(exc), ) raise finally: @@ -817,21 +821,21 @@ async def dataset_websocket_endpoint(websocket: WebSocket, env_id: str): return await websocket.accept() - logger.reason("Accepted dataset event WebSocket", extra={"env_id": env_id}) + logger.reason("Accepted dataset event WebSocket", payload={"env_id": env_id}) task_manager = get_task_manager() queue = await task_manager.subscribe_dataset_events(env_id) try: while True: event = await queue.get() await websocket.send_json(event) - logger.reflect("Forwarded dataset.updated event to client", extra={"env_id": env_id}) + logger.reflect("Forwarded dataset.updated event to client", payload={"env_id": env_id}) except WebSocketDisconnect: - logger.reason("WebSocket client disconnected from dataset events", extra={"env_id": env_id}) + logger.reason("WebSocket client disconnected from dataset events", payload={"env_id": env_id}) except Exception as exc: - logger.explore("WebSocket dataset streaming failed", extra={"env_id": env_id, "error": str(exc)}) + logger.explore("WebSocket dataset streaming failed", payload={"env_id": env_id}, error=str(exc)) finally: task_manager.unsubscribe_dataset_events(env_id, queue) - logger.reflect("Released dataset event subscription", extra={"env_id": env_id}) + logger.reflect("Released dataset event subscription", payload={"env_id": env_id}) # #endregion dataset_websocket_endpoint # #region translate_run_websocket [C:3] [TYPE Function] # @ingroup Module @@ -848,7 +852,7 @@ async def translate_run_websocket(websocket: WebSocket, run_id: str): await websocket.close(code=4001, reason="Authentication required") return await websocket.accept() - logger.reason("Accepted translate run WebSocket", extra={"run_id": run_id}) + logger.reason("Accepted translate run WebSocket", payload={"run_id": run_id}) try: while True: try: @@ -871,15 +875,15 @@ async def translate_run_websocket(websocket: WebSocket, run_id: str): finally: db.close() except Exception as tick_err: - logger.explore("Translate run WS tick error", extra={"run_id": run_id, "error": str(tick_err)}) + logger.explore("Translate run WS tick error", payload={"run_id": run_id}, error=str(tick_err)) await websocket.send_json({"error": str(tick_err)}) break await asyncio.sleep(1) except WebSocketDisconnect: - logger.reason("Translate run WS disconnected", extra={"run_id": run_id}) + logger.reason("Translate run WS disconnected", payload={"run_id": run_id}) except Exception as exc: - logger.explore("Translate run WS error", extra={"run_id": run_id, "error": str(exc)}) - logger.reflect("Translate run WS closed", extra={"run_id": run_id}) + logger.explore("Translate run WS error", payload={"run_id": run_id}, error=str(exc)) + logger.reflect("Translate run WS closed", payload={"run_id": run_id}) # #endregion translate_run_websocket # #region StaticFiles [C:1] [TYPE Mount] [SEMANTICS static, frontend, spa] # @BRIEF Mounts the frontend build directory to serve static assets. diff --git a/backend/src/core/__tests__/test_native_filters.py b/backend/src/core/__tests__/test_native_filters.py index d552a540..f9494e59 100644 --- a/backend/src/core/__tests__/test_native_filters.py +++ b/backend/src/core/__tests__/test_native_filters.py @@ -5,7 +5,7 @@ # @RELATION BINDS_TO ->[AsyncSupersetClient] # @RELATION BINDS_TO ->[FilterState] import json -from unittest.mock import MagicMock +from unittest.mock import AsyncMock, MagicMock from src.core.config_models import Environment from src.core.superset_client import SupersetClient @@ -36,9 +36,9 @@ def _make_environment() -> Environment: # #region test_extract_native_filters_from_permalink [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Extract native filters from a permalink key. -def test_extract_native_filters_from_permalink(): +async def test_extract_native_filters_from_permalink(): client = SupersetClient(_make_environment()) - client.get_dashboard_permalink_state = MagicMock( + client.get_dashboard_permalink_state = AsyncMock( return_value={ "result": { "state": { @@ -65,7 +65,7 @@ def test_extract_native_filters_from_permalink(): } } ) - result = client.extract_native_filters_from_permalink("test-permalink-key") + result = await client.extract_native_filters_from_permalink("test-permalink-key") assert result["permalink_key"] == "test-permalink-key" assert "dataMask" in result assert "filter_country" in result["dataMask"] @@ -79,9 +79,9 @@ def test_extract_native_filters_from_permalink(): # #region test_extract_native_filters_from_permalink_direct_response [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Handle permalink response without result wrapper. -def test_extract_native_filters_from_permalink_direct_response(): +async def test_extract_native_filters_from_permalink_direct_response(): client = SupersetClient(_make_environment()) - client.get_dashboard_permalink_state = MagicMock( + client.get_dashboard_permalink_state = AsyncMock( return_value={ "state": { "dataMask": { @@ -94,16 +94,16 @@ def test_extract_native_filters_from_permalink_direct_response(): } } ) - result = client.extract_native_filters_from_permalink("direct-key") + result = await client.extract_native_filters_from_permalink("direct-key") assert result["permalink_key"] == "direct-key" assert "filter_1" in result["dataMask"] # #endregion test_extract_native_filters_from_permalink_direct_response # #region test_extract_native_filters_from_key [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Extract native filters from a native_filters_key. -def test_extract_native_filters_from_key(): +async def test_extract_native_filters_from_key(): client = SupersetClient(_make_environment()) - client.get_native_filter_state = MagicMock( + client.get_native_filter_state = AsyncMock( return_value={ "result": { "value": json.dumps( @@ -122,7 +122,7 @@ def test_extract_native_filters_from_key(): } } ) - result = client.extract_native_filters_from_key(123, "filter-state-key") + result = await client.extract_native_filters_from_key(123, "filter-state-key") assert result["dashboard_id"] == 123 assert result["filter_state_key"] == "filter-state-key" assert "dataMask" in result @@ -134,9 +134,9 @@ def test_extract_native_filters_from_key(): # #region test_extract_native_filters_from_key_single_filter [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Handle single filter format in native filter state. -def test_extract_native_filters_from_key_single_filter(): +async def test_extract_native_filters_from_key_single_filter(): client = SupersetClient(_make_environment()) - client.get_native_filter_state = MagicMock( + client.get_native_filter_state = AsyncMock( return_value={ "result": { "value": json.dumps( @@ -151,7 +151,7 @@ def test_extract_native_filters_from_key_single_filter(): } } ) - result = client.extract_native_filters_from_key(456, "single-key") + result = await client.extract_native_filters_from_key(456, "single-key") assert "dataMask" in result assert "single_filter" in result["dataMask"] assert ( @@ -162,9 +162,9 @@ def test_extract_native_filters_from_key_single_filter(): # #region test_extract_native_filters_from_key_dict_value [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Handle filter state value as dict instead of JSON string. -def test_extract_native_filters_from_key_dict_value(): +async def test_extract_native_filters_from_key_dict_value(): client = SupersetClient(_make_environment()) - client.get_native_filter_state = MagicMock( + client.get_native_filter_state = AsyncMock( return_value={ "result": { "value": { @@ -176,19 +176,19 @@ def test_extract_native_filters_from_key_dict_value(): } } ) - result = client.extract_native_filters_from_key(789, "dict-key") + result = await client.extract_native_filters_from_key(789, "dict-key") assert "dataMask" in result assert "filter_id" in result["dataMask"] # #endregion test_extract_native_filters_from_key_dict_value # #region test_parse_dashboard_url_for_filters_permalink [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Parse permalink URL format. -def test_parse_dashboard_url_for_filters_permalink(): +async def test_parse_dashboard_url_for_filters_permalink(): client = SupersetClient(_make_environment()) - client.extract_native_filters_from_permalink = MagicMock( + client.extract_native_filters_from_permalink = AsyncMock( return_value={"dataMask": {"f1": {}}, "permalink_key": "abc123"} ) - result = client.parse_dashboard_url_for_filters( + result = await client.parse_dashboard_url_for_filters( "http://superset.local/superset/dashboard/p/abc123/" ) assert result["filter_type"] == "permalink" @@ -197,16 +197,16 @@ def test_parse_dashboard_url_for_filters_permalink(): # #region test_parse_dashboard_url_for_filters_native_key [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Parse native_filters_key URL format with numeric dashboard ID. -def test_parse_dashboard_url_for_filters_native_key(): +async def test_parse_dashboard_url_for_filters_native_key(): client = SupersetClient(_make_environment()) - client.extract_native_filters_from_key = MagicMock( + client.extract_native_filters_from_key = AsyncMock( return_value={ "dataMask": {"f2": {}}, "dashboard_id": 42, "filter_state_key": "xyz", } ) - result = client.parse_dashboard_url_for_filters( + result = await client.parse_dashboard_url_for_filters( "http://superset.local/dashboard/42/?native_filters_key=xyz" ) assert result["filter_type"] == "native_filters_key" @@ -216,22 +216,26 @@ def test_parse_dashboard_url_for_filters_native_key(): # #region test_parse_dashboard_url_for_filters_native_key_slug [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Parse native_filters_key URL format when dashboard reference is a slug, not a numeric ID. -def test_parse_dashboard_url_for_filters_native_key_slug(): +async def test_parse_dashboard_url_for_filters_native_key_slug(): client = SupersetClient(_make_environment()) # Simulate slug resolution: get_dashboard returns the dashboard with numeric ID - client.get_dashboard = MagicMock( + client.get_dashboard = AsyncMock( return_value={ - "result": {"id": 99, "dashboard_title": "COVID Dashboard", "slug": "covid"} + "result": { + "id": 99, + "json_metadata": json.dumps({}), + "dashboard_title": "Test Dashboard", + } } ) - client.extract_native_filters_from_key = MagicMock( + client.extract_native_filters_from_key = AsyncMock( return_value={ "dataMask": {"f_slug": {}}, "dashboard_id": 99, "filter_state_key": "abc123", } ) - result = client.parse_dashboard_url_for_filters( + result = await client.parse_dashboard_url_for_filters( "http://superset.local/superset/dashboard/covid/?native_filters_key=abc123" ) assert result["filter_type"] == "native_filters_key" @@ -243,10 +247,10 @@ def test_parse_dashboard_url_for_filters_native_key_slug(): # #region test_parse_dashboard_url_for_filters_native_key_slug_resolution_fails [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Gracefully handle slug resolution failure for native_filters_key URL. -def test_parse_dashboard_url_for_filters_native_key_slug_resolution_fails(): +async def test_parse_dashboard_url_for_filters_native_key_slug_resolution_fails(): client = SupersetClient(_make_environment()) - client.get_dashboard = MagicMock(side_effect=Exception("Not found")) - result = client.parse_dashboard_url_for_filters( + client.get_dashboard = AsyncMock(side_effect=Exception("Not found")) + result = await client.parse_dashboard_url_for_filters( "http://superset.local/dashboard/unknownslug/?native_filters_key=key1" ) assert result["filter_type"] is None @@ -255,9 +259,9 @@ def test_parse_dashboard_url_for_filters_native_key_slug_resolution_fails(): # #region test_parse_dashboard_url_for_filters_native_filters_direct [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Parse native_filters direct query param. -def test_parse_dashboard_url_for_filters_native_filters_direct(): +async def test_parse_dashboard_url_for_filters_native_filters_direct(): client = SupersetClient(_make_environment()) - result = client.parse_dashboard_url_for_filters( + result = await client.parse_dashboard_url_for_filters( "http://superset.local/dashboard/1/?native_filters=" + json.dumps({"filter_1": {"col": "x", "op": "==", "val": "y"}}) ) @@ -267,9 +271,9 @@ def test_parse_dashboard_url_for_filters_native_filters_direct(): # #region test_parse_dashboard_url_for_filters_no_filters [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Return empty result when no filters present. -def test_parse_dashboard_url_for_filters_no_filters(): +async def test_parse_dashboard_url_for_filters_no_filters(): client = SupersetClient(_make_environment()) - result = client.parse_dashboard_url_for_filters( + result = await client.parse_dashboard_url_for_filters( "http://superset.local/dashboard/1/" ) assert result["filter_type"] is None @@ -356,9 +360,9 @@ def test_native_filter_data_mask_model(): # #region test_recover_imported_filters_reconciles_raw_native_filter_ids_to_metadata_names [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Reconcile raw native filter ids from state to canonical metadata filter names. -def test_recover_imported_filters_reconciles_raw_native_filter_ids_to_metadata_names(): +async def test_recover_imported_filters_reconciles_raw_native_filter_ids_to_metadata_names(): client = MagicMock() - client.get_dashboard.return_value = { + client.get_dashboard = AsyncMock(return_value={ "result": { "json_metadata": json.dumps( { @@ -372,7 +376,7 @@ def test_recover_imported_filters_reconciles_raw_native_filter_ids_to_metadata_n } ) } - } + }) extractor = SupersetContextExtractor(_make_environment(), client=client) parsed_context = SupersetParsedContext( source_url="http://superset.local/dashboard/42/?native_filters_key=abc", @@ -399,7 +403,7 @@ def test_recover_imported_filters_reconciles_raw_native_filter_ids_to_metadata_n } ], ) - result = extractor.recover_imported_filters(parsed_context) + result = await extractor.recover_imported_filters(parsed_context) assert len(result) == 1 assert result[0]["filter_name"] == "Country" assert result[0]["display_name"] == "Country" @@ -416,9 +420,9 @@ def test_recover_imported_filters_reconciles_raw_native_filter_ids_to_metadata_n # #region test_recover_imported_filters_collapses_state_and_metadata_duplicates_into_one_canonical_filter [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Collapse raw-id state entries and metadata entries into one canonical filter. -def test_recover_imported_filters_collapses_state_and_metadata_duplicates_into_one_canonical_filter(): +async def test_recover_imported_filters_collapses_state_and_metadata_duplicates_into_one_canonical_filter(): client = MagicMock() - client.get_dashboard.return_value = { + client.get_dashboard = AsyncMock(return_value={ "result": { "json_metadata": json.dumps( { @@ -437,7 +441,7 @@ def test_recover_imported_filters_collapses_state_and_metadata_duplicates_into_o } ) } - } + }) extractor = SupersetContextExtractor(_make_environment(), client=client) parsed_context = SupersetParsedContext( source_url="http://superset.local/dashboard/42/?native_filters_key=abc", @@ -455,7 +459,7 @@ def test_recover_imported_filters_collapses_state_and_metadata_duplicates_into_o } ], ) - result = extractor.recover_imported_filters(parsed_context) + result = await extractor.recover_imported_filters(parsed_context) assert len(result) == 2 country_filter = next(item for item in result if item["filter_name"] == "Country") region_filter = next(item for item in result if item["filter_name"] == "Region") @@ -467,9 +471,9 @@ def test_recover_imported_filters_collapses_state_and_metadata_duplicates_into_o # #region test_recover_imported_filters_preserves_unmatched_raw_native_filter_ids [TYPE Function] # @RELATION BINDS_TO -> NativeFilterExtractionTests # @BRIEF Preserve unmatched raw native filter ids as fallback diagnostics when metadata mapping is unavailable. -def test_recover_imported_filters_preserves_unmatched_raw_native_filter_ids(): +async def test_recover_imported_filters_preserves_unmatched_raw_native_filter_ids(): client = MagicMock() - client.get_dashboard.return_value = { + client.get_dashboard = AsyncMock(return_value={ "result": { "json_metadata": json.dumps( { @@ -483,7 +487,7 @@ def test_recover_imported_filters_preserves_unmatched_raw_native_filter_ids(): } ) } - } + }) extractor = SupersetContextExtractor(_make_environment(), client=client) parsed_context = SupersetParsedContext( source_url="http://superset.local/dashboard/42/?native_filters_key=abc", @@ -501,7 +505,7 @@ def test_recover_imported_filters_preserves_unmatched_raw_native_filter_ids(): } ], ) - result = extractor.recover_imported_filters(parsed_context) + result = await extractor.recover_imported_filters(parsed_context) assert len(result) == 2 assert any( item["filter_name"] == "Country" and item["recovery_status"] == "partial" diff --git a/backend/src/core/auth/logger.py b/backend/src/core/auth/logger.py index b1f82b62..c193cbf8 100644 --- a/backend/src/core/auth/logger.py +++ b/backend/src/core/auth/logger.py @@ -54,19 +54,24 @@ def _mask_details(details: dict[str, Any] | None) -> dict[str, Any] | None: def log_security_event(event_type: str, username: str, details: dict = None): with belief_scope("log_security_event", f"{event_type}:{username}"): timestamp = datetime.now(UTC).isoformat() - logger.info( - "[AUDIT][%s][%s] User: %s", - timestamp, - event_type, - username, - ) safe_details = _mask_details(details) + logger.reason( + "Security event recorded", + payload={ + "event_type": event_type, + "username": username, + "timestamp": timestamp, + "details_present": bool(safe_details), + }, + ) if safe_details: - logger.info( - "[AUDIT][%s][%s] Details: %s", - timestamp, - event_type, - safe_details, + logger.reason( + "Security event details", + payload={ + "event_type": event_type, + "details": safe_details, + "timestamp": timestamp, + }, ) # #endregion log_security_event diff --git a/backend/src/core/connection_service.py b/backend/src/core/connection_service.py index d0e71816..b1c432c0 100644 --- a/backend/src/core/connection_service.py +++ b/backend/src/core/connection_service.py @@ -35,15 +35,13 @@ # @SIDE_EFFECT Opens/closes native DB connection. Network I/O. # #endregion -import logging import time as time_module from typing import Any from .config_manager import ConfigManager from .config_models import DatabaseConnection from .encryption import EncryptionManager - -logger = logging.getLogger(__name__) +from .logger import logger MASKED_PASSWORD = "********" diff --git a/backend/src/core/cot_logger.py b/backend/src/core/cot_logger.py index b089c09b..b832c95f 100644 --- a/backend/src/core/cot_logger.py +++ b/backend/src/core/cot_logger.py @@ -147,6 +147,7 @@ def log( "marker": marker, "intent": intent, "src": src, + "span_id": _span_id.get() or None, } if payload is not None: @@ -167,7 +168,7 @@ def log( # #endregion cot_log_function # #region MarkerLogger [C:2] [TYPE Class] [SEMANTICS logger, proxy, marker, syntactic-sugar] -# @defgroup Core Module group. +# @ingroup Core # @BRIEF Thin proxy class providing .reason(), .reflect(), .explore() convenience methods. class MarkerLogger: """Thin proxy over the cot_logger.log() function. @@ -183,7 +184,6 @@ class MarkerLogger: """ # #region MarkerLogger.__init__ [TYPE Function] -# @ingroup Core # @BRIEF Store the module/component name used as the 'src' field in all log calls. def __init__(self, module_name: str) -> None: """Initialise the MarkerLogger with a module or component name. @@ -196,7 +196,6 @@ class MarkerLogger: # #endregion MarkerLogger.__init__ # #region MarkerLogger.reason [TYPE Function] -# @ingroup Core # @BRIEF Log a REASON marker — strict deduction, core logic. def reason( self, intent: str, *, payload: dict[str, Any] | None = None @@ -207,7 +206,6 @@ class MarkerLogger: # #endregion MarkerLogger.reason # #region MarkerLogger.reflect [TYPE Function] -# @ingroup Core # @BRIEF Log a REFLECT marker — self-check, structural validation. def reflect( self, intent: str, *, payload: dict[str, Any] | None = None @@ -218,7 +216,6 @@ class MarkerLogger: # #endregion MarkerLogger.reflect # #region MarkerLogger.explore [TYPE Function] -# @ingroup Core # @BRIEF Log an EXPLORE marker — searching, alternatives, violated assumptions. def explore( self, diff --git a/backend/src/core/mapping_service.py b/backend/src/core/mapping_service.py index 29b13a84..a47eb041 100644 --- a/backend/src/core/mapping_service.py +++ b/backend/src/core/mapping_service.py @@ -92,7 +92,7 @@ class IdMappingService: try: for res_enum, endpoint, name_field in types_to_poll: logger.debug( - f"[IdMappingService.sync_environment][Explore] Polling {endpoint} endpoint" + "Polling %s endpoint", endpoint, ) # Simulated API Fetch (Would be: superset_client.get(f"/api/v1/{endpoint}/")... ) # This relies on the superset API structure, e.g. { "result": [{"id": 1, "uuid": "...", name_field: "..."}] } @@ -114,7 +114,7 @@ class IdMappingService: from datetime import timedelta since_dttm = max_date - timedelta(minutes=5) logger.debug( - f"[IdMappingService.sync_environment] Incremental sync since {since_dttm}" + "Incremental sync since %s", since_dttm, ) resources = await superset_client.get_all_resources( endpoint, since_dttm=since_dttm @@ -170,22 +170,26 @@ class IdMappingService: if deleted: total_deleted += deleted logger.reason( - f"Removed {deleted} stale {endpoint} mapping(s) for {environment_id}", - extra={"src": "IdMappingService.sync_environment", "payload": {"deleted": deleted, "endpoint": endpoint, "environment_id": environment_id}}, + "Removed stale mappings", + payload={"deleted": deleted, "endpoint": endpoint, "environment_id": environment_id}, ) except Exception as loop_e: - logger.error( - f"[IdMappingService.sync_environment][Reason] Error polling {endpoint}: {loop_e}" + logger.explore( + "Error polling endpoint", + error=str(loop_e), + payload={"endpoint": endpoint}, ) # Continue to next resource type instead of blowing up the whole sync self.db.commit() - logger.info( - f"[IdMappingService.sync_environment][Coherence:OK] Successfully synced {total_synced} items and deleted {total_deleted} stale items." + logger.reflect( + "Successfully synced environment", + payload={"synced": total_synced, "deleted_stale": total_deleted}, ) except Exception as e: self.db.rollback() - logger.error( - f"[IdMappingService.sync_environment][Coherence:Failed] Critical sync failure: {e}" + logger.explore( + "Critical sync failure", + error=str(e), ) raise # #endregion sync_environment diff --git a/backend/src/core/scheduler.py b/backend/src/core/scheduler.py index 64e5bdf6..01022c1d 100644 --- a/backend/src/core/scheduler.py +++ b/backend/src/core/scheduler.py @@ -98,7 +98,7 @@ class SchedulerService: db.close() except Exception as e: logger.explore("Failed to load translation schedules on startup", - extra={"error": str(e)}) + error=str(e)) # Re-register active validation policies with schedules try: from ..models.llm import ValidationPolicy @@ -133,7 +133,7 @@ class SchedulerService: db.close() except Exception as e: logger.explore("Failed to load validation schedules on startup", - extra={"error": str(e)}) + error=str(e)) # #endregion load_schedules # #region add_backup_job [TYPE Function] # @ingroup Core @@ -156,11 +156,12 @@ class SchedulerService: args=[env_id], replace_existing=True, ) - logger.info( - f"Scheduled backup job added for environment {env_id}: {cron_expression}" + logger.reason( + "Backup job added", + payload={"env_id": env_id, "cron": cron_expression}, ) except Exception as e: - logger.error(f"Failed to add backup job for environment {env_id}: {e}") + logger.explore("Failed to add backup job", payload={"env_id": env_id}, error=str(e)) # #endregion add_backup_job # #region add_translation_job [C:4] [TYPE Function] [SEMANTICS scheduler,translation,cron,apscheduler] # @ingroup Core @@ -194,8 +195,9 @@ class SchedulerService: ) except Exception as e: logger.explore( - f"Failed to register translation schedule: {job_id_aps}", - extra={"error": str(e)}, + "Failed to register translation schedule", + payload={"job": job_id_aps}, + error=str(e), ) # #endregion add_translation_job # #region remove_translation_job [C:4] [TYPE Function] [SEMANTICS scheduler,translation,remove,apscheduler] @@ -212,7 +214,7 @@ class SchedulerService: job_id_aps = f"translate_{schedule_id}" try: self.scheduler.remove_job(job_id_aps) - logger.info(f"Translation schedule removed: {job_id_aps}") + logger.reason("Translation schedule removed", payload={"job": job_id_aps}) except Exception: logger.reason(f"Translation schedule not found (already removed): {job_id_aps}") # #endregion remove_translation_job @@ -272,8 +274,9 @@ class SchedulerService: ) except Exception as e: logger.explore( - f"Failed to register validation schedule: {job_id_aps}", - extra={"error": str(e)}, + "Failed to register validation schedule", + payload={"job": job_id_aps}, + error=str(e), ) # #endregion add_validation_job # #region remove_validation_job [C:2] [TYPE Function] [SEMANTICS scheduler,validation,remove,apscheduler] @@ -290,7 +293,7 @@ class SchedulerService: job_id_aps = f"validation_{policy_id}" try: self.scheduler.remove_job(job_id_aps) - logger.info(f"Validation schedule removed: {job_id_aps}") + logger.reason("Validation schedule removed", payload={"job": job_id_aps}) except Exception: logger.reason(f"Validation schedule not found (already removed): {job_id_aps}") # #endregion remove_validation_job @@ -329,8 +332,9 @@ class SchedulerService: db.close() except Exception as e: logger.explore( - f"Failed to reload validation policy {policy_id}", - extra={"error": str(e)}, + "Failed to reload validation policy", + payload={"policy_id": policy_id}, + error=str(e), ) # #endregion reload_validation_policy # #region _trigger_validation [C:3] [TYPE Function] [SEMANTICS scheduler,validation,trigger] @@ -392,8 +396,9 @@ class SchedulerService: ) except Exception as e: logger.explore( - f"Error triggering validation for policy {policy_id}", - extra={"error": str(e)}, + "Error triggering validation for policy", + payload={"policy_id": policy_id}, + error=str(e), ) finally: db.close() @@ -431,8 +436,10 @@ class ThrottledSchedulerConfigurator: total_seconds = (end_dt - start_dt).total_seconds() # Minimum interval of 1 second to avoid division by zero or negative if total_seconds <= 0: - logger.warning( - f"[calculate_schedule] Window size is zero or negative. Falling back to start time for all {n} tasks." + logger.explore( + "Window size is zero or negative — falling back to start time", + payload={"task_count": n}, + error="Non-positive window", ) return [start_dt] * n # If window is too small for even distribution (e.g. 10 tasks in 5 seconds), @@ -444,8 +451,10 @@ class ThrottledSchedulerConfigurator: # If interval is too small (e.g. < 1s), we might want a fallback, # but the spec says "handle too-small windows with explicit fallback/warning". if interval < 1: - logger.warning( - f"[calculate_schedule] Window too small for {n} tasks (interval {interval:.2f}s). Tasks will be highly concentrated." + logger.explore( + "Window too small for distribution", + payload={"task_count": n, "interval_seconds": round(interval, 2)}, + error="Sub-second interval", ) scheduled_times = [] for i in range(n): diff --git a/backend/src/core/superset_client/_base.py b/backend/src/core/superset_client/_base.py index 9ee4699e..5b20dee2 100644 --- a/backend/src/core/superset_client/_base.py +++ b/backend/src/core/superset_client/_base.py @@ -132,11 +132,11 @@ class SupersetClientBase: # @RELATION CALLS -> [AsyncAPIClient] async def _do_import(self, file_name: str | Path) -> dict: with belief_scope("_do_import"): - app_logger.debug(f"[_do_import][State] Uploading file: {file_name}") + app_logger.reason(f"Uploading file: {file_name}") file_path = Path(file_name) if not file_path.exists(): - app_logger.error( - f"[_do_import][Failure] File does not exist: {file_name}" + app_logger.explore( + f"File does not exist: {file_name}", error="FileNotFound" ) raise FileNotFoundError(f"File does not exist: {file_name}") return await self.client.upload_file( @@ -170,9 +170,9 @@ class SupersetClientBase: if not filename: timestamp = datetime.now().strftime("%Y%m%dT%H%M%S") filename = f"dashboard_export_{dashboard_id}_{timestamp}.zip" - app_logger.warning( - "[_resolve_export_filename][Warning] Generated filename: %s", - filename, + app_logger.explore( + "Generated fallback filename", + payload={"filename": filename}, ) return filename # #endregion SupersetClientResolveExportFilename @@ -201,9 +201,9 @@ class SupersetClientBase: if dash_id is not None: return dash_id if dash_slug is not None: - app_logger.debug( - "[_resolve_target_id_for_delete][State] Resolving ID by slug '%s'.", - dash_slug, + app_logger.reason( + "Resolving ID by slug", + payload={"slug": dash_slug}, ) try: _, candidates = await self.get_dashboards( @@ -213,16 +213,15 @@ class SupersetClientBase: ) if candidates: target_id = candidates[0]["id"] - app_logger.debug( - "[_resolve_target_id_for_delete][Success] Resolved slug to ID %s.", - target_id, + app_logger.reflect( + f"Resolved slug to ID {target_id}", ) return target_id except Exception as e: - app_logger.warning( - "[_resolve_target_id_for_delete][Warning] Could not resolve slug '%s' to ID: %s", - dash_slug, - e, + app_logger.explore( + "Could not resolve slug to ID", + payload={"slug": dash_slug}, + error=str(e), ) return None # #endregion SupersetClientResolveTargetIdForDelete @@ -254,9 +253,9 @@ class SupersetClientBase: } config = column_map.get(resource_type) if not config: - app_logger.warning( - "[get_all_resources][Warning] Unknown resource type: %s", - resource_type, + app_logger.explore( + "Unknown resource type", + payload={"resource_type": resource_type}, ) return [] query = {"columns": config["columns"]} diff --git a/backend/src/core/superset_client/_dashboards_crud.py b/backend/src/core/superset_client/_dashboards_crud.py index fcf60aab..330be60e 100644 --- a/backend/src/core/superset_client/_dashboards_crud.py +++ b/backend/src/core/superset_client/_dashboards_crud.py @@ -104,8 +104,9 @@ class SupersetDashboardsCrudMixin: or "Chart", }) except Exception as e: - app_logger.warning( - "[get_dashboard_detail][Warning] Failed to fetch dashboard charts: %s", e, + app_logger.explore( + "Failed to fetch dashboard charts", + error=str(e), ) try: datasets_response = await self.client.request( @@ -143,8 +144,9 @@ class SupersetDashboardsCrudMixin: "overview": fq_name, }) except Exception as e: - app_logger.warning( - "[get_dashboard_detail][Warning] Failed to fetch dashboard datasets: %s", e, + app_logger.explore( + "Failed to fetch dashboard datasets", + error=str(e), ) # Fallback: derive chart IDs from layout metadata if not charts: @@ -175,9 +177,9 @@ class SupersetDashboardsCrudMixin: chart_ids_from_position.update( self._extract_chart_ids_from_layout(raw_json_metadata) ) - app_logger.info( - "[get_dashboard_detail][State] Extracted %s fallback chart IDs from layout (dashboard_id=%s)", - len(chart_ids_from_position), dashboard_ref, + app_logger.reflect( + f"Extracted {len(chart_ids_from_position)} fallback chart IDs from layout", + payload={"dashboard_id": dashboard_ref, "fallback_count": len(chart_ids_from_position)}, ) for chart_id in sorted(chart_ids_from_position): try: @@ -194,9 +196,10 @@ class SupersetDashboardsCrudMixin: or chart_data.get("viz_type") or "Chart", }) except Exception as e: - app_logger.warning( - "[get_dashboard_detail][Warning] Failed to resolve fallback chart %s: %s", - chart_id, e, + app_logger.explore( + "Failed to resolve fallback chart", + payload={"chart_id": chart_id}, + error=str(e), ) # Backfill datasets from chart datasource IDs. dataset_ids_from_charts = { @@ -237,9 +240,10 @@ class SupersetDashboardsCrudMixin: "overview": fq_name, }) except Exception as e: - app_logger.warning( - "[get_dashboard_detail][Warning] Failed to resolve dataset %s: %s", - dataset_id, e, + app_logger.explore( + "Failed to resolve dataset", + payload={"dataset_id": dataset_id}, + error=str(e), ) unique_charts = {chart["id"]: chart for chart in charts} unique_datasets = {dataset["id"]: dataset for dataset in datasets} @@ -267,8 +271,8 @@ class SupersetDashboardsCrudMixin: # @RELATION CALLS -> [AsyncAPIClient] async def export_dashboard(self, dashboard_id: int) -> tuple[bytes, str]: with belief_scope("export_dashboard"): - app_logger.info( - "[export_dashboard][Enter] Exporting dashboard %s.", dashboard_id + app_logger.reason( + "Exporting dashboard", payload={"dashboard_id": dashboard_id} ) response = await self.client.request( method="GET", @@ -305,22 +309,23 @@ class SupersetDashboardsCrudMixin: try: return await self._do_import(file_path) except Exception as exc: - app_logger.error( - "[import_dashboard][Failure] First import attempt failed: %s", - exc, exc_info=True, + app_logger.explore( + "First import attempt failed", + error=str(exc), + exc_info=True, ) if not self.delete_before_reimport: raise target_id = await self._resolve_target_id_for_delete(dash_id, dash_slug) if target_id is None: - app_logger.error( - "[import_dashboard][Failure] No ID available for delete-retry." + app_logger.explore( + "No ID available for delete-retry", ) raise await self.delete_dashboard(target_id) - app_logger.info( - "[import_dashboard][State] Deleted dashboard ID %s, retrying import.", - target_id, + app_logger.reflect( + f"Deleted dashboard ID {target_id}, retrying import", + payload={"target_id": target_id}, ) return await self._do_import(file_path) # #endregion SupersetClientImportDashboard @@ -331,21 +336,21 @@ class SupersetDashboardsCrudMixin: # @RELATION CALLS -> [AsyncAPIClient] async def delete_dashboard(self, dashboard_id: int | str) -> None: with belief_scope("delete_dashboard"): - app_logger.info( - "[delete_dashboard][Enter] Deleting dashboard %s.", dashboard_id + app_logger.reason( + "Deleting dashboard", payload={"dashboard_id": dashboard_id} ) response = await self.client.request( method="DELETE", endpoint=f"/dashboard/{dashboard_id}" ) response = cast(dict, response) if response.get("result", True) is not False: - app_logger.info( - "[delete_dashboard][Success] Dashboard %s deleted.", dashboard_id + app_logger.reflect( + f"Dashboard {dashboard_id} deleted" ) else: - app_logger.warning( - "[delete_dashboard][Warning] Unexpected response while deleting %s: %s", - dashboard_id, response, + app_logger.explore( + "Unexpected response while deleting", + payload={"dashboard_id": dashboard_id, "response": response}, ) # #endregion SupersetClientDeleteDashboard # #endregion SupersetDashboardsCrudMixin diff --git a/backend/src/core/superset_client/_dashboards_list.py b/backend/src/core/superset_client/_dashboards_list.py index 9c8f7446..9a08781f 100644 --- a/backend/src/core/superset_client/_dashboards_list.py +++ b/backend/src/core/superset_client/_dashboards_list.py @@ -25,7 +25,7 @@ class SupersetDashboardsListMixin: # @RELATION CALLS -> [SupersetClientFetchAllPages] async def get_dashboards(self, query: dict | None = None) -> tuple[int, list[dict]]: with belief_scope("get_dashboards"): - app_logger.info("[get_dashboards][Enter] Fetching dashboards.") + app_logger.reason("Fetching dashboards") validated_query = self._validate_query_params(query or {}) if "columns" not in validated_query: validated_query["columns"] = [ diff --git a/backend/src/core/superset_client/_databases.py b/backend/src/core/superset_client/_databases.py index 21d26e92..0303f7e1 100644 --- a/backend/src/core/superset_client/_databases.py +++ b/backend/src/core/superset_client/_databases.py @@ -22,7 +22,7 @@ class SupersetDatabasesMixin: # @RELATION CALLS -> [SupersetClientFetchAllPages] async def get_databases(self, query: dict | None = None) -> tuple[int, list[dict]]: with belief_scope("get_databases"): - app_logger.info("[get_databases][Enter] Fetching databases.") + app_logger.reason("Fetching databases") validated_query = self._validate_query_params(query or {}) if "columns" not in validated_query: validated_query["columns"] = [] @@ -44,7 +44,7 @@ class SupersetDatabasesMixin: # @RELATION CALLS -> [AsyncAPIClient] async def get_database(self, database_id: int) -> dict: with belief_scope("get_database"): - app_logger.info("[get_database][Enter] Fetching database %s.", database_id) + app_logger.reason("Fetching database", payload={"database_id": database_id}) response = await self.client.request( method="GET", endpoint=f"/database/{database_id}" ) diff --git a/backend/src/core/superset_client/_datasets.py b/backend/src/core/superset_client/_datasets.py index 6cbff56a..f804d391 100644 --- a/backend/src/core/superset_client/_datasets.py +++ b/backend/src/core/superset_client/_datasets.py @@ -23,7 +23,7 @@ class SupersetDatasetsMixin: # @RELATION CALLS -> [SupersetClientFetchAllPages] async def get_datasets(self, query: dict | None = None) -> tuple[int, list[dict]]: with belief_scope("get_datasets"): - app_logger.info("[get_datasets][Enter] Fetching datasets.") + app_logger.reason("Fetching datasets") validated_query = self._validate_query_params(query) paginated_data = await self._fetch_all_pages( endpoint="/dataset/", @@ -86,8 +86,10 @@ class SupersetDatasetsMixin: return len(dashboards_data) return 0 except Exception as e: - app_logger.warning( - f"[get_dataset_linked_dashboard_count][Warning] Failed to fetch related dashboards for dataset {dataset_id}: {e}" + app_logger.explore( + "Failed to fetch related dashboards", + payload={"dataset_id": dataset_id}, + error=str(e), ) return 0 # #endregion SupersetClientGetDatasetLinkedDashboardCount @@ -185,8 +187,9 @@ class SupersetDatasetsMixin: {"id": dash_id, "title": f"Dashboard {dash_id}", "slug": None} ) except Exception as e: - app_logger.warning( - f"[get_dataset_detail][Warning] Failed to fetch related dashboards: {e}" + app_logger.explore( + "Failed to fetch related dashboards", + error=str(e), ) linked_dashboards = [] database_obj = dataset.get("database") @@ -224,7 +227,7 @@ class SupersetDatasetsMixin: # @RELATION CALLS -> [AsyncAPIClient] async def get_dataset(self, dataset_id: int) -> dict: with belief_scope("SupersetClient.get_dataset", f"id={dataset_id}"): - app_logger.info("[get_dataset][Enter] Fetching dataset %s.", dataset_id) + app_logger.reason("Fetching dataset", payload={"dataset_id": dataset_id}) response = await self.client.request( method="GET", endpoint=f"/dataset/{dataset_id}" ) @@ -239,7 +242,7 @@ class SupersetDatasetsMixin: # @RELATION CALLS -> [AsyncAPIClient] async def update_dataset(self, dataset_id: int, data: dict, override_columns: bool = False) -> dict: with belief_scope("SupersetClient.update_dataset", f"id={dataset_id}"): - app_logger.info("[update_dataset][Enter] Updating dataset %s.", dataset_id) + app_logger.reason("Updating dataset", payload={"dataset_id": dataset_id, "override_columns": override_columns}) endpoint = f"/dataset/{dataset_id}?override_columns={'true' if override_columns else 'false'}" response = await self.client.request( method="PUT", diff --git a/backend/src/core/task_manager/lifecycle.py b/backend/src/core/task_manager/lifecycle.py index 60bb3639..29934116 100644 --- a/backend/src/core/task_manager/lifecycle.py +++ b/backend/src/core/task_manager/lifecycle.py @@ -99,17 +99,20 @@ class JobLifecycle: ) -> Task: with belief_scope("JobLifecycle.create_task", f"plugin_id={plugin_id}"): if not self.plugin_loader.has_plugin(plugin_id): - logger.error(f"Plugin with ID '{plugin_id}' not found.") + logger.explore("Plugin not found in loader", payload={"plugin_id": plugin_id}, error=f"Plugin with ID '{plugin_id}' missing") raise ValueError(f"Plugin with ID '{plugin_id}' not found.") self.plugin_loader.get_plugin(plugin_id) if not isinstance(params, dict): - logger.error("Task parameters must be a dictionary.") + logger.explore("Task parameters validation failed", payload={"received_type": type(params).__name__}, error="Params must be a dict") raise ValueError("Task parameters must be a dictionary.") logger.reason("Creating task node") task = Task(plugin_id=plugin_id, params=params, user_id=user_id) self.graph.add_task(task) self.persistence_service.persist_task(task) - logger.info(f"Task {task.id} created (execution scheduled by TaskManager)") + logger.reflect( + "Task node created and registered", + payload={"task_id": task.id, "plugin_id": plugin_id}, + ) logger.reflect( "Task creation persisted", extra={"task_id": task.id, "plugin_id": plugin_id}, @@ -127,15 +130,16 @@ class JobLifecycle: with belief_scope("JobLifecycle._run_task", f"task_id={task_id}"): task = self.graph.get_task(task_id) if task is None: - logger.error(f"Task {task_id} not found in registry") + logger.explore("Task not found in registry", payload={"task_id": task_id}, error="Task missing from graph") return plugin = self.plugin_loader.get_plugin(task.plugin_id) logger.reason( "Transitioning task to running state", extra={"task_id": task_id, "plugin_id": task.plugin_id}, ) - logger.info( - f"Starting execution of task {task_id} for plugin '{plugin.name}'" + logger.reason( + "Starting execution of task", + payload={"task_id": task_id, "plugin_name": plugin.name}, ) task.status = TaskStatus.RUNNING task.started_at = datetime.now(UTC) @@ -173,7 +177,7 @@ class JobLifecycle: task.result = await asyncio.to_thread( plugin.execute, params ) - logger.info(f"Task {task_id} completed successfully") + logger.reflect("Task execution completed successfully", payload={"task_id": task_id}) task.status = TaskStatus.SUCCESS await self._broadcast_task_status(task) if add_log_callback: @@ -183,7 +187,7 @@ class JobLifecycle: source="system", ) except Exception as e: - logger.error(f"Task {task_id} failed: {e}") + logger.explore("Task execution failed", payload={"task_id": task_id}, error=str(e)) task.status = TaskStatus.FAILED await self._broadcast_task_status(task) if add_log_callback: @@ -197,8 +201,9 @@ class JobLifecycle: task.finished_at = datetime.now(UTC) await self.event_bus.flush_task_logs(task_id) self.persistence_service.persist_task(task) - logger.info( - f"Task {task_id} execution finished with status: {task.status}" + logger.reflect( + "Task execution finished", + payload={"task_id": task_id, "status": str(task.status)}, ) logger.reflect( "Task lifecycle reached persisted terminal state", diff --git a/backend/src/core/task_manager/manager.py b/backend/src/core/task_manager/manager.py index c49287d8..1b14d0a5 100644 --- a/backend/src/core/task_manager/manager.py +++ b/backend/src/core/task_manager/manager.py @@ -217,7 +217,7 @@ class TaskManager: if tasks_to_remove: self.event_bus.delete_logs_for_tasks(tasks_to_remove) removed = self.graph.remove_tasks(tasks_to_remove) - logger.info(f"Cleared {removed} tasks.") + logger.reason("Cleared tasks from registry", payload={"removed_count": removed}) return removed # #endregion clear_tasks diff --git a/backend/src/core/utils/async_network.py b/backend/src/core/utils/async_network.py index 4420d6d1..2addf240 100644 --- a/backend/src/core/utils/async_network.py +++ b/backend/src/core/utils/async_network.py @@ -138,7 +138,7 @@ class AsyncAPIClient: if cached_tokens and cached_tokens.get("access_token") and cached_tokens.get("csrf_token"): self._tokens = cached_tokens self._authenticated = True - app_logger.info("[async_authenticate][CacheHit] Reusing cached Superset auth tokens for %s", self.base_url) + app_logger.reflect("Reusing cached Superset auth tokens", payload={"base_url": self.base_url}) # Refresh CSRF token to set matching session cookie on this httpx client try: csrf_url = f"{self.api_base_url}/security/csrf_token/" @@ -160,7 +160,7 @@ class AsyncAPIClient: if cached_tokens and cached_tokens.get("access_token") and cached_tokens.get("csrf_token"): self._tokens = cached_tokens self._authenticated = True - app_logger.info("[async_authenticate][CacheHitAfterWait] Reusing cached Superset auth tokens for %s", self.base_url) + app_logger.reflect("Reusing cached Superset auth tokens after wait", payload={"base_url": self.base_url}) try: csrf_url = f"{self.api_base_url}/security/csrf_token/" csrf_resp = await self._client.get( @@ -176,7 +176,7 @@ class AsyncAPIClient: pass return self._tokens with belief_scope("AsyncAPIClient.authenticate"): - app_logger.info("[async_authenticate][Enter] Authenticating to %s", self.base_url) + app_logger.reason("Authenticating to Superset", payload={"base_url": self.base_url}) try: login_url = f"{self.api_base_url}/security/login" response = await self._client.post(login_url, json=self.auth) diff --git a/backend/src/core/utils/dataset_mapper.py b/backend/src/core/utils/dataset_mapper.py index 1128532e..22112eee 100644 --- a/backend/src/core/utils/dataset_mapper.py +++ b/backend/src/core/utils/dataset_mapper.py @@ -48,15 +48,14 @@ class DatasetMapper: ) -> dict[str, str]: with belief_scope("Fetch mappings via SQL Lab"): # Получаем датасет из Superset, чтобы узнать table_name и schema - dataset_response = client.get_dataset(dataset_id) + dataset_response = await client.get_dataset(dataset_id) dataset_data = dataset_response.get("result", dataset_response) table_name = dataset_data.get("table_name") table_schema = dataset_data.get("schema") or "public" database_name = dataset_data.get("database", {}).get("database_name", "") - app_logger.info( - "[get_sqllab_mappings] Dataset %d: %s.%s (db: %s)", - dataset_id, table_schema, table_name, database_name + app_logger.reason( + "Retrieved dataset info", payload={"dataset_id": dataset_id, "schema": table_schema, "table": table_name, "database": database_name} ) # Если SQL-запрос не указан, строим дефолтный для information_schema @@ -69,15 +68,15 @@ class DatasetMapper: f"FROM information_schema.columns\n" f"WHERE table_schema = '{table_schema}' AND table_name = '{table_name}';\n" ) - app_logger.info("[get_sqllab_mappings] Using default information_schema query for %s.%s", table_schema, table_name) + app_logger.reason("Using default information_schema query", payload={"schema": table_schema, "table": table_name}) else: - app_logger.info("[get_sqllab_mappings] Using custom SQL query") + app_logger.reason("Using custom SQL query") # Выполняем запрос через SQL Lab - app_logger.info("[get_sqllab_mappings] Executing SQL Lab query on database %d...", database_id) + app_logger.reason("Executing SQL Lab query", payload={"database_id": database_id}) result = await sqllab_executor.execute_and_poll(sql_query, database_id) rows = result.get("results") or result.get("data") or result.get("result", []) - app_logger.info("[get_sqllab_mappings] SQL Lab returned %d rows", len(rows)) + app_logger.reflect("SQL Lab query returned results", payload={"row_count": len(rows)}) mappings: dict[str, str] = {} for row in rows: @@ -86,7 +85,7 @@ class DatasetMapper: if col_name and verbose_name: mappings[col_name] = str(verbose_name) - app_logger.info("[get_sqllab_mappings] Extracted %d mappings", len(mappings)) + app_logger.reflect("Extracted column mappings from SQL Lab results", payload={"mapping_count": len(mappings)}) return mappings # #endregion get_sqllab_mappings @@ -100,14 +99,14 @@ class DatasetMapper: # @RETURN Dict[str, str] - Словарь с маппингами. def load_excel_mappings(self, file_path: str) -> dict[str, str]: with belief_scope("Load mappings from Excel"): - app_logger.info("[load_excel_mappings][Enter] Loading mappings from %s.", file_path) + app_logger.reason("Loading mappings from Excel file", payload={"file_path": file_path}) try: df = pd.read_excel(file_path) mappings = df.set_index('column_name')['verbose_name'].to_dict() - app_logger.info("[load_excel_mappings][Success] Loaded %d mappings.", len(mappings)) + app_logger.reflect("Loaded mappings from Excel file", payload={"count": len(mappings)}) return mappings except Exception as e: - app_logger.error("[load_excel_mappings][Failure] %s", e, exc_info=True) + app_logger.explore("Failed to load Excel mappings", payload={}, error=str(e), exc_info=True) raise # #endregion load_excel_mappings @@ -139,7 +138,7 @@ class DatasetMapper: excel_path: str | None = None, ): with belief_scope(f"Run dataset mapping for ID {dataset_id}"): - app_logger.info("[run_mapping][Enter] Starting dataset mapping for ID %d from source '%s'.", dataset_id, source) + app_logger.reason("Starting dataset mapping", payload={"dataset_id": dataset_id, "source": source}) mappings: dict[str, str] = {} try: @@ -150,7 +149,7 @@ class DatasetMapper: assert excel_path, "excel_path is required." mappings.update(self.load_excel_mappings(excel_path)) else: - app_logger.error("[run_mapping][Failure] Invalid source: %s.", source) + app_logger.explore("Invalid mapping source", payload={"source": source}, error=f"Invalid source: {source}") return dataset_response = await superset_client.get_dataset(dataset_id) @@ -232,11 +231,11 @@ class DatasetMapper: payload_for_update = {k: v for k, v in payload_for_update.items() if v is not None} await superset_client.update_dataset(dataset_id, payload_for_update) - app_logger.info("[run_mapping][Success] Dataset %d columns' verbose_name updated.", dataset_id) + app_logger.reflect("Dataset columns' verbose_name updated", payload={"dataset_id": dataset_id}) else: - app_logger.info("[run_mapping][State] No changes in columns' verbose_name, skipping update.") + app_logger.reason("No changes in columns' verbose_name, skipping update") except (AssertionError, FileNotFoundError, Exception) as e: - app_logger.error("[run_mapping][Failure] %s", e, exc_info=True) + app_logger.explore("Dataset mapping failed", error=str(e), exc_info=True) return # #endregion run_mapping # #endregion DatasetMapper diff --git a/backend/src/core/utils/fileio.py b/backend/src/core/utils/fileio.py index c9d6a30a..4f9f890f 100644 --- a/backend/src/core/utils/fileio.py +++ b/backend/src/core/utils/fileio.py @@ -41,7 +41,7 @@ def create_temp_file(content: bytes | None = None, suffix: str = ".zip", mode: s if is_dir: with tempfile.TemporaryDirectory(suffix=suffix) as temp_dir: resource_path = Path(temp_dir) - app_logger.debug("[create_temp_file][State] Created temporary directory: %s", resource_path) + app_logger.reason("Created temporary directory", payload={"dir": str(resource_path)}) yield resource_path else: fd, temp_path_str = tempfile.mkstemp(suffix=suffix) @@ -49,19 +49,19 @@ def create_temp_file(content: bytes | None = None, suffix: str = ".zip", mode: s os.close(fd) if content: resource_path.write_bytes(content) - app_logger.debug("[create_temp_file][State] Created temporary file: %s", resource_path) + app_logger.reason("Created temporary file", payload={"dir": str(resource_path)}) yield resource_path finally: if resource_path and resource_path.exists() and not dry_run: try: if resource_path.is_dir(): shutil.rmtree(resource_path) - app_logger.debug("[create_temp_file][Cleanup] Removed temporary directory: %s", resource_path) + app_logger.reason("Removed temporary directory", payload={"dir": str(resource_path)}) else: resource_path.unlink() - app_logger.debug("[create_temp_file][Cleanup] Removed temporary file: %s", resource_path) + app_logger.reason("Removed temporary file", payload={"dir": str(resource_path)}) except OSError as e: - app_logger.error("[create_temp_file][Failure] Error during cleanup of %s: %s", resource_path, e) + app_logger.explore("Error during cleanup", payload={"dir": str(resource_path)}, error=str(e)) # #endregion create_temp_file # #region remove_empty_directories [TYPE Function] # @ingroup Core @@ -70,20 +70,20 @@ def create_temp_file(content: bytes | None = None, suffix: str = ".zip", mode: s # @POST Все пустые поддиректории удалены, возвращено их количество. def remove_empty_directories(root_dir: str) -> int: with belief_scope(f"Remove empty directories in {root_dir}"): - app_logger.info("[remove_empty_directories][Enter] Starting cleanup of empty directories in %s", root_dir) + app_logger.reason("Starting cleanup of empty directories", payload={"root_dir": root_dir}) removed_count = 0 if not os.path.isdir(root_dir): - app_logger.error("[remove_empty_directories][Failure] Directory not found: %s", root_dir) + app_logger.explore("Directory not found", payload={"root_dir": root_dir}, error=f"Directory not found: {root_dir}") return 0 for current_dir, _, _ in os.walk(root_dir, topdown=False): if not os.listdir(current_dir): try: os.rmdir(current_dir) removed_count += 1 - app_logger.info("[remove_empty_directories][State] Removed empty directory: %s", current_dir) + app_logger.reason("Removed empty directory", payload={"dir": current_dir}) except OSError as e: - app_logger.error("[remove_empty_directories][Failure] Failed to remove %s: %s", current_dir, e) - app_logger.reflect(f"Removed {removed_count} empty directories.", extra={"src": "remove_empty_directories"}) + app_logger.explore("Failed to remove empty directory", payload={"dir": current_dir}, error=str(e)) + app_logger.reflect("Removed empty directories", payload={"removed_count": removed_count}) return removed_count # #endregion remove_empty_directories # #region read_dashboard_from_disk [TYPE Function] @@ -95,10 +95,10 @@ def read_dashboard_from_disk(file_path: str) -> tuple[bytes, str]: with belief_scope(f"Read dashboard from {file_path}"): path = Path(file_path) assert path.is_file(), f"Файл дашборда не найден: {file_path}" - app_logger.info("[read_dashboard_from_disk][Enter] Reading file: %s", file_path) + app_logger.reason("Reading dashboard file from disk", payload={"file_path": file_path}) content = path.read_bytes() if not content: - app_logger.warning("[read_dashboard_from_disk][Warning] File is empty: %s", file_path) + app_logger.explore("Dashboard file is empty", payload={"file_path": file_path}, error=f"File is empty: {file_path}") return content, path.name # #endregion read_dashboard_from_disk # #region calculate_crc32 [TYPE Function] @@ -131,18 +131,18 @@ def archive_exports(output_dir: str, policy: RetentionPolicy, deduplicate: bool with belief_scope(f"Archive exports in {output_dir}"): output_path = Path(output_dir) if not output_path.is_dir(): - app_logger.warning("[archive_exports][Skip] Archive directory not found: %s", output_dir) + app_logger.explore("Archive directory not found, skipping", payload={"output_dir": output_dir}, error=f"Directory not found: {output_dir}") return - app_logger.info("[archive_exports][Enter] Managing archive in %s", output_dir) + app_logger.reason("Managing archive exports", payload={"output_dir": output_dir}) # 1. Collect all zip files zip_files = list(output_path.glob("*.zip")) if not zip_files: - app_logger.info("[archive_exports][State] No zip files found in %s", output_dir) + app_logger.reason("No zip files found in archive directory", payload={"output_dir": output_dir}) return # 2. Deduplication if deduplicate: - app_logger.info("[archive_exports][State] Starting deduplication...") + app_logger.reason("Starting deduplication of archive files") checksums = {} files_to_remove = [] @@ -154,19 +154,19 @@ def archive_exports(output_dir: str, policy: RetentionPolicy, deduplicate: bool crc = calculate_crc32(file_path) if crc in checksums: files_to_remove.append(file_path) - app_logger.debug("[archive_exports][State] Duplicate found: %s (same as %s)", file_path.name, checksums[crc].name) + app_logger.reason("Duplicate found", payload={"duplicate": file_path.name, "original": checksums[crc].name}) else: checksums[crc] = file_path except Exception as e: - app_logger.error("[archive_exports][Failure] Failed to calculate CRC32 for %s: %s", file_path, e) + app_logger.explore("Failed to calculate CRC32", payload={"file": str(file_path)}, error=str(e)) for f in files_to_remove: try: f.unlink() zip_files.remove(f) - app_logger.info("[archive_exports][State] Removed duplicate: %s", f.name) + app_logger.reason("Removed duplicate archive", payload={"file": f.name}) except OSError as e: - app_logger.error("[archive_exports][Failure] Failed to remove duplicate %s: %s", f, e) + app_logger.explore("Failed to remove duplicate archive", payload={"file": str(f)}, error=str(e)) # 3. Retention Policy files_with_dates = [] for file_path in zip_files: @@ -179,7 +179,7 @@ def archive_exports(output_dir: str, policy: RetentionPolicy, deduplicate: bool date_str = match.group(1) file_date = datetime.strptime(date_str, "%Y%m%d").date() except ValueError: - app_logger.debug("Could not parse date from filename %s", file_path.name) + app_logger.reason("Could not parse date from filename", payload={"file": file_path.name}) if not file_date: # Fallback to modification time @@ -192,9 +192,9 @@ def archive_exports(output_dir: str, policy: RetentionPolicy, deduplicate: bool if file_path not in files_to_keep: try: file_path.unlink() - app_logger.info("[archive_exports][State] Removed by retention policy: %s", file_path.name) + app_logger.reason("Removed by retention policy", payload={"file": file_path.name}) except OSError as e: - app_logger.error("[archive_exports][Failure] Failed to remove %s: %s", file_path, e) + app_logger.explore("Failed to remove archive by retention policy", payload={"file": str(file_path)}, error=str(e)) # #endregion archive_exports # #region apply_retention_policy [TYPE Function] # @ingroup Core @@ -225,7 +225,7 @@ def apply_retention_policy(files_with_dates: list[tuple[Path, date]], policy: Re files_to_keep.update(daily_files) files_to_keep.update(weekly_files[:policy.weekly]) files_to_keep.update(monthly_files[:policy.monthly]) - app_logger.debug("[apply_retention_policy][State] Keeping %d files according to retention policy", len(files_to_keep)) + app_logger.reason("Files to keep according to retention policy", payload={"count": len(files_to_keep)}) return files_to_keep # #endregion apply_retention_policy # #region save_and_unpack_dashboard [TYPE Function] @@ -235,22 +235,22 @@ def apply_retention_policy(files_with_dates: list[tuple[Path, date]], policy: Re # @POST ZIP-файл сохранен, и если unpack=True, он распакован в output_dir. def save_and_unpack_dashboard(zip_content: bytes, output_dir: str | Path, unpack: bool = False, original_filename: str | None = None) -> tuple[Path, Path | None]: with belief_scope("Save and unpack dashboard"): - app_logger.info("[save_and_unpack_dashboard][Enter] Processing dashboard. Unpack: %s", unpack) + app_logger.reason("Processing dashboard ZIP archive", payload={"unpack": unpack}) try: output_path = Path(output_dir) output_path.mkdir(parents=True, exist_ok=True) zip_name = sanitize_filename(original_filename) if original_filename else f"dashboard_export_{datetime.now().strftime('%Y%m%d_%H%M%S')}.zip" zip_path = output_path / zip_name zip_path.write_bytes(zip_content) - app_logger.info("[save_and_unpack_dashboard][State] Dashboard saved to: %s", zip_path) + app_logger.reason("Dashboard saved to disk", payload={"zip_path": str(zip_path)}) if unpack: with zipfile.ZipFile(zip_path, 'r') as zip_ref: zip_ref.extractall(output_path) - app_logger.info("[save_and_unpack_dashboard][State] Dashboard unpacked to: %s", output_path) + app_logger.reason("Dashboard unpacked to directory", payload={"output_path": str(output_path)}) return zip_path, output_path return zip_path, None except zipfile.BadZipFile as e: - app_logger.error("[save_and_unpack_dashboard][Failure] Invalid ZIP archive: %s", e) + app_logger.explore("Invalid ZIP archive", payload={}, error=str(e)) raise InvalidZipFormatError(f"Invalid ZIP file: {e}") from e # #endregion save_and_unpack_dashboard # #region update_yamls [TYPE Function] @@ -261,7 +261,7 @@ def save_and_unpack_dashboard(zip_content: bytes, output_dir: str | Path, unpack # @RELATION CALLS -> [_update_yaml_file] def update_yamls(db_configs: list[dict[str, Any]] | None = None, path: str = "dashboards", regexp_pattern: LiteralString | None = None, replace_string: LiteralString | None = None) -> None: with belief_scope("Update YAML configurations"): - app_logger.info("[update_yamls][Enter] Starting YAML configuration update.") + app_logger.reason("Starting YAML configuration update") dir_path = Path(path) assert dir_path.is_dir(), f"Путь {path} не существует или не является директорией" @@ -281,7 +281,7 @@ def _update_yaml_file(file_path: Path, db_configs: list[dict[str, Any]], regexp_ with open(file_path, encoding='utf-8') as f: content = f.read() except Exception as e: - app_logger.error("[_update_yaml_file][Failure] Failed to read %s: %s", file_path, e) + app_logger.explore("Failed to read YAML file", payload={"file": str(file_path)}, error=str(e)) return # Если задан pattern и replace_string, применяем замену по регулярному выражению if regexp_pattern and replace_string: @@ -290,9 +290,9 @@ def _update_yaml_file(file_path: Path, db_configs: list[dict[str, Any]], regexp_ if new_content != content: with open(file_path, 'w', encoding='utf-8') as f: f.write(new_content) - app_logger.info("[_update_yaml_file][State] Updated %s using regex pattern", file_path) + app_logger.reason("Updated YAML file using regex pattern", payload={"file": str(file_path)}) except Exception as e: - app_logger.error("[_update_yaml_file][Failure] Error applying regex to %s: %s", file_path, e) + app_logger.explore("Error applying regex to YAML file", payload={"file": str(file_path)}, error=str(e)) # Если заданы конфигурации, заменяем значения (поддержка old/new) if db_configs: try: @@ -325,12 +325,12 @@ def _update_yaml_file(file_path: Path, db_configs: list[dict[str, Any]], regexp_ return f"{prefix}{quote_open}{new_val}{quote_close}" # #endregion replacer modified_content = re.sub(pattern, replacer, modified_content) - app_logger.info("[_update_yaml_file][State] Replaced '%s' with '%s' for key %s in %s", old_val, new_val, key, file_path) + app_logger.reason("Replaced value in YAML file", payload={"old": old_val, "new": new_val, "key": key, "file": str(file_path)}) # Записываем обратно изменённый контент без парсинга YAML, сохраняем оригинальное форматирование with open(file_path, 'w', encoding='utf-8') as f: f.write(modified_content) except Exception as e: - app_logger.error("[_update_yaml_file][Failure] Error performing raw replacement in %s: %s", file_path, e) + app_logger.explore("Error performing replacement in YAML file", payload={"file": str(file_path)}, error=str(e)) # #endregion _update_yaml_file # #region create_dashboard_export [TYPE Function] # @ingroup Core @@ -339,7 +339,7 @@ def _update_yaml_file(file_path: Path, db_configs: list[dict[str, Any]], regexp_ # @POST ZIP-архив создан по пути zip_path. def create_dashboard_export(zip_path: str | Path, source_paths: list[str | Path], exclude_extensions: list[str] | None = None) -> bool: with belief_scope(f"Create dashboard export: {zip_path}"): - app_logger.info("[create_dashboard_export][Enter] Packing dashboard: %s -> %s", source_paths, zip_path) + app_logger.reason("Packing dashboard export", payload={"source_paths": [str(p) for p in source_paths], "zip_path": str(zip_path)}) try: exclude_ext = [ext.lower() for ext in exclude_extensions or []] with zipfile.ZipFile(zip_path, 'w', zipfile.ZIP_DEFLATED) as zipf: @@ -350,10 +350,10 @@ def create_dashboard_export(zip_path: str | Path, source_paths: list[str | Path] if item.is_file() and item.suffix.lower() not in exclude_ext: arcname = item.relative_to(src_path.parent) zipf.write(item, arcname) - app_logger.reflect(f"Archive created: {zip_path}", extra={"src": "create_dashboard_export"}) + app_logger.reflect("Archive created", payload={"zip_path": str(zip_path)}) return True except (OSError, zipfile.BadZipFile, AssertionError) as e: - app_logger.error("[create_dashboard_export][Failure] Error: %s", e, exc_info=True) + app_logger.explore("Error creating dashboard export", payload={}, error=str(e), exc_info=True) return False # #endregion create_dashboard_export # #region sanitize_filename [TYPE Function] @@ -387,7 +387,7 @@ def consolidate_archive_folders(root_directory: Path) -> None: assert isinstance(root_directory, Path), "root_directory must be a Path object." assert root_directory.is_dir(), "root_directory must be an existing directory." - app_logger.info("[consolidate_archive_folders][Enter] Consolidating archives in %s", root_directory) + app_logger.reason("Consolidating archive folders", payload={"root": str(root_directory)}) # Собираем все директории с архивами archive_dirs = [] for item in root_directory.iterdir(): @@ -410,7 +410,7 @@ def consolidate_archive_folders(root_directory: Path) -> None: # Создаем целевую директорию target_dir = root_directory / slug target_dir.mkdir(exist_ok=True) - app_logger.info("[consolidate_archive_folders][State] Consolidating %d directories under %s", len(dirs), target_dir) + app_logger.reason("Consolidating directories", payload={"count": len(dirs), "target": str(target_dir)}) # Перемещаем содержимое for source_dir in dirs: if source_dir == target_dir: @@ -423,13 +423,13 @@ def consolidate_archive_folders(root_directory: Path) -> None: else: shutil.move(str(item), str(dest_item)) except Exception as e: - app_logger.error("[consolidate_archive_folders][Failure] Failed to move %s to %s: %s", item, dest_item, e) + app_logger.explore("Failed to move item", payload={"source": str(item), "dest": str(dest_item)}, error=str(e)) # Удаляем исходную директорию try: source_dir.rmdir() - app_logger.info("[consolidate_archive_folders][State] Removed source directory: %s", source_dir) + app_logger.reason("Removed source directory", payload={"dir": str(source_dir)}) except Exception as e: - app_logger.error("[consolidate_archive_folders][Failure] Failed to remove source directory %s: %s", source_dir, e) + app_logger.explore("Failed to remove source directory", payload={"dir": str(source_dir)}, error=str(e)) # #endregion consolidate_archive_folders # #region AsyncFileIOWrappers [C:3] [TYPE Module] [SEMANTICS async, fileio, aiofiles, run_blocking] # @defgroup Core Module group. @@ -461,8 +461,8 @@ async def aread_dashboard_from_disk(file_path: str) -> bytes: else: content = await run_blocking(kind="file", fn=path.read_bytes) if not content: - app_logger.warning( - "[aread_dashboard_from_disk][Warning] File is empty: %s", file_path + app_logger.explore( + "Dashboard file is empty", payload={"file_path": file_path}, error=f"File is empty: {file_path}" ) return content # #endregion aread_dashboard_from_disk @@ -478,8 +478,8 @@ async def asave_and_unpack_dashboard( zip_content: bytes, target_dir: str, unpack: bool = False, original_filename: str | None = None ) -> tuple[Path, Path | None]: with belief_scope(f"Async save and unpack dashboard in {target_dir}"): - app_logger.info( - "[asave_and_unpack_dashboard][Enter] Processing dashboard. Unpack: %s", unpack + app_logger.reason( + "Processing dashboard ZIP archive", payload={"unpack": unpack} ) output_path = Path(target_dir) await run_blocking(kind="file", fn=output_path.mkdir, parents=True, exist_ok=True) @@ -491,8 +491,8 @@ async def asave_and_unpack_dashboard( zip_path = output_path / zip_name async with aiofiles.open(zip_path, "wb") as f: await f.write(zip_content) - app_logger.info( - "[asave_and_unpack_dashboard][State] Dashboard saved to: %s", zip_path + app_logger.reason( + "Dashboard saved to disk", payload={"zip_path": str(zip_path)} ) if unpack: await run_blocking( @@ -501,8 +501,8 @@ async def asave_and_unpack_dashboard( str(zip_path), str(output_path), ) - app_logger.info( - "[asave_and_unpack_dashboard][State] Dashboard unpacked to: %s", output_path + app_logger.reason( + "Dashboard unpacked to directory", payload={"output_path": str(output_path)} ) return zip_path, output_path return zip_path, None diff --git a/backend/src/core/utils/superset_context_extractor/_parsing.py b/backend/src/core/utils/superset_context_extractor/_parsing.py index a6f50515..8c21e60c 100644 --- a/backend/src/core/utils/superset_context_extractor/_parsing.py +++ b/backend/src/core/utils/superset_context_extractor/_parsing.py @@ -75,7 +75,7 @@ class SupersetContextParsingMixin: "Resolving dashboard permalink state from Superset", extra={"permalink_key": dashboard_permalink_key}, ) - permalink_payload = self.client.get_dashboard_permalink_state( + permalink_payload = await self.client.get_dashboard_permalink_state( dashboard_permalink_key ) permalink_state = ( @@ -262,7 +262,7 @@ class SupersetContextParsingMixin: dataset_payload: dict[str, Any] | None = None if dataset_id is not None: try: - dataset_payload = self.client.get_dataset_detail(dataset_id) + dataset_payload = await self.client.get_dataset_detail(dataset_id) table_name = str( dataset_payload.get("table_name") or "" ).strip() diff --git a/backend/src/core/utils/superset_context_extractor/_recovery.py b/backend/src/core/utils/superset_context_extractor/_recovery.py index 4477a262..d3426dba 100644 --- a/backend/src/core/utils/superset_context_extractor/_recovery.py +++ b/backend/src/core/utils/superset_context_extractor/_recovery.py @@ -29,7 +29,7 @@ class SupersetContextRecoveryMixin: # @POST returns explicit recovered and partial filter entries with preserved provenance and confirmation requirements. # @SIDE_EFFECT may issue Superset reads for dashboard metadata enrichment. # @DATA_CONTRACT Input[SupersetParsedContext] -> Output[List[Dict[str,Any]]] - def recover_imported_filters( + async def recover_imported_filters( self, parsed_context: SupersetParsedContext ) -> list[dict[str, Any]]: with belief_scope("SupersetContextExtractor.recover_imported_filters"): @@ -90,7 +90,7 @@ class SupersetContextRecoveryMixin: existing["notes"] = f"{existing['notes']}; {candidate['notes']}" if parsed_context.dashboard_id is not None: try: - dashboard_payload = self.client.get_dashboard( + dashboard_payload = await self.client.get_dashboard( parsed_context.dashboard_id ) dashboard_record = ( diff --git a/backend/src/dependencies.py b/backend/src/dependencies.py index f4184050..373935a5 100755 --- a/backend/src/dependencies.py +++ b/backend/src/dependencies.py @@ -115,9 +115,10 @@ def get_plugin_loader() -> PluginLoader: global plugin_loader if plugin_loader is None: plugin_loader = PluginLoader(plugin_dir=str(plugin_dir)) - logger.info(f"PluginLoader initialized with directory: {plugin_dir}") - logger.info( - f"Available plugins: {[config.name for config in plugin_loader.get_all_plugin_configs()]}" + logger.reason("PluginLoader initialized", payload={"plugin_dir": str(plugin_dir)}) + logger.reflect( + "Available plugins loaded", + payload={"plugins": [config.name for config in plugin_loader.get_all_plugin_configs()]}, ) return plugin_loader @@ -134,7 +135,7 @@ def get_task_manager() -> TaskManager: global task_manager if task_manager is None: task_manager = TaskManager(get_plugin_loader()) - logger.info("TaskManager initialized") + logger.reason("TaskManager initialized") return task_manager @@ -150,7 +151,7 @@ def get_scheduler_service() -> SchedulerService: global scheduler_service if scheduler_service is None: scheduler_service = SchedulerService(get_task_manager(), get_config_manager()) - logger.info("SchedulerService initialized") + logger.reason("SchedulerService initialized") return scheduler_service @@ -172,7 +173,7 @@ def get_async_job_runner() -> AsyncJobRunner: loop = asyncio.new_event_loop() asyncio.set_event_loop(loop) async_job_runner = AsyncJobRunner(loop) - logger.info("AsyncJobRunner initialized") + logger.reason("AsyncJobRunner initialized") return async_job_runner @@ -188,7 +189,7 @@ def get_resource_service() -> ResourceService: global resource_service if resource_service is None: resource_service = ResourceService() - logger.info("ResourceService initialized") + logger.reason("ResourceService initialized") return resource_service @@ -360,7 +361,7 @@ def require_api_key_or_jwt( detail=f"Permission denied for {required_jwt_resource}:{required_jwt_action}", ) - logger.info(f"JWT auth: {user.username}") + logger.reason("JWT auth", payload={"username": user.username}) return f"jwt:{user.username}" # ── Try API key auth ── @@ -408,7 +409,7 @@ def require_api_key_or_jwt( api_key.last_used_at = datetime.now(UTC) db.flush() - logger.info(f"API key auth: {api_key.name} ({api_key.prefix}...)") + logger.reason("API key auth", payload={"name": api_key.name, "prefix": api_key.prefix}) return f"api_key:{api_key.name}" # ── Neither JWT nor API key provided ── @@ -489,14 +490,14 @@ async def get_api_key_principal( api_key = db.query(APIKey).filter(APIKey.key_hash == key_hash).first() if not api_key: - logger.warning(f"API key auth failed: key not found (hash prefix: {raw_key[:11]}...)") + logger.explore("API key auth failed", payload={"hash_prefix": raw_key[:11]}, error="Key not found") raise HTTPException( status_code=status.HTTP_401_UNAUTHORIZED, detail="Invalid API key", ) if not api_key.active: - logger.warning(f"API key auth failed: key revoked (id: {api_key.id}, name: {api_key.name})") + logger.explore("API key auth failed", payload={"id": api_key.id, "name": api_key.name}, error="Key revoked") raise HTTPException( status_code=status.HTTP_401_UNAUTHORIZED, detail="API key has been revoked", @@ -507,7 +508,7 @@ async def get_api_key_principal( if expires_at.tzinfo is None: expires_at = expires_at.replace(tzinfo=UTC) if expires_at < datetime.now(UTC): - logger.warning(f"API key auth failed: key expired (id: {api_key.id}, name: {api_key.name})") + logger.explore("API key auth failed", payload={"id": api_key.id, "name": api_key.name}, error="Key expired") raise HTTPException( status_code=status.HTTP_401_UNAUTHORIZED, detail="API key has expired", @@ -517,7 +518,7 @@ async def get_api_key_principal( api_key.last_used_at = datetime.now(UTC) db.flush() - logger.info(f"API key auth success: {api_key.name} ({api_key.prefix}...)") + logger.reason("API key auth success", payload={"name": api_key.name, "prefix": api_key.prefix}) return APIKeyPrincipal( name=api_key.name, api_key_id=api_key.id, diff --git a/backend/src/plugins/git_plugin.py b/backend/src/plugins/git_plugin.py index 6bc58c82..3910d8f1 100644 --- a/backend/src/plugins/git_plugin.py +++ b/backend/src/plugins/git_plugin.py @@ -134,18 +134,18 @@ class GitPlugin(PluginBase): # @POST Инициализированы git_service и config_manager. def __init__(self): with belief_scope("GitPlugin.__init__"): - app_logger.info("Initializing GitPlugin.") + app_logger.reason("Initializing GitPlugin", extra={"src": "GitPlugin.__init__"}) self.git_service = GitService() # Используем shared config_manager из dependencies try: from src.dependencies import config_manager self.config_manager = config_manager - app_logger.info("GitPlugin initialized using shared config_manager.") + app_logger.reflect("GitPlugin initialized using shared config_manager", extra={"src": "GitPlugin.__init__"}) except Exception as exc: - app_logger.error(f"GitPlugin: failed to get shared config_manager: {exc}") + app_logger.explore("Failed to get shared config_manager", extra={"src": "GitPlugin.__init__"}, error=str(exc)) self.config_manager = ConfigManager() - app_logger.info("GitPlugin initialized with fallback ConfigManager.") + app_logger.reflect("GitPlugin initialized with fallback ConfigManager", extra={"src": "GitPlugin.__init__"}) # endregion __init__ @property @@ -296,11 +296,11 @@ class GitPlugin(PluginBase): except Exception as ge: app_logger.explore(f"Failed to stage changes: {ge}", extra={"src": "_handle_sync"}) - app_logger.info(f"[_handle_sync][Coherence:OK] Dashboard {dashboard_id} synced successfully.") + app_logger.reflect(f"Dashboard {dashboard_id} synced successfully", extra={"src": "_handle_sync"}, payload={"dashboard_id": dashboard_id}) return {"status": "success", "message": "Dashboard synced and flattened in local repository"} except Exception as e: - app_logger.error(f"[_handle_sync][Coherence:Failed] Sync failed: {e}") + app_logger.explore("Sync failed", extra={"src": "_handle_sync"}, error=str(e), payload={"dashboard_id": dashboard_id}) raise # endregion _handle_sync @@ -346,14 +346,14 @@ class GitPlugin(PluginBase): try: app_logger.reason(f"Importing dashboard to {env.name}", extra={"src": "_handle_deploy"}) result = await client.import_dashboard(temp_zip_path) - app_logger.info(f"[_handle_deploy][Coherence:OK] Deployment successful for dashboard {dashboard_id}.") + app_logger.reflect(f"Deployment successful for dashboard {dashboard_id}", extra={"src": "_handle_deploy"}, payload={"dashboard_id": dashboard_id, "env": env.name}) return {"status": "success", "message": f"Dashboard deployed to {env.name}", "details": result} finally: if await run_blocking(kind='file', fn=temp_zip_path.exists): await run_blocking(kind='file', fn=os.remove, path=temp_zip_path) except Exception as e: - app_logger.error(f"[_handle_deploy][Coherence:Failed] Deployment failed: {e}") + app_logger.explore("Deployment failed", extra={"src": "_handle_deploy"}, error=str(e), payload={"dashboard_id": dashboard_id}) raise # endregion _handle_deploy @@ -412,7 +412,7 @@ class GitPlugin(PluginBase): app_logger.reflect(f"Using first environment from ConfigManager: {envs[0].name}", extra={"src": "_get_env"}) return envs[0] - app_logger.error(f"[_get_env][Coherence:Failed] No environments configured (searched config.json and DB). env_id={env_id}") + app_logger.explore("No environments configured", extra={"src": "_get_env"}, payload={"env_id": env_id, "searched": ["config.json", "DB"]}) raise ValueError("No environments configured. Please add a Superset Environment in Settings.") # endregion _get_env diff --git a/backend/src/plugins/llm_analysis/service.py b/backend/src/plugins/llm_analysis/service.py index 3b59bb1e..fde33af5 100644 --- a/backend/src/plugins/llm_analysis/service.py +++ b/backend/src/plugins/llm_analysis/service.py @@ -149,13 +149,13 @@ class ScreenshotService: hidden_fields = await self._extract_hidden_login_fields(page) csrf_token = str(hidden_fields.get("csrf_token") or "").strip() if not csrf_token: - logger.warning("[DEBUG] Direct form login fallback skipped: csrf_token not found") + logger.explore("Direct form login fallback skipped: csrf_token not found", error="Missing csrf_token in login form") return False try: request_context = page.context.request except Exception as context_error: - logger.warning(f"[DEBUG] Direct form login fallback skipped: request context unavailable: {context_error}") + logger.explore("Direct form login fallback skipped: request context unavailable", payload={"error": str(context_error)}, error="Browser request context unavailable") return False parsed_url = urlsplit(login_url) @@ -163,8 +163,9 @@ class ScreenshotService: payload = dict(hidden_fields) payload["username"] = self.env.username payload["password"] = self.env.password - logger.info( - f"[DEBUG] Attempting direct form login fallback via browser context request with hidden fields: {sorted(hidden_fields.keys())}" + logger.reason( + "Attempting direct form login fallback via browser context request", + payload={"hidden_fields": sorted(hidden_fields.keys())}, ) response = await request_context.post( @@ -189,16 +190,18 @@ class ScreenshotService: redirect_statuses = {301, 302, 303, 307, 308} if response_status in redirect_statuses: redirect_authenticated = self._redirect_looks_authenticated(redirect_location) - logger.info( - f"[DEBUG] Direct form login fallback redirect response: status={response_status} url={response_url} location={redirect_location!r} authenticated={redirect_authenticated}" + logger.reason( + "Direct form login fallback redirect response", + payload={"status": response_status, "url": response_url, "location": redirect_location, "authenticated": redirect_authenticated}, ) return redirect_authenticated response_text = await response.text() text_snippet = " ".join(response_text.split())[:200] looks_like_login_page = self._response_looks_like_login_page(response_text) - logger.info( - f"[DEBUG] Direct form login fallback response: status={response_status} url={response_url} login_markup={looks_like_login_page} snippet={text_snippet!r}" + logger.reason( + "Direct form login fallback response", + payload={"status": response_status, "url": response_url, "login_markup": looks_like_login_page, "snippet": text_snippet}, ) return not looks_like_login_page # endregion ScreenshotService._submit_login_via_form_post @@ -278,8 +281,10 @@ class ScreenshotService: try: return await page.goto(url, wait_until=primary_wait_until, timeout=timeout) except Exception as primary_error: - logger.warning( - f"[ScreenshotService._goto_resilient] Primary navigation wait '{primary_wait_until}' failed for {url}: {primary_error}" + logger.explore( + "Primary navigation wait failed, falling back to fallback wait", + payload={"primary_wait_until": primary_wait_until, "url": url}, + error=str(primary_error), ) return await page.goto(url, wait_until=fallback_wait_until, timeout=timeout) # endregion ScreenshotService._goto_resilient @@ -308,7 +313,7 @@ class ScreenshotService: }); }""", timeout=timeout_ms) except Exception: - logger.warning("[ScreenshotService] Chart stabilization wait timed out, proceeding anyway") + logger.explore("Chart stabilization wait timed out, proceeding anyway", error="Timed out waiting for charts to render") # endregion ScreenshotService._wait_for_charts_stabilized # region ScreenshotService._wait_for_resize_rendered [TYPE Function] [C:2] @@ -328,7 +333,7 @@ class ScreenshotService: return currentCharts > 0 && (currentCanvases > 0 || currentSvgs > 0); }""", arg=chart_count_before, timeout=timeout_ms) except Exception: - logger.warning("[ScreenshotService] Re-render wait timed out after viewport resize, proceeding anyway") + logger.explore("Re-render wait timed out after viewport resize, proceeding anyway", error="Timed out waiting for charts to re-render after resize") # endregion ScreenshotService._wait_for_resize_rendered # region ScreenshotService._save_debug_screenshot [TYPE Function] [C:1] @@ -524,7 +529,7 @@ class ScreenshotService: pass await self._wait_for_charts_stabilized(page) - logger.info(f"[_launch_and_login] Login + navigation successful for dashboard {dashboard_id}") + logger.reflect("Login and navigation to dashboard successful", payload={"dashboard_id": dashboard_id}) return browser, context, page # endregion ScreenshotService._launch_and_login @@ -584,7 +589,7 @@ class ScreenshotService: if not found_tabs: return - logger.info(f"[capture_dashboard_chunks] Found {len(found_tabs)} tabs at depth {depth}") + logger.reason("Found tabs at current depth", payload={"tab_count": len(found_tabs), "depth": depth}) for i, tab in enumerate(found_tabs): try: tab_text = (await tab.inner_text()).strip() @@ -597,7 +602,7 @@ class ScreenshotService: continue processed_tabs.add(tab_id) - logger.info(f"[capture_dashboard_chunks] Switching to tab: {tab_text}") + logger.reason("Switching to tab", payload={"tab_text": tab_text, "depth": depth, "index": i}) is_active = "ant-tabs-tab-active" in (await tab.get_attribute("class") or "") if not is_active: @@ -615,8 +620,10 @@ class ScreenshotService: timeout=PLAYWRIGHT_WAIT_TIMEOUT_MS, ) except Exception: - logger.warning( - f"[capture_dashboard_chunks] Content verification timed out for tab: {tab_text}" + logger.explore( + "Content verification timed out after tab switch", + payload={"tab_text": tab_text}, + error="Verification wait timed out", ) # Wait for charts to stabilize @@ -648,21 +655,24 @@ class ScreenshotService: with open(tab_path, "wb") as f: f.write(image_data) except Exception as cdp_err: - logger.warning( - f"[capture_dashboard_chunks] CDP failed for tab {tab_text}: {cdp_err}. " - "Falling back to Playwright full_page." + logger.explore( + "CDP screenshot failed, falling back to Playwright full_page", + payload={"tab_text": tab_text}, + error=str(cdp_err), ) await page.screenshot(path=tab_path, full_page=True, timeout=PLAYWRIGHT_WAIT_TIMEOUT_MS) - logger.info(f"[capture_dashboard_chunks] Saved screenshot: {tab_path}") + logger.reason("Saved screenshot for tab", payload={"tab_path": tab_path, "tab_text": tab_text}) results.append({"tab_name": tab_text, "path": tab_path}) # Recurse into nested tabs await _capture_tabs(depth + 1) except Exception as tab_e: - logger.warning( - f"[capture_dashboard_chunks] Failed to process tab {i} at depth {depth}: {tab_e}" + logger.explore( + "Failed to process tab", + payload={"tab_index": i, "depth": depth}, + error=str(tab_e), ) # Return to first tab @@ -677,7 +687,7 @@ class ScreenshotService: # If no tabs found, capture the whole page as a single chunk if not results: - logger.info("[capture_dashboard_chunks] No tabs found, capturing full-page as single chunk") + logger.reason("No tabs found, capturing full-page as single chunk") await self._wait_for_charts_stabilized(page) await page.set_viewport_size({"width": 1920, "height": 1200}) @@ -696,7 +706,7 @@ class ScreenshotService: with open(tab_path, "wb") as f: f.write(image_data) except Exception as cdp_err: - logger.warning(f"[capture_dashboard_chunks] CDP full fallback failed: {cdp_err}") + logger.explore("CDP full-page fallback failed, using Playwright full_page", payload={}, error=str(cdp_err)) await page.screenshot(path=tab_path, full_page=True, timeout=PLAYWRIGHT_WAIT_TIMEOUT_MS) results.append({"tab_name": "full", "path": tab_path}) @@ -728,27 +738,29 @@ class ScreenshotService: os.makedirs(output_dir, exist_ok=True) with belief_scope("capture_dashboard", f"dashboard_id={dashboard_id}"): - logger.info(f"Capturing screenshots for dashboard {dashboard_id}") + logger.reason("Capturing dashboard screenshots", payload={"dashboard_id": dashboard_id}) # 1. Capture per-tab screenshots chunks = await self.capture_dashboard_chunks(dashboard_id, output_dir) png_paths = [c["path"] for c in chunks if c.get("path")] if not png_paths: - logger.warning(f"[capture_dashboard] No screenshots captured for dashboard {dashboard_id}") + logger.explore("No screenshots captured for dashboard", payload={"dashboard_id": dashboard_id}, error="All capture attempts returned empty") return [], [] # 2. Convert PNGs to JPEGs for LLM jpeg_paths = self._convert_screenshots_for_llm(png_paths, output_dir) - logger.info( - f"[capture_dashboard] Converted {len(jpeg_paths)}/{len(png_paths)} PNGs to JPEGs for LLM" + logger.reason( + "Converted PNGs to JPEGs for LLM analysis", + payload={"converted": len(jpeg_paths), "total": len(png_paths)}, ) # 3. Archive to WebP (deletes PNGs on success) archive_results = self._archive_screenshots_as_webp(png_paths, output_dir) - logger.info( - f"[capture_dashboard] Archived {sum(1 for r in archive_results if r.get('webp_path'))} " - f"of {len(archive_results)} screenshots to WebP" + archived_count = sum(1 for r in archive_results if r.get("webp_path")) + logger.reason( + "Archived screenshots to WebP", + payload={"archived": archived_count, "total": len(archive_results)}, ) # 4. Return JPEGs for LLM — caller cleans up after analysis @@ -785,7 +797,7 @@ class ScreenshotService: img.save(jpeg_path, format="JPEG", quality=60, optimize=True) jpeg_paths.append(jpeg_path) except Exception as e: - logger.warning(f"[convert_for_llm] Failed to convert {png_path}: {e}") + logger.explore("Failed to convert screenshot for LLM", payload={"png_path": png_path}, error=str(e)) return jpeg_paths # endregion ScreenshotService._convert_screenshots_for_llm @@ -818,7 +830,7 @@ class ScreenshotService: results.append({"original": png_path, "webp_path": webp_path}) except Exception as e: - logger.warning(f"[archive_webp] Failed to convert {png_path}: {e}. Keeping PNG.") + logger.explore("Failed to archive screenshot to WebP, keeping PNG", payload={"png_path": png_path}, error=str(e)) results.append({"original": png_path, "webp_path": None}) return results @@ -834,7 +846,7 @@ class ScreenshotService: if os.path.exists(path): os.remove(path) except Exception as e: - logger.warning(f"[cleanup] Failed to delete {path}: {e}") + logger.explore("Failed to delete temporary file", payload={"path": path}, error=str(e)) # endregion ScreenshotService._cleanup_temp_files # #endregion ScreenshotService @@ -855,12 +867,16 @@ class LLMClient: self.default_model = default_model # DEBUG: Log initialization parameters (without exposing full API key) - logger.info("[LLMClient.__init__] Initializing LLM client:") - logger.info(f"[LLMClient.__init__] Provider Type: {provider_type}") - logger.info(f"[LLMClient.__init__] Base URL: {base_url}") - logger.info(f"[LLMClient.__init__] Default Model: {default_model}") - logger.info(f"[LLMClient.__init__] API Key (first 8 chars): {self.api_key[:8] if self.api_key and len(self.api_key) > 8 else 'EMPTY_OR_NONE'}...") - logger.info(f"[LLMClient.__init__] API Key Length: {len(self.api_key) if self.api_key else 0}") + logger.reason( + "Initializing LLM client", + payload={ + "provider_type": str(provider_type), + "base_url": base_url, + "default_model": default_model, + "api_key_prefix": self.api_key[:8] if self.api_key and len(self.api_key) > 8 else "EMPTY_OR_NONE", + "api_key_length": len(self.api_key) if self.api_key else 0, + }, + ) # Some OpenAI-compatible gateways are strict about auth header naming. default_headers = {"Authorization": f"Bearer {self.api_key}"} @@ -879,7 +895,10 @@ class LLMClient: # is sufficient. No additional headers like HTTP-Referer or X-API-Key are required. ssl_verify = self._get_ssl_verify() - logger.info(f"[LLMClient.__init__] SSL Verify: {ssl_verify} (set LLM_SSL_VERIFY=false to disable)") + ssl_desc = str(ssl_verify) + if isinstance(ssl_verify, ssl.SSLContext): + ssl_desc = f"SSLContext(capath={ssl_verify.capath if hasattr(ssl_verify, 'capath') else 'default'})" + logger.reason("LLM client SSL verification configured", payload={"ssl_verify": ssl_desc}) http_client = httpx.AsyncClient( headers=default_headers, @@ -982,13 +1001,16 @@ class LLMClient: try: use_json_mode = self._supports_json_response_format() try: - logger.info( - f"[get_json_completion] Attempting LLM call for model: {self.default_model} " - f"(json_mode={'on' if use_json_mode else 'off'})" + logger.reason( + "Attempting LLM call", + payload={ + "model": self.default_model, + "json_mode": "on" if use_json_mode else "off", + "base_url": self.base_url, + "message_count": len(messages), + "api_key_present": bool(self.api_key and len(self.api_key) > 0), + }, ) - logger.info(f"[get_json_completion] Base URL being used: {self.base_url}") - logger.info(f"[get_json_completion] Number of messages: {len(messages)}") - logger.info(f"[get_json_completion] API Key present: {bool(self.api_key and len(self.api_key) > 0)}") if use_json_mode: response = await self.client.chat.completions.create( @@ -1008,7 +1030,7 @@ class LLMClient: or "response_format" in str(e).lower() or "400" in str(e) ): - logger.warning(f"[get_json_completion] JSON mode failed or not supported: {e!s}. Falling back to plain text response.") + logger.explore("JSON mode failed or not supported, falling back to plain text", payload={"model": self.default_model}, error=str(e)) response = await self.client.chat.completions.create( model=self.default_model, messages=messages @@ -1016,13 +1038,13 @@ class LLMClient: else: raise e - logger.debug(f"[get_json_completion] LLM Response: {response}") + logger.reflect("LLM API response received", payload={"response_summary": str(response)[:200]}) except OpenAIAuthenticationError as e: - logger.error(f"[get_json_completion] Authentication error: {e!s}") + logger.explore("LLM authentication error, not retrying", payload={"model": self.default_model}, error=str(e)) # Do not retry on auth errors - re-raise to stop retry raise except RateLimitError as e: - logger.warning(f"[get_json_completion] Rate limit hit: {e!s}") + logger.explore("Rate limit hit on LLM call, retrying with backoff", payload={}, error=str(e)) # Extract retry_delay from error metadata if available retry_delay = 5.0 # Default fallback @@ -1048,17 +1070,18 @@ class LLMClient: retry_delay = float(delay_str.rstrip('s')) break except Exception as parse_e: - logger.debug(f"[get_json_completion] Failed to parse retry delay: {parse_e}") + logger.explore("Failed to parse retry delay from error response", payload={}, error=str(parse_e)) # Add a small safety margin (0.5s) as requested wait_time = retry_delay + 0.5 - logger.info(f"[get_json_completion] Waiting for {wait_time}s before retry...") + logger.reason("Waiting before LLM retry", payload={"wait_time_seconds": wait_time}) await asyncio.sleep(wait_time) raise except Exception as e: - logger.error( - f"[get_json_completion] LLM call failed.\n" - f"{self._format_connection_error(e)}" + logger.explore( + "LLM call failed with unexpected error", + payload={"formatted_error": self._format_connection_error(e)}, + error=str(e), ) raise @@ -1066,7 +1089,7 @@ class LLMClient: raise RuntimeError(f"Invalid LLM response: {response}") content = response.choices[0].message.content - logger.debug(f"[get_json_completion] Raw content to parse: {content}") + logger.reflect("Raw LLM response content received for parsing", payload={"content_length": len(content) if content else 0}) # LLM returned null content — likely content filter or rate limit if content is None: @@ -1075,7 +1098,7 @@ class LLMClient: try: return json.loads(content) except json.JSONDecodeError: - logger.warning("[get_json_completion] Failed to parse JSON directly, attempting to extract from code blocks") + logger.explore("Failed to parse JSON directly, attempting to extract from code blocks", payload={}, error="JSONDecodeError on first parse attempt") if "```json" in content: json_str = content.split("```json")[1].split("```")[0].strip() return json.loads(json_str) @@ -1114,14 +1137,15 @@ class LLMClient: model_ids = [m.id for m in response.data] model_ids.sort() logger.reason( - f"[LLMClient.fetch_models] Fetched {len(model_ids)} models from {self.base_url}", - extra={"src": "LLMClient.fetch_models"}, + "Fetched available models from provider", + payload={"model_count": len(model_ids), "base_url": self.base_url}, ) return model_ids except Exception as e: - logger.warning( - f"[LLMClient.fetch_models] Failed to fetch models.\n" - f"{self._format_connection_error(e)}", + logger.explore( + "Failed to fetch models from provider", + payload={"base_url": self.base_url, "formatted_error": self._format_connection_error(e)}, + error=str(e), ) raise # endregion LLMClient.fetch_models @@ -1227,7 +1251,7 @@ class LLMClient: b64, _ = self._reduce_image_quality(path, max_width, quality) encoded.append(b64) except Exception as e: - logger.warning(f"[_optimize_images] Optimization failed for {path}: {e}") + logger.explore("Image optimization failed, falling back to raw read", payload={"path": path}, error=str(e)) with open(path, "rb") as f: raw = f.read() b64 = base64.b64encode(raw).decode("utf-8") @@ -1327,9 +1351,8 @@ class LLMClient: if is_chunking: logger.reason( - f"[analyze_dashboard_multimodal] Chunking {n_total} images into " - f"{(n_total + chunk_size - 1) // chunk_size} chunks of {chunk_size}", - extra={"src": "analyze_dashboard_multimodal", "total": n_total, "chunk_size": chunk_size}, + "Chunking images for multimodal analysis", + payload={"total_images": n_total, "chunk_count": (n_total + chunk_size - 1) // chunk_size, "chunk_size": chunk_size}, ) # Skip quality reduction: each chunk has ≤ max_images images, # well within the context window at normal quality. @@ -1339,9 +1362,9 @@ class LLMClient: screenshot_paths, len(prompt) + len(log_text) ) if estimate["exceeds_limit"] and image_quality > 30: - logger.info( - f"[analyze_dashboard_multimodal] Payload estimated at {estimate['pct_of_limit']}% " - f"of context window. Reducing image quality to 30." + logger.reason( + "Reducing image quality to fit context window", + payload={"pct_of_limit": estimate["pct_of_limit"], "new_quality": 30}, ) encoded_images = self._optimize_images(screenshot_paths, max_width, image_quality=30) @@ -1362,7 +1385,7 @@ class LLMClient: valid_results: list[dict] = [] for i, cr in enumerate(chunk_results): if isinstance(cr, Exception): - logger.error(f"[analyze_dashboard_multimodal] Chunk {i + 1}/{len(chunks)} failed: {cr!s}") + logger.explore("Multimodal analysis chunk failed", payload={"chunk_index": i + 1, "total_chunks": len(chunks)}, error=str(cr)) valid_results.append({ "status": "UNKNOWN", "summary": f"Chunk {i + 1} failed: {cr!s}", @@ -1373,7 +1396,7 @@ class LLMClient: result = self._merge_chunk_results(valid_results) except Exception as e: - logger.error(f"[analyze_dashboard_multimodal] Failed to get analysis: {e!s}") + logger.explore("Failed to get multimodal analysis from LLM", payload={}, error=str(e)) return { "status": "UNKNOWN", "summary": f"Failed to get response from LLM: {e!s}", diff --git a/backend/src/plugins/search.py b/backend/src/plugins/search.py index 8bec5674..e4a97c5a 100644 --- a/backend/src/plugins/search.py +++ b/backend/src/plugins/search.py @@ -132,13 +132,13 @@ class SearchPlugin(PluginBase): raise ValueError(f"Environment '{env_name}' not found in configuration.") client = SupersetClient(env_config) - client.authenticate() + await client.authenticate() log.info(f"Searching for pattern: '{search_query}' in environment: {env_name}") try: # Ported logic from search_script.py - _, datasets = client.get_datasets(query={"columns": ["id", "table_name", "sql", "database", "columns"]}) + _, datasets = await client.get_datasets(query={"columns": ["id", "table_name", "sql", "database", "columns"]}) if not datasets: search_log.warning("No datasets found.") diff --git a/backend/src/plugins/storage/plugin.py b/backend/src/plugins/storage/plugin.py index 3f777eea..27fdcc98 100644 --- a/backend/src/plugins/storage/plugin.py +++ b/backend/src/plugins/storage/plugin.py @@ -139,7 +139,7 @@ class StoragePlugin(PluginBase): storage_log = log.with_source("storage") if context else log log.with_source("filesystem") if context else log - storage_log.info(f"Executing with params: {params}") + logger.reason("Executing storage task", payload={"params": params}) # endregion execute # region get_storage_root [TYPE Function] @@ -183,7 +183,7 @@ class StoragePlugin(PluginBase): # Clean up any double slashes or leading/trailing slashes for relative path return os.path.normpath(resolved).strip("/") except KeyError as e: - logger.warning(f"[StoragePlugin][Coherence:Failed] Missing variable for path resolution: {e}") + logger.explore("Missing variable for path resolution", error=str(e)) # Fallback to literal pattern if formatting fails partially (or handle as needed) return pattern.replace("{", "").replace("}", "") # endregion resolve_path @@ -214,7 +214,7 @@ class StoragePlugin(PluginBase): try: resolved.relative_to(root) except ValueError: - logger.error(f"[StoragePlugin][Coherence:Failed] Path traversal detected: {resolved} is not under {root}") + logger.explore("Path traversal detected", error=f"Path {resolved} is not under {root}") raise ValueError("Access denied: Path is outside of storage root.") return resolved # endregion validate_path diff --git a/backend/src/scripts/create_admin.py b/backend/src/scripts/create_admin.py index 49b2aec2..a2dd2056 100644 --- a/backend/src/scripts/create_admin.py +++ b/backend/src/scripts/create_admin.py @@ -43,7 +43,7 @@ def create_admin(username, password, email=None): # 1. Ensure Admin role exists admin_role = db.query(Role).filter(Role.name == "Admin").first() if not admin_role: - logger.info("Creating Admin role...") + logger.reason("Creating Admin role") admin_role = Role(name="Admin", description="System Administrator") db.add(admin_role) db.commit() @@ -52,11 +52,11 @@ def create_admin(username, password, email=None): # 2. Check if user already exists existing_user = db.query(User).filter(User.username == username).first() if existing_user: - logger.warning(f"User {username} already exists.") + logger.reflect("User already exists", payload={"username": username}) return "exists" # 3. Create Admin user - logger.info(f"Creating admin user: {username}") + logger.reason("Creating admin user", payload={"username": username}) new_user = User( username=username, email=normalized_email, @@ -67,11 +67,11 @@ def create_admin(username, password, email=None): new_user.roles.append(admin_role) db.add(new_user) db.commit() - logger.info(f"Admin user {username} created successfully.") + logger.reason("Admin user created successfully", payload={"username": username}) return "created" except Exception as e: - logger.error(f"Failed to create admin user: {e}") + logger.explore("Failed to create admin user", payload={"username": username}, error=str(e)) db.rollback() raise finally: diff --git a/backend/src/scripts/init_auth_db.py b/backend/src/scripts/init_auth_db.py index 041a9f11..6bd1f658 100644 --- a/backend/src/scripts/init_auth_db.py +++ b/backend/src/scripts/init_auth_db.py @@ -32,17 +32,17 @@ from src.scripts.seed_permissions import seed_permissions def run_init(): seed_trace_id() with belief_scope("init_auth_db"): - logger.info("Initializing authentication database...") + logger.reason("Initializing authentication database") try: ensure_encryption_key() init_db() - logger.info("Authentication database initialized successfully.") + logger.reason("Authentication database initialized successfully") # Seed permissions seed_permissions() except Exception as e: - logger.error(f"Failed to initialize authentication database: {e}") + logger.explore("Failed to initialize authentication database", payload={}, error=str(e)) sys.exit(1) diff --git a/backend/src/scripts/seed_permissions.py b/backend/src/scripts/seed_permissions.py index 54a55dee..8a68499b 100644 --- a/backend/src/scripts/seed_permissions.py +++ b/backend/src/scripts/seed_permissions.py @@ -78,7 +78,7 @@ def seed_permissions(): with belief_scope("seed_permissions"): db = AuthSessionLocal() try: - logger.info("Seeding permissions...") + logger.reason("Seeding permissions") count = 0 for perm_data in INITIAL_PERMISSIONS: exists = ( @@ -98,7 +98,7 @@ def seed_permissions(): count += 1 db.commit() - logger.info(f"Seeding completed. Added {count} new permissions.") + logger.reason("Seeding completed", payload={"added_count": count}) # Assign permissions to User role repo = AuthRepository(db) @@ -134,10 +134,10 @@ def seed_permissions(): user_role.permissions.append(perm) db.commit() - logger.info("User role permissions updated.") + logger.reason("User role permissions updated") except Exception as e: - logger.error(f"Failed to seed permissions: {e}") + logger.explore("Failed to seed permissions", payload={}, error=str(e)) db.rollback() finally: db.close() diff --git a/backend/src/scripts/test_dataset_dashboard_relations.py b/backend/src/scripts/test_dataset_dashboard_relations.py index eb5bb6b1..a449e4d4 100644 --- a/backend/src/scripts/test_dataset_dashboard_relations.py +++ b/backend/src/scripts/test_dataset_dashboard_relations.py @@ -33,24 +33,24 @@ def test_dashboard_dataset_relations(): environments = config_manager.get_environments() if not environments: - logger.error("No environments configured!") + logger.explore("No environments configured", payload={}, error="ConfigManager returned empty environment list") return # Use first available environment env = environments[0] - logger.info(f"Using environment: {env.name} ({env.url})") + logger.reason("Using environment for test", payload={"env_name": env.name, "env_url": env.url}) client = SupersetClient(env) try: # Authenticate - logger.info("Authenticating to Superset...") + logger.reason("Authenticating to Superset") client.authenticate() - logger.info("Authentication successful!") + logger.reason("Authentication successful", payload={"env_name": env.name}) # Test dashboard ID 13 dashboard_id = 13 - logger.info(f"\n=== Fetching Dashboard {dashboard_id} ===") + logger.reason("Fetching dashboard", payload={"dashboard_id": dashboard_id}) dashboard = client.network.request(method="GET", endpoint=f"/dashboard/{dashboard_id}") print("\nDashboard structure:") @@ -60,7 +60,7 @@ def test_dashboard_dataset_relations(): # Check for slices/charts if 'slices' in dashboard: - logger.info(f"\n Found {len(dashboard['slices'])} slices/charts in dashboard") + logger.reason("Found slices in dashboard", payload={"dashboard_id": dashboard_id, "slice_count": len(dashboard['slices'])}) for i, slice_data in enumerate(dashboard['slices'][:5]): # Show first 5 print(f" Slice {i+1}:") print(f" ID: {slice_data.get('slice_id')}") @@ -73,12 +73,12 @@ def test_dashboard_dataset_relations(): if 'datasource_type' in slice_data: print(f" Datasource Type: {slice_data['datasource_type']}") else: - logger.warning(" No 'slices' field found in dashboard response") - logger.info(f" Available fields: {list(dashboard.keys())}") + logger.reflect("No slices field in dashboard response", payload={"dashboard_id": dashboard_id}) + logger.reason("Dashboard available fields", payload={"fields": list(dashboard.keys())}) # Test dataset ID 26 dataset_id = 26 - logger.info(f"\n=== Fetching Dataset {dataset_id} ===") + logger.reason("Fetching dataset", payload={"dataset_id": dataset_id}) dataset = client.get_dataset(dataset_id) print("\nDataset structure:") @@ -88,72 +88,72 @@ def test_dashboard_dataset_relations(): print(f" Database: {dataset.get('database', {}).get('database_name', 'Unknown')}") # Check for dashboards that use this dataset - logger.info(f"\n=== Finding Dashboards using Dataset {dataset_id} ===") + logger.reason("Finding dashboards for dataset", payload={"dataset_id": dataset_id}) # Method: Use Superset's related_objects API try: - logger.info(f" Using /api/v1/dataset/{dataset_id}/related_objects endpoint...") + logger.reason("Querying related objects endpoint", payload={"dataset_id": dataset_id}) related_objects = client.network.request( method="GET", endpoint=f"/dataset/{dataset_id}/related_objects" ) - logger.info(f" Related objects response type: {type(related_objects)}") - logger.info(f" Related objects keys: {list(related_objects.keys()) if isinstance(related_objects, dict) else 'N/A'}") + logger.reason("Related objects response type", payload={"response_type": str(type(related_objects))}) + logger.reason("Related objects keys", payload={"keys": list(related_objects.keys()) if isinstance(related_objects, dict) else "N/A"}) # Check for dashboards in related objects if 'dashboards' in related_objects: dashboards = related_objects['dashboards'] - logger.info(f" Found {len(dashboards)} dashboards using this dataset:") + logger.reason("Found dashboards for dataset", payload={"dataset_id": dataset_id, "count": len(dashboards)}) for dash in dashboards: if isinstance(dash, dict): - logger.info(f" - Dashboard ID {dash.get('id')}: {dash.get('dashboard_title', dash.get('title', 'Unknown'))}") + logger.reason("Dashboard entry", payload={"dashboard_id": dash.get("id"), "title": dash.get("dashboard_title", dash.get("title", "Unknown"))}) else: - logger.info(f" - Dashboard: {dash}") + logger.reason("Dashboard entry", payload={"dashboard": str(dash)}) elif 'result' in related_objects: # Some Superset versions use 'result' wrapper result = related_objects['result'] if 'dashboards' in result: dashboards = result['dashboards'] - logger.info(f" Found {len(dashboards)} dashboards using this dataset:") + logger.reason("Found dashboards for dataset (result wrapper)", payload={"dataset_id": dataset_id, "count": len(dashboards)}) for dash in dashboards: - logger.info(f" - Dashboard ID {dash.get('id')}: {dash.get('dashboard_title', dash.get('title', 'Unknown'))}") + logger.reason("Dashboard entry", payload={"dashboard_id": dash.get("id"), "title": dash.get("dashboard_title", dash.get("title", "Unknown"))}) else: - logger.warning(f" No 'dashboards' key in result. Keys: {list(result.keys())}") + logger.reflect("No dashboards key in result", payload={"keys": list(result.keys())}) else: - logger.warning(f" No 'dashboards' key in response. Available keys: {list(related_objects.keys())}") - logger.info(" Full related_objects response:") + logger.reflect("No dashboards key in response", payload={"available_keys": list(related_objects.keys())}) + logger.reason("Full related_objects response") print(json.dumps(related_objects, indent=2, default=str)[:1000]) except Exception as e: - logger.error(f" Error fetching related objects: {e}") + logger.explore("Error fetching related objects", payload={"dataset_id": dataset_id}, error=str(e)) import traceback traceback.print_exc() # Method 2: Try to use the position_json from dashboard - logger.info("\n=== Analyzing Dashboard Position JSON ===") + logger.reason("Analyzing dashboard position JSON") if 'position_json' in dashboard: position_data = json.loads(dashboard['position_json']) - logger.info(f" Position data type: {type(position_data)}") + logger.reason("Position data type", payload={"type": str(type(position_data))}) # Look for datasource references datasource_ids = set() if isinstance(position_data, dict): for key, value in position_data.items(): if 'datasource' in key.lower() or key == 'DASHBOARD_VERSION_KEY': - logger.debug(f" Key: {key}, Value type: {type(value)}") + logger.reason("Position entry", payload={"key": key, "value_type": str(type(value))}) elif isinstance(position_data, list): - logger.info(f" Position data has {len(position_data)} items") + logger.reason("Position data item count", payload={"count": len(position_data)}) for item in position_data[:3]: # Show first 3 - logger.debug(f" Item: {type(item)}, keys: {list(item.keys()) if isinstance(item, dict) else 'N/A'}") + logger.reason("Position item", payload={"item_type": str(type(item)), "keys": list(item.keys()) if isinstance(item, dict) else "N/A"}) if isinstance(item, dict): if 'datasource_id' in item: datasource_ids.add(item['datasource_id']) if datasource_ids: - logger.info(f" Found datasource IDs: {datasource_ids}") + logger.reason("Found datasource IDs in position data", payload={"datasource_ids": sorted(datasource_ids)}) # Save full response for analysis output_file = Path(__file__).parent / "dataset_dashboard_analysis.json" @@ -162,10 +162,10 @@ def test_dashboard_dataset_relations(): 'dashboard': dashboard, 'dataset': dataset }, f, indent=2, default=str) - logger.info(f"\nFull response saved to: {output_file}") + logger.reason("Full response saved", payload={"output_file": str(output_file)}) except Exception as e: - logger.error(f"Error: {e}", exc_info=True) + logger.explore("Error in test dashboard dataset relations", payload={}, error=str(e)) raise diff --git a/backend/src/services/dataset_review/orchestrator.py b/backend/src/services/dataset_review/orchestrator.py index ea7606d5..ec3b01d0 100644 --- a/backend/src/services/dataset_review/orchestrator.py +++ b/backend/src/services/dataset_review/orchestrator.py @@ -462,7 +462,7 @@ class DatasetReviewOrchestrator: ) -> tuple[list[ImportedFilter], list[TemplateVariable], list[ExecutionMapping], list[ValidationFinding]]: session_record = cast(Any, session) extractor = SupersetContextExtractor(environment) - imported_filters_payload = extractor.recover_imported_filters(parsed_context) + imported_filters_payload = await extractor.recover_imported_filters(parsed_context) if imported_filters_payload is None: imported_filters_payload = [] imported_filters = [ diff --git a/backend/src/services/git/_base.py b/backend/src/services/git/_base.py index 3f76bfce..79e73c02 100644 --- a/backend/src/services/git/_base.py +++ b/backend/src/services/git/_base.py @@ -121,9 +121,7 @@ class GitServiceBase: try: base.mkdir(parents=True, exist_ok=True) except (PermissionError, OSError) as e: - logger.warning( - f"[_ensure_base_path_exists][Coherence:Failed] Cannot create Git repositories base path: {self.base_path}. Error: {e}" - ) + logger.explore("Cannot create Git repositories base path", extra={"src": "_ensure_base_path_exists"}, payload={"base_path": self.base_path}, error=str(e)) raise ValueError(f"Cannot create Git repositories base path: {self.base_path}. {e}") # endregion _ensure_base_path_exists @@ -158,7 +156,7 @@ class GitServiceBase: return str(repo_root.resolve()) return str((root / repo_root).resolve()) except Exception as e: - logger.warning(f"[_resolve_base_path][Coherence:Failed] Falling back to default path: {e}") + logger.explore("Falling back to default path for base_path resolution", extra={"src": "_resolve_base_path"}, error=str(e)) return fallback_path # endregion _resolve_base_path @@ -192,7 +190,7 @@ class GitServiceBase: finally: session.close() except Exception as e: - logger.warning(f"[_update_repo_local_path][Coherence:Failed] {e}") + logger.explore("Failed to update repo local_path in DB", extra={"src": "_update_repo_local_path"}, error=str(e)) # endregion _update_repo_local_path # region _migrate_repo_directory [TYPE Function] @@ -215,9 +213,7 @@ class GitServiceBase: except OSError: await run_blocking('file', shutil.move, source_abs, target_abs) self._update_repo_local_path(dashboard_id, target_abs) - logger.info( - f"[_migrate_repo_directory][Coherence:OK] Repository migrated for dashboard {dashboard_id}: {source_abs} -> {target_abs}" - ) + logger.reflect("Repository migrated", extra={"src": "_migrate_repo_directory"}, payload={"dashboard_id": dashboard_id, "source": source_abs, "target": target_abs}) return target_abs # endregion _migrate_repo_directory @@ -258,7 +254,7 @@ class GitServiceBase: return await self._migrate_repo_directory(dashboard_id, db_path, target_path) return db_path except Exception as e: - logger.warning(f"[_get_repo_path][Coherence:Failed] Could not resolve local_path from DB: {e}") + logger.explore("Could not resolve local_path from DB", extra={"src": "_get_repo_path"}, error=str(e)) legacy_id_path = os.path.join(self.legacy_base_path, str(dashboard_id)) if os.path.exists(legacy_id_path) and not os.path.exists(target_path): return await self._migrate_repo_directory(dashboard_id, legacy_id_path, target_path) @@ -341,7 +337,7 @@ class GitServiceBase: raise except Exception as e: session.rollback() - logger.error(f"[delete_repo][Coherence:Failed] Failed to delete repository for dashboard {dashboard_id}: {e}") + logger.explore("Failed to delete repository", extra={"src": "delete_repo"}, payload={"dashboard_id": dashboard_id}, error=str(e)) raise HTTPException(status_code=500, detail=f"Failed to delete repository: {e!s}") finally: session.close() @@ -357,12 +353,12 @@ class GitServiceBase: with self._locked(dashboard_id), belief_scope("GitService.get_repo"): repo_path = await self._get_repo_path(dashboard_id) if not os.path.exists(repo_path): - logger.error(f"[EXT:method:get_repo][Coherence:Failed] Repository for dashboard {dashboard_id} does not exist") + logger.explore("Repository does not exist", extra={"src": "get_repo"}, payload={"dashboard_id": dashboard_id}) raise HTTPException(status_code=404, detail=f"Repository for dashboard {dashboard_id} not found") try: return await run_blocking('git', Repo, repo_path) except Exception as e: - logger.error(f"[EXT:method:get_repo][Coherence:Failed] Failed to open repository at {repo_path}: {e}") + logger.explore("Failed to open repository", extra={"src": "get_repo"}, payload={"repo_path": repo_path}, error=str(e)) raise HTTPException(status_code=500, detail="Failed to open local Git repository") # endregion get_repo @@ -384,7 +380,7 @@ class GitServiceBase: config_writer.set_value("user", "email", normalized_email) logger.reason(f"Applied repository-local git identity for dashboard {dashboard_id}", extra={"src": "configure_identity"}) except Exception as e: - logger.error(f"[configure_identity][Coherence:Failed] Failed to configure git identity: {e}") + logger.explore("Failed to configure git identity", extra={"src": "configure_identity"}, error=str(e)) raise HTTPException(status_code=500, detail=f"Failed to configure git identity: {e!s}") # endregion configure_identity diff --git a/backend/src/services/git/_branch.py b/backend/src/services/git/_branch.py index c3503e1d..9f06c3ca 100644 --- a/backend/src/services/git/_branch.py +++ b/backend/src/services/git/_branch.py @@ -78,7 +78,7 @@ class GitServiceBranchMixin: extra={"src": "_ensure_gitflow_branches"}, ) except Exception as e: - logger.error(f"[_ensure_gitflow_branches][Coherence:Failed] Failed to push branch {branch_name} to origin: {e}") + logger.explore("Failed to push branch to origin", extra={"src": "_ensure_gitflow_branches"}, payload={"branch": branch_name, "dashboard_id": dashboard_id}, error=str(e)) raise HTTPException( status_code=500, detail=f"Failed to create default branch '{branch_name}' on remote: {e!s}", @@ -168,7 +168,7 @@ class GitServiceBranchMixin: new_branch = repo.create_head(name, from_branch) return new_branch except Exception as e: - logger.error(f"[create_branch][Coherence:Failed] {e}") + logger.explore("Failed to create branch", extra={"src": "create_branch"}, error=str(e)) raise # endregion create_branch @@ -225,7 +225,7 @@ class GitServiceBranchMixin: ], }, ) - logger.error(f"[checkout_branch][Coherence:Failed] {e}") + logger.explore("Failed to checkout branch", extra={"src": "checkout_branch"}, error=str(e)) raise HTTPException( status_code=500, detail=f"Git checkout failed: {details}", @@ -252,7 +252,7 @@ class GitServiceBranchMixin: logger.reason("Staging all changes", extra={"src": "commit_changes"}) repo.git.add(A=True) repo.index.commit(message) - logger.info(f"[commit_changes][Coherence:OK] Committed changes with message: {message}") + logger.reflect("Committed changes", extra={"src": "commit_changes"}, payload={"message": message}) # endregion commit_changes # #endregion GitServiceBranchMixin # #endregion GitServiceBranchMixin diff --git a/backend/src/services/git/_gitea.py b/backend/src/services/git/_gitea.py index 93e54d65..6c75370e 100644 --- a/backend/src/services/git/_gitea.py +++ b/backend/src/services/git/_gitea.py @@ -29,10 +29,10 @@ class GitServiceGiteaMixin: logger.reason("Local/Offline mode detected for URL", extra={"src": "test_connection"}) return True if not url.startswith(('http://', 'https://')): - logger.error(f"[test_connection][Coherence:Failed] Invalid URL protocol: {url}") + logger.explore("Invalid URL protocol", extra={"src": "test_connection"}, payload={"url": url}) return False if not pat or not pat.strip(): - logger.error("[test_connection][Coherence:Failed] Git PAT is missing or empty") + logger.explore("Git PAT is missing or empty", extra={"src": "test_connection"}) return False pat = pat.strip() try: @@ -51,10 +51,10 @@ class GitServiceGiteaMixin: else: return False if resp.status_code != 200: - logger.error(f"[test_connection][Coherence:Failed] Git connection test failed for {provider} at {api_url}. Status: {resp.status_code}") + logger.explore("Git connection test failed", extra={"src": "test_connection"}, payload={"provider": str(provider), "api_url": api_url, "status": resp.status_code}) return resp.status_code == 200 except Exception as e: - logger.error(f"[test_connection][Coherence:Failed] Error testing git connection: {e}") + logger.explore("Error testing git connection", extra={"src": "test_connection"}, error=str(e)) return False # endregion test_connection @@ -89,7 +89,7 @@ class GitServiceGiteaMixin: try: response = await self._http_client.request(method=method, url=url, headers=headers, json=payload) except Exception as e: - logger.error(f"[gitea_request][Coherence:Failed] Network error: {e}") + logger.explore("Gitea API network error", extra={"src": "_gitea_request"}, error=str(e)) raise HTTPException(status_code=503, detail=f"Gitea API is unavailable: {e!s}") if response.status_code >= 400: detail = response.text @@ -98,7 +98,7 @@ class GitServiceGiteaMixin: detail = parsed.get("message") or parsed.get("error") or detail except Exception: logger.debug("Could not parse error response JSON from Gitea API") - logger.error(f"[gitea_request][Coherence:Failed] method={method} endpoint={endpoint} status={response.status_code} detail={detail}") + logger.explore("Gitea API returned error status", extra={"src": "_gitea_request"}, payload={"method": method, "endpoint": endpoint, "status": response.status_code}, error=str(detail)) raise HTTPException(status_code=response.status_code, detail=f"Gitea API error: {detail}") if response.status_code == 204: return None diff --git a/backend/src/services/git/_status.py b/backend/src/services/git/_status.py index e777a1b0..15c806f7 100644 --- a/backend/src/services/git/_status.py +++ b/backend/src/services/git/_status.py @@ -28,7 +28,7 @@ class GitServiceStatusMixin: try: output = repo.git.status("--porcelain") except Exception: - logger.warning("[_parse_status_porcelain][Coherence:Failed] git status --porcelain failed") + logger.explore("git status --porcelain failed", extra={"src": "_parse_status_porcelain"}) return staged, modified, untracked for line in output.split("\n"): if not line: diff --git a/backend/src/services/git/_sync.py b/backend/src/services/git/_sync.py index 9da10cf6..8012c801 100644 --- a/backend/src/services/git/_sync.py +++ b/backend/src/services/git/_sync.py @@ -28,12 +28,12 @@ class GitServiceSyncMixin: with belief_scope("GitService.push_changes"): repo = await self.get_repo(dashboard_id) if not repo.heads: - logger.warning(f"[push_changes][Coherence:Failed] No local branches to push for dashboard {dashboard_id}") + logger.explore("No local branches to push", extra={"src": "push_changes"}, payload={"dashboard_id": dashboard_id}) return try: origin = repo.remote(name='origin') except ValueError: - logger.error(f"[push_changes][Coherence:Failed] Remote 'origin' not found for dashboard {dashboard_id}") + logger.explore("Remote 'origin' not found", extra={"src": "push_changes"}, payload={"dashboard_id": dashboard_id}) raise HTTPException(status_code=400, detail="Remote 'origin' not configured") try: origin_urls = list(origin.urls) @@ -96,7 +96,7 @@ class GitServiceSyncMixin: push_info = origin.push(refspec=f'{current_branch.name}:{current_branch.name}') for info in push_info: if info.flags & info.ERROR: - logger.error(f"[push_changes][Coherence:Failed] Error pushing ref {info.remote_ref_string}: {info.summary}") + logger.explore("Error pushing ref", extra={"src": "push_changes"}, payload={"ref": info.remote_ref_string}, error=str(info.summary)) raise Exception(f"Git push error for {info.remote_ref_string}: {info.summary}") except GitCommandError as e: details = str(e) @@ -106,10 +106,10 @@ class GitServiceSyncMixin: status_code=409, detail="Push rejected: remote branch contains newer commits. Run Pull first, resolve conflicts if any, then push again.", ) - logger.error(f"[push_changes][Coherence:Failed] Failed to push changes: {e}") + logger.explore("Failed to push changes", extra={"src": "push_changes"}, error=str(e)) raise HTTPException(status_code=500, detail=f"Git push failed: {details}") except Exception as e: - logger.error(f"[push_changes][Coherence:Failed] Failed to push changes: {e}") + logger.explore("Failed to push changes", extra={"src": "push_changes"}, error=str(e)) raise HTTPException(status_code=500, detail=f"Git push failed: {e!s}") # endregion push_changes @@ -155,7 +155,7 @@ class GitServiceSyncMixin: logger.reason(f"Pulling changes from origin/{current_branch}", extra={"src": "pull_changes"}) repo.git.pull("--no-rebase", "origin", current_branch) except ValueError: - logger.error(f"[pull_changes][Coherence:Failed] Remote 'origin' not found for dashboard {dashboard_id}") + logger.explore("Remote 'origin' not found", extra={"src": "pull_changes"}, payload={"dashboard_id": dashboard_id}) raise HTTPException(status_code=400, detail="Remote 'origin' not configured") except GitCommandError as e: details = str(e) @@ -165,12 +165,12 @@ class GitServiceSyncMixin: status_code=409, detail="Pull requires conflict resolution. Resolve conflicts in repository and repeat operation.", ) - logger.error(f"[pull_changes][Coherence:Failed] Failed to pull changes: {e}") + logger.explore("Failed to pull changes", extra={"src": "pull_changes"}, error=str(e)) raise HTTPException(status_code=500, detail=f"Git pull failed: {details}") except HTTPException: raise except Exception as e: - logger.error(f"[pull_changes][Coherence:Failed] Failed to pull changes: {e}") + logger.explore("Failed to pull changes", extra={"src": "pull_changes"}, error=str(e)) raise HTTPException(status_code=500, detail=f"Git pull failed: {e!s}") # endregion pull_changes # #endregion GitServiceSyncMixin diff --git a/backend/src/services/git/_url.py b/backend/src/services/git/_url.py index 05024d21..32b454b5 100644 --- a/backend/src/services/git/_url.py +++ b/backend/src/services/git/_url.py @@ -125,10 +125,7 @@ class GitServiceUrlMixin: try: origin.set_url(aligned_url) except Exception as e: - logger.warning( - "[_align_origin_host_with_config][Coherence:Failed] Failed to set origin URL for dashboard %s: %s", - dashboard_id, e, - ) + logger.explore("Failed to set origin URL for dashboard", extra={"src": "_align_origin_host_with_config"}, payload={"dashboard_id": dashboard_id}, error=str(e)) return None try: session = SessionLocal() diff --git a/backend/src/services/mapping_service.py b/backend/src/services/mapping_service.py index bcf66df3..ec612b62 100644 --- a/backend/src/services/mapping_service.py +++ b/backend/src/services/mapping_service.py @@ -80,8 +80,8 @@ class MappingService: source_client = self._get_client(source_env_id) target_client = self._get_client(target_env_id) - source_dbs = source_client.get_databases_summary() - target_dbs = target_client.get_databases_summary() + source_dbs = await source_client.get_databases_summary() + target_dbs = await target_client.get_databases_summary() return suggest_mappings(source_dbs, target_dbs) diff --git a/backend/src/services/validation_service.py b/backend/src/services/validation_service.py index 7f63b7ba..31f6b2f4 100644 --- a/backend/src/services/validation_service.py +++ b/backend/src/services/validation_service.py @@ -120,7 +120,7 @@ class ValidationTaskService: # dashboard URL. Called during source creation when type == "dashboard_url". # @REJECTED Silently accepting unparseable URLs rejected — would create broken sources that # fail at runtime during validation without clear error attribution. - def _parse_superset_link(self, url: str, environment_id: str) -> dict: + async def _parse_superset_link(self, url: str, environment_id: str) -> dict: if not self.config_manager: raise ValueError("Config manager not available — cannot validate Superset URL") env = self.config_manager.get_environment(environment_id) @@ -129,7 +129,7 @@ class ValidationTaskService: from ..core.utils.superset_context_extractor import SupersetContextExtractor extractor = SupersetContextExtractor(environment=env) - parsed = extractor.parse_superset_link(url) + parsed = await extractor.parse_superset_link(url) return { "source_url": parsed.source_url, "dataset_ref": parsed.dataset_ref, @@ -147,7 +147,7 @@ class ValidationTaskService: # @BRIEF Fetch a dashboard title from the Superset API by its numeric ID. # @SIDE_EFFECT Makes an HTTP GET to Superset REST API via the config-manager. # @RETURNS The dashboard title string, or None if it cannot be resolved. - def _resolve_dashboard_title(self, environment_id: str, dashboard_id: str) -> str | None: + async def _resolve_dashboard_title(self, environment_id: str, dashboard_id: str) -> str | None: try: from ..core.superset_client import SupersetClient @@ -157,7 +157,7 @@ class ValidationTaskService: if not env: return None client = SupersetClient(env) - resp = client.get_dashboard(dashboard_id) + resp = await client.get_dashboard(dashboard_id) # Superset API returns { "result": { "dashboard_title": "..." } } result = resp.get("result", resp) title = result.get("dashboard_title") or result.get("title") @@ -173,7 +173,7 @@ class ValidationTaskService: # Falls back to dashboard_ids for backward compatibility. # @REJECTED Mixing source types in a single method that also persists rejected — separation # from DB commit gives callers control over transaction boundaries. - def _resolve_sources( + async def _resolve_sources( self, sources_input: list[SourceInput] | None, dashboard_ids: list[str] | None, @@ -191,7 +191,7 @@ class ValidationTaskService: title = None if s.type == "dashboard_url": - parsed_context = self._parse_superset_link(s.value, environment_id) + parsed_context = await self._parse_superset_link(s.value, environment_id) if parsed_context.get("dashboard_id"): resolved_dashboard_id = str(parsed_context["dashboard_id"]) if parsed_context.get("partial_recovery"): @@ -201,7 +201,7 @@ class ValidationTaskService: # Resolve dashboard title from Superset API if resolved_dashboard_id and not title: - title = self._resolve_dashboard_title(environment_id, resolved_dashboard_id) + title = await self._resolve_dashboard_title(environment_id, resolved_dashboard_id) sources.append(ValidationSource( policy_id=policy_id, @@ -215,7 +215,7 @@ class ValidationTaskService: # Fallback: dashboard_ids (v1 backward compat) elif dashboard_ids: for did in dashboard_ids: - title = self._resolve_dashboard_title(environment_id, str(did)) + title = await self._resolve_dashboard_title(environment_id, str(did)) sources.append(ValidationSource( policy_id=policy_id, type="dashboard_id", @@ -330,7 +330,7 @@ class ValidationTaskService: # #region _record_to_dict [C:2] [TYPE Function] # @BRIEF Convert ValidationRecord ORM object to a serializable dict with all v2 fields. - def _record_to_dict(self, record: ValidationRecord) -> dict: + async def _record_to_dict(self, record: ValidationRecord) -> dict: # Try to resolve dashboard title from sources dashboard_title = record.dashboard_id try: @@ -343,7 +343,7 @@ class ValidationTaskService: dashboard_title = source.title elif source and record.environment_id: # Fallback: resolve from Superset API and cache back to source - resolved = self._resolve_dashboard_title(record.environment_id, record.dashboard_id) + resolved = await self._resolve_dashboard_title(record.environment_id, record.dashboard_id) if resolved: dashboard_title = resolved source.title = resolved @@ -417,7 +417,7 @@ class ValidationTaskService: # or falls back to dashboard_ids for backward compatibility. # @REJECTED Lazy validation on first run rejected — would allow creation of invalid task # configurations with incorrect providers that fail only at runtime. - def create_task(self, payload: ValidationTaskCreate) -> ValidationTaskResponse: + async def create_task(self, payload: ValidationTaskCreate) -> ValidationTaskResponse: self._validate_provider(payload.provider_id, require_multimodal=payload.screenshot_enabled) self._validate_environment(payload.environment_id) @@ -449,7 +449,7 @@ class ValidationTaskService: self.db.flush() # acquire policy.id for source foreign keys # Resolve sources - sources = self._resolve_sources( + sources = await self._resolve_sources( sources_input=payload.sources, dashboard_ids=payload.dashboard_ids, policy_id=policy.id, @@ -460,9 +460,9 @@ class ValidationTaskService: self.db.commit() self.db.refresh(policy) - logger.info( - "[ValidationTaskService] Created task '%s' (id=%s) with %d sources", - policy.name, policy.id, len(sources), + logger.reflect( + "Created validation task", + payload={"name": policy.name, "id": policy.id, "sources": len(sources)}, ) return self._policy_to_response(policy) @@ -494,7 +494,7 @@ class ValidationTaskService: # #region _apply_sources_update [C:2] [TYPE Function] # @BRIEF Replace all ValidationSource rows for a policy when sources are provided in update. - def _apply_sources_update(self, update_data: dict, policy: ValidationPolicy) -> None: + async def _apply_sources_update(self, update_data: dict, policy: ValidationPolicy) -> None: if "sources" not in update_data: return sources_data = update_data.pop("sources") @@ -503,7 +503,7 @@ class ValidationTaskService: self.db.query(ValidationSource).filter( ValidationSource.policy_id == policy.id ).delete(synchronize_session=False) - new_sources = self._resolve_sources( + new_sources = await self._resolve_sources( sources_input=sources_data, dashboard_ids=None, policy_id=policy.id, @@ -521,7 +521,7 @@ class ValidationTaskService: # replacement to extracted methods to stay within CC ≤ 10. # @REJECTED Full re-validation on every update rejected — would prevent updating non-critical # fields (e.g., schedule, name) when a provider is temporarily unavailable. - def update_task(self, task_id: str, payload: ValidationTaskUpdate) -> ValidationTaskResponse: + async def update_task(self, task_id: str, payload: ValidationTaskUpdate) -> ValidationTaskResponse: policy = self.db.query(ValidationPolicy).filter(ValidationPolicy.id == task_id).first() if not policy: raise ValueError(f"Validation task '{task_id}' not found") @@ -536,7 +536,7 @@ class ValidationTaskService: self._apply_time_field(update_data, policy, "window_start") self._apply_time_field(update_data, policy, "window_end") - self._apply_sources_update(update_data, policy) + await self._apply_sources_update(update_data, policy) for key, value in update_data.items(): if hasattr(policy, key): @@ -544,7 +544,7 @@ class ValidationTaskService: self.db.commit() self.db.refresh(policy) - logger.info("[ValidationTaskService] Updated task '%s' (id=%s)", policy.name, policy.id) + logger.reflect("Updated validation task", payload={"name": policy.name, "id": policy.id}) return self._policy_to_response(policy) # #endregion update_task @@ -581,9 +581,9 @@ class ValidationTaskService: # Sources are cascade-deleted via relationship; delete the policy self.db.delete(policy) self.db.commit() - logger.info( - "[ValidationTaskService] Deleted task '%s' (id=%s) delete_runs=%s", - policy.name, policy.id, delete_runs, + logger.reflect( + "Deleted validation task", + payload={"name": policy.name, "id": policy.id, "delete_runs": delete_runs}, ) # #endregion delete_task @@ -689,9 +689,9 @@ class ValidationTaskService: run.task_id = task.id self.db.commit() - logger.info( - "[ValidationTaskService] Triggered run for task '%s' run=%s spawned=%s dashboards=%d", - policy.name, run.id, task.id, len(resolved_dashboard_ids), + logger.reflect( + "Triggered validation run", + payload={"task_name": policy.name, "run_id": run.id, "task_id": task.id, "dashboards": len(resolved_dashboard_ids)}, ) return {"task_id": task.id, "run_id": run.id} @@ -720,7 +720,7 @@ class ValidationTaskService: # #region list_all_runs [C:2] [TYPE Function] # @ingroup Services # @BRIEF List runs across ALL tasks with optional filters (replaces v1 cross-task endpoint). - def list_all_runs( + async def list_all_runs( self, status: str | None = None, environment_id: str | None = None, @@ -744,7 +744,10 @@ class ValidationTaskService: .limit(page_size) .all() ) - return total, [self._record_to_dict(r) for r in records] + items = [] + for r in records: + items.append(await self._record_to_dict(r)) + return total, items # #endregion list_all_runs @@ -756,7 +759,7 @@ class ValidationTaskService: # validation execution across all its dashboards. # @REJECTED Embedding record data inside the run response without pagination rejected — for # very large runs (100+ dashboards), but acceptable for typical task sizes (<20). - def get_run_detail(self, run_id: str) -> dict: + async def get_run_detail(self, run_id: str) -> dict: run = self.db.query(ValidationRun).filter(ValidationRun.id == run_id).first() if not run: raise ValueError(f"Validation run '{run_id}' not found") @@ -767,9 +770,12 @@ class ValidationTaskService: .order_by(ValidationRecord.timestamp.desc()) .all() ) + record_dicts = [] + for r in records: + record_dicts.append(await self._record_to_dict(r)) return { "run": self._run_to_dict(run), - "records": [self._record_to_dict(r) for r in records], + "records": record_dicts, } # #endregion get_run_detail diff --git a/backend/tests/api/test_assistant_tools.py b/backend/tests/api/test_assistant_tools.py index 878376e9..3e94d5f2 100644 --- a/backend/tests/api/test_assistant_tools.py +++ b/backend/tests/api/test_assistant_tools.py @@ -643,7 +643,7 @@ class TestToolLlmValidation: svc = MagicMock() mock_validation_svc.return_value = svc - svc.create_task.return_value = MagicMock(id="vt-1", name="Validation Task") + svc.create_task = AsyncMock(return_value=MagicMock(id="vt-1", name="Validation Task")) svc.trigger_run = AsyncMock(return_value={"task_id": "task-42", "run_id": "run-1"}) intent_data = { @@ -694,7 +694,7 @@ class TestToolLlmValidation: svc = MagicMock() mock_validation_svc.return_value = svc - svc.create_task.side_effect = ValueError("Invalid config") + svc.create_task = AsyncMock(side_effect=ValueError("Invalid config")) with pytest.raises(HTTPException) as exc: await handle_run_llm_validation( @@ -723,7 +723,7 @@ class TestToolLlmValidation: svc = MagicMock() mock_validation_svc.return_value = svc - svc.create_task.return_value = MagicMock(id="vt-1", name="Validation Task") + svc.create_task = AsyncMock(return_value=MagicMock(id="vt-1", name="Validation Task")) svc.trigger_run = AsyncMock(side_effect=ValueError("Trigger failed")) with pytest.raises(HTTPException) as exc: diff --git a/backend/tests/api/test_migration.py b/backend/tests/api/test_migration.py index e36ab0e0..290672e4 100644 --- a/backend/tests/api/test_migration.py +++ b/backend/tests/api/test_migration.py @@ -351,10 +351,13 @@ class TestTriggerSyncNow: mock_db.query.return_value.filter_by.return_value.first.side_effect = [None, None] mock_sync = MagicMock() + mock_sync.sync_environment = AsyncMock() from src.core.database import get_db from src.dependencies import get_config_manager - with patch("src.api.routes.migration.IdMappingService", return_value=mock_sync): + with patch("src.api.routes.migration.IdMappingService", return_value=mock_sync), \ + patch("src.api.routes.migration.AsyncSupersetClient"), \ + patch("src.api.routes.migration.get_async_job_runner"): client = _make_client({ get_config_manager: lambda: mock_config, get_db: lambda: mock_db, @@ -388,11 +391,14 @@ class TestTriggerSyncNow: mock_db.query.return_value.filter_by.return_value.first.return_value = None mock_sync = MagicMock() - mock_sync.sync_environment.side_effect = [None, RuntimeError("sync failed")] + mock_sync.sync_environment = AsyncMock() from src.core.database import get_db from src.dependencies import get_config_manager - with patch("src.api.routes.migration.IdMappingService", return_value=mock_sync): + # Make AsyncSupersetClient raise on 2nd call to simulate sync failure + with patch("src.api.routes.migration.IdMappingService", return_value=mock_sync), \ + patch("src.api.routes.migration.AsyncSupersetClient", side_effect=[MagicMock(), RuntimeError("Connection failed")]), \ + patch("src.api.routes.migration.get_async_job_runner"): client = _make_client({ get_config_manager: lambda: mock_config, get_db: lambda: mock_db, diff --git a/backend/tests/api/test_validation_tasks.py b/backend/tests/api/test_validation_tasks.py index 3b61511d..f46b06a9 100644 --- a/backend/tests/api/test_validation_tasks.py +++ b/backend/tests/api/test_validation_tasks.py @@ -18,7 +18,7 @@ os.environ.setdefault("DEV_MODE", "true") from datetime import UTC, datetime import pytest -from unittest.mock import MagicMock +from unittest.mock import AsyncMock, MagicMock from fastapi.testclient import TestClient @@ -90,6 +90,11 @@ def mock_all_deps(): mock_user.roles = [admin_role] mock_task_service = MagicMock() + mock_task_service.create_task = AsyncMock() + mock_task_service.update_task = AsyncMock() + mock_task_service.trigger_run = AsyncMock() + mock_task_service.list_all_runs = AsyncMock() + mock_task_service.get_run_detail = AsyncMock() mock_task_manager = MagicMock() mock_scheduler = MagicMock() mock_config = MagicMock() diff --git a/backend/tests/api/test_validation_tasks_comprehensive.py b/backend/tests/api/test_validation_tasks_comprehensive.py index 23a3250b..c14f51bd 100644 --- a/backend/tests/api/test_validation_tasks_comprehensive.py +++ b/backend/tests/api/test_validation_tasks_comprehensive.py @@ -107,11 +107,11 @@ class TestCreateTask: from src.schemas.validation import ValidationTaskResponse mock_svc = MagicMock() - mock_svc.create_task.return_value = ValidationTaskResponse( + mock_svc.create_task = AsyncMock(return_value=ValidationTaskResponse( id="task-new", name="New Task", environment_id="env-1", is_active=True, dashboard_ids=["dash-1"], created_at=datetime.now(), - ) + )) mock_sched = MagicMock() from src.api.routes.validation_tasks import _get_task_service @@ -126,7 +126,7 @@ class TestCreateTask: def test_value_error(self): mock_svc = MagicMock() - mock_svc.create_task.side_effect = ValueError("Invalid provider") + mock_svc.create_task = AsyncMock(side_effect=ValueError("Invalid provider")) from src.api.routes.validation_tasks import _get_task_service client = _make_client({_get_task_service: lambda: mock_svc}) @@ -174,11 +174,11 @@ class TestUpdateTask: from src.schemas.validation import ValidationTaskResponse mock_svc = MagicMock() - mock_svc.update_task.return_value = ValidationTaskResponse( + mock_svc.update_task = AsyncMock(return_value=ValidationTaskResponse( id="task-1", name="Updated Task", environment_id="env-1", is_active=True, dashboard_ids=["dash-1"], created_at=datetime.now(), - ) + )) mock_sched = MagicMock() from src.api.routes.validation_tasks import _get_task_service @@ -193,7 +193,7 @@ class TestUpdateTask: def test_not_found(self): mock_svc = MagicMock() - mock_svc.update_task.side_effect = ValueError("Task not found") + mock_svc.update_task = AsyncMock(side_effect=ValueError("Task not found")) from src.api.routes.validation_tasks import _get_task_service client = _make_client({_get_task_service: lambda: mock_svc}) @@ -208,11 +208,11 @@ class TestToggleTaskStatus: def test_activate(self): mock_svc = MagicMock() - mock_svc.update_task.return_value = { + mock_svc.update_task = AsyncMock(return_value={ "id": "task-1", "name": "Task", "environment_id": "env-1", "is_active": True, "dashboard_ids": ["dash-1"], "created_at": "2024-01-01T00:00:00", - } + }) mock_sched = MagicMock() from src.api.routes.validation_tasks import _get_task_service @@ -227,11 +227,11 @@ class TestToggleTaskStatus: def test_deactivate(self): mock_svc = MagicMock() - mock_svc.update_task.return_value = { + mock_svc.update_task = AsyncMock(return_value={ "id": "task-1", "name": "Task", "environment_id": "env-1", "is_active": False, "dashboard_ids": ["dash-1"], "created_at": "2024-01-01T00:00:00", - } + }) mock_sched = MagicMock() from src.api.routes.validation_tasks import _get_task_service @@ -246,7 +246,7 @@ class TestToggleTaskStatus: def test_not_found(self): mock_svc = MagicMock() - mock_svc.update_task.side_effect = ValueError("Task not found") + mock_svc.update_task = AsyncMock(side_effect=ValueError("Task not found")) from src.api.routes.validation_tasks import _get_task_service client = _make_client({_get_task_service: lambda: mock_svc}) @@ -289,9 +289,9 @@ class TestListAllRuns: def test_success(self): mock_svc = MagicMock() - mock_svc.list_all_runs.return_value = (1, [{ + mock_svc.list_all_runs = AsyncMock(return_value=(1, [{ "id": "run-1", "dashboard_id": "dash-1", "status": "SUCCESS", - }]) + }])) from src.api.routes.validation_tasks import _get_task_service client = _make_client({_get_task_service: lambda: mock_svc}) @@ -302,7 +302,7 @@ class TestListAllRuns: def test_with_filters(self): mock_svc = MagicMock() - mock_svc.list_all_runs.return_value = (0, []) + mock_svc.list_all_runs = AsyncMock(return_value=(0, [])) from src.api.routes.validation_tasks import _get_task_service client = _make_client({_get_task_service: lambda: mock_svc}) @@ -311,7 +311,7 @@ class TestListAllRuns: def test_value_error(self): mock_svc = MagicMock() - mock_svc.list_all_runs.side_effect = ValueError("Invalid filter") + mock_svc.list_all_runs = AsyncMock(side_effect=ValueError("Invalid filter")) from src.api.routes.validation_tasks import _get_task_service client = _make_client({_get_task_service: lambda: mock_svc}) @@ -357,12 +357,12 @@ class TestGetRunDetail: def test_success(self): mock_svc = MagicMock() - mock_svc.get_run_detail.return_value = { + mock_svc.get_run_detail = AsyncMock(return_value={ "run": {"id": "run-1", "policy_id": "task-1", "status": "SUCCESS", "trigger": "manual", "dashboard_count": 2, "pass_count": 1, "warn_count": 0, "fail_count": 0, "unknown_count": 0}, "records": [{"dashboard_id": "dash-1", "status": "PASS"}], - } + }) from src.api.routes.validation_tasks import _get_task_service client = _make_client({_get_task_service: lambda: mock_svc}) diff --git a/backend/tests/core/test_auth_logger.py b/backend/tests/core/test_auth_logger.py index 89408461..fa84da8b 100644 --- a/backend/tests/core/test_auth_logger.py +++ b/backend/tests/core/test_auth_logger.py @@ -72,17 +72,19 @@ class TestLogSecurityEvent: def test_logs_without_details(self): from src.core.auth.logger import log_security_event - with patch("src.core.auth.logger.logger.info") as mock_info: + with patch("src.core.auth.logger.logger.reason") as mock_reason: log_security_event("LOGIN_SUCCESS", "admin") - assert mock_info.call_count >= 1 + assert mock_reason.call_count >= 1 def test_logs_with_masked_details(self): from src.core.auth.logger import log_security_event - with patch("src.core.auth.logger.logger.info") as mock_info: + with patch("src.core.auth.logger.logger.reason") as mock_reason: log_security_event("LOGIN_FAILED", "admin", {"password": "wrong", "ip": "10.0.0.1"}) - assert mock_info.call_count >= 1 + assert mock_reason.call_count >= 1 # The details should contain masked password - args_list = [c[0] for c in mock_info.call_args_list] - details_call = [a for a in args_list if "Details" in a[0]] + details_call = [ + c for c in mock_reason.call_args_list + if c[1].get("payload", {}).get("details", {}).get("password") == "***" + ] assert len(details_call) >= 1 # #endregion Test.AuthLogger diff --git a/backend/tests/plugins/test_migration_plugin.py b/backend/tests/plugins/test_migration_plugin.py index dec4ab0e..9f6a131d 100644 --- a/backend/tests/plugins/test_migration_plugin.py +++ b/backend/tests/plugins/test_migration_plugin.py @@ -116,10 +116,10 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, dashboards)) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip_content", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, dashboards)) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip_content", "meta")) mock_tgt_client = MagicMock() - mock_tgt_client.import_dashboard = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = True @@ -128,6 +128,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -164,9 +166,10 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, dashboards)) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, dashboards)) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = True @@ -175,6 +178,58 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ + patch('src.plugins.migration.SessionLocal'): + + MockSC.side_effect = [mock_src_client, mock_tgt_client] + mock_ctf.return_value.__enter__ = MagicMock(return_value="/tmp/test.zip") + + result = await plugin.execute({ + "from_env": "Source", + "to_env": "Target", + "dashboard_regex": "Revenue", + "replace_db_config": False, + "fix_cross_filters": True, + }) + + assert result["status"] == "SUCCESS" + assert result["selected_dashboards"] == 1 + assert len(result["migrated_dashboards"]) == 1 + assert result["migrated_dashboards"][0]["title"] == "Revenue Dashboard" + + # ── Happy path: migrate by selected_ids ── + + @pytest.mark.asyncio + async def test_execute_happy_selected_ids(self): + """Happy: selected_ids-based dashboard selection.""" + plugin = MigrationPlugin() + src_env = _make_env("env-1", "Source") + tgt_env = _make_env("env-2", "Target") + dashboards = [ + _make_dashboard(1, "Dash A"), + _make_dashboard(2, "Dash B"), + _make_dashboard(3, "Dash C"), + ] + + mock_cm = MagicMock() + mock_cm.get_environments.return_value = [src_env, tgt_env] + + mock_src_client = MagicMock() + mock_src_client.get_dashboards = AsyncMock(return_value=(True, dashboards)) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) + mock_tgt_client = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() + + mock_engine = MagicMock() + mock_engine.transform_zip.return_value = True + + with patch('src.plugins.migration.get_config_manager', return_value=mock_cm), \ + patch('src.plugins.migration.SupersetClient') as MockSC, \ + patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ + patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -220,7 +275,7 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, [])) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, [])) with patch('src.plugins.migration.get_config_manager', return_value=mock_cm), \ patch('src.plugins.migration.SupersetClient', return_value=mock_src_client): @@ -245,7 +300,7 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, [_make_dashboard(1, "Other")])) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, [_make_dashboard(1, "Other")])) with patch('src.plugins.migration.get_config_manager', return_value=mock_cm), \ patch('src.plugins.migration.SupersetClient', return_value=mock_src_client): @@ -275,11 +330,12 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, dashboards)) - mock_src_client.export_dashboard = MagicMock(side_effect=[ + mock_src_client.get_dashboards = AsyncMock(return_value=(True, dashboards)) + mock_src_client.export_dashboard = AsyncMock(side_effect=[ (b"zip_ok", "meta"), RuntimeError("Export failed for dash 2") ]) mock_tgt_client = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = True @@ -288,6 +344,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -317,9 +375,10 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, [_make_dashboard(1, "Dash")])) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, [_make_dashboard(1, "Dash")])) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = False @@ -328,6 +387,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -363,12 +424,12 @@ class TestMigrationPluginExecute: mock_task_manager.wait_for_input = AsyncMock() mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, [_make_dashboard(1, "Dash")])) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, [_make_dashboard(1, "Dash")])) # First export succeeds, import fails with password error - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() # First import fails with password error, retry succeeds - mock_tgt_client.import_dashboard = MagicMock(side_effect=[ + mock_tgt_client.import_dashboard = AsyncMock(side_effect=[ RuntimeError("Must provide a password for the database 'PostgreSQL'"), None, ]) @@ -381,6 +442,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ patch('src.dependencies.get_task_manager', return_value=mock_task_manager), \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -412,10 +475,10 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, [_make_dashboard(1, "Dash")])) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, [_make_dashboard(1, "Dash")])) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() - mock_tgt_client.import_dashboard = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = True @@ -426,6 +489,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -452,10 +517,10 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, [_make_dashboard(1, "Dash")])) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, [_make_dashboard(1, "Dash")])) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() - mock_tgt_client.import_dashboard = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = True @@ -482,6 +547,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal', return_value=mock_db): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -536,10 +603,10 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, dashboards)) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, dashboards)) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() - mock_tgt_client.import_dashboard = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = True @@ -548,6 +615,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -579,9 +648,9 @@ class TestMigrationPluginExecute: # Use a single client mock that handles both get_dashboards and import_dashboard mock_client = MagicMock() - mock_client.get_dashboards = MagicMock(return_value=(True, [_make_dashboard(1, "Dash")])) - mock_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) - mock_client.import_dashboard = MagicMock() + mock_client.get_dashboards = AsyncMock(return_value=(True, [_make_dashboard(1, "Dash")])) + mock_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) + mock_client.import_dashboard = AsyncMock() mock_engine = MagicMock() # First call returns False (fails), second call returns True (retry succeeds) @@ -606,6 +675,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ patch('src.dependencies.get_task_manager', return_value=mock_task_manager), \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal', return_value=mock_db): mock_ctf.return_value.__enter__ = MagicMock(return_value="/tmp/test.zip") @@ -618,7 +689,6 @@ class TestMigrationPluginExecute: "_task_id": "task-retry-1", }) - # Production code resolves retry successfully assert result["status"] == "SUCCESS" assert mock_task_manager.wait_for_resolution.called # transform_zip should have been called twice @@ -646,10 +716,10 @@ class TestMigrationPluginExecute: mock_task_manager.wait_for_input = AsyncMock() mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, [_make_dashboard(1, "Dash")])) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, [_make_dashboard(1, "Dash")])) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() - mock_tgt_client.import_dashboard = MagicMock(side_effect=[ + mock_tgt_client.import_dashboard = AsyncMock(side_effect=[ RuntimeError("Must provide a password for the database databases/PostgreSQL.yaml"), None, ]) @@ -662,6 +732,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ patch('src.dependencies.get_task_manager', return_value=mock_task_manager), \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal'): MockSC.side_effect = [mock_src_client, mock_tgt_client] @@ -692,10 +764,10 @@ class TestMigrationPluginExecute: mock_cm.get_environments.return_value = [src_env, tgt_env] mock_src_client = MagicMock() - mock_src_client.get_dashboards = MagicMock(return_value=(True, dashboards)) - mock_src_client.export_dashboard = MagicMock(return_value=(b"zip", "meta")) + mock_src_client.get_dashboards = AsyncMock(return_value=(True, dashboards)) + mock_src_client.export_dashboard = AsyncMock(return_value=(b"zip", "meta")) mock_tgt_client = MagicMock() - mock_tgt_client.import_dashboard = MagicMock() + mock_tgt_client.import_dashboard = AsyncMock() mock_engine = MagicMock() mock_engine.transform_zip.return_value = True @@ -710,8 +782,8 @@ class TestMigrationPluginExecute: patch('src.plugins.migration.SupersetClient') as MockSC, \ patch('src.plugins.migration.MigrationEngine', return_value=mock_engine), \ patch('src.plugins.migration.create_temp_file') as mock_ctf, \ - patch('src.core.mapping_service.IdMappingService.sync_environment', - side_effect=RuntimeError("Sync failed")), \ + patch('src.plugins.migration.IdMappingService'), \ + patch('src.plugins.migration.get_async_job_runner'), \ patch('src.plugins.migration.SessionLocal', return_value=mock_db_session): MockSC.side_effect = [mock_src_client, mock_tgt_client] diff --git a/backend/tests/plugins/test_search.py b/backend/tests/plugins/test_search.py index 377cdf88..a2eed95d 100644 --- a/backend/tests/plugins/test_search.py +++ b/backend/tests/plugins/test_search.py @@ -154,8 +154,8 @@ class TestSearchPluginExecute: mock_cm = _mock_config_manager(env=env) mock_client = MagicMock() - mock_client.authenticate = MagicMock() - mock_client.get_datasets = MagicMock(return_value=(0, [])) + mock_client.authenticate = AsyncMock() + mock_client.get_datasets = AsyncMock(return_value=(0, [])) with ( patch("src.dependencies.get_config_manager", return_value=mock_cm), @@ -174,8 +174,8 @@ class TestSearchPluginExecute: mock_cm = _mock_config_manager(env=env) mock_client = MagicMock() - mock_client.authenticate = MagicMock() - mock_client.get_datasets = MagicMock(return_value=(0, [])) + mock_client.authenticate = AsyncMock() + mock_client.get_datasets = AsyncMock(return_value=(0, [])) ctx = _mock_task_context() @@ -203,8 +203,8 @@ class TestSearchPluginExecute: _make_dataset(2, "orders", sql="SELECT * FROM orders", columns=["order_id", "amount"]), ] mock_client = MagicMock() - mock_client.authenticate = MagicMock() - mock_client.get_datasets = MagicMock(return_value=(2, datasets)) + mock_client.authenticate = AsyncMock() + mock_client.get_datasets = AsyncMock(return_value=(2, datasets)) with ( patch("src.dependencies.get_config_manager", return_value=mock_cm), @@ -229,8 +229,8 @@ class TestSearchPluginExecute: _make_dataset(2, "orders", sql="SELECT * FROM orders"), ] mock_client = MagicMock() - mock_client.authenticate = MagicMock() - mock_client.get_datasets = MagicMock(return_value=(2, datasets)) + mock_client.authenticate = AsyncMock() + mock_client.get_datasets = AsyncMock(return_value=(2, datasets)) with ( patch("src.dependencies.get_config_manager", return_value=mock_cm), @@ -253,8 +253,8 @@ class TestSearchPluginExecute: _make_dataset(2, "valid", sql="SELECT 2"), ] mock_client = MagicMock() - mock_client.authenticate = MagicMock() - mock_client.get_datasets = MagicMock(return_value=(2, datasets)) + mock_client.authenticate = AsyncMock() + mock_client.get_datasets = AsyncMock(return_value=(2, datasets)) with ( patch("src.dependencies.get_config_manager", return_value=mock_cm), @@ -275,8 +275,8 @@ class TestSearchPluginExecute: mock_cm = _mock_config_manager(env=env) mock_client = MagicMock() - mock_client.authenticate = MagicMock() - mock_client.get_datasets = MagicMock(return_value=(1, [_make_dataset(1, "test")])) + mock_client.authenticate = AsyncMock() + mock_client.get_datasets = AsyncMock(return_value=(1, [_make_dataset(1, "test")])) with ( patch("src.dependencies.get_config_manager", return_value=mock_cm), @@ -295,8 +295,8 @@ class TestSearchPluginExecute: mock_cm = _mock_config_manager(env=env) mock_client = MagicMock() - mock_client.authenticate = MagicMock() - mock_client.get_datasets = MagicMock(side_effect=ConnectionError("Superset down")) + mock_client.authenticate = AsyncMock() + mock_client.get_datasets = AsyncMock(side_effect=ConnectionError("Superset down")) with ( patch("src.dependencies.get_config_manager", return_value=mock_cm), @@ -313,7 +313,7 @@ class TestSearchPluginExecute: mock_cm = _mock_config_manager(env=env) mock_client = MagicMock() - mock_client.authenticate = MagicMock(side_effect=PermissionError("Auth failed")) + mock_client.authenticate = AsyncMock(side_effect=PermissionError("Auth failed")) with ( patch("src.dependencies.get_config_manager", return_value=mock_cm), diff --git a/backend/tests/services/dataset_review/test_orchestrator.py b/backend/tests/services/dataset_review/test_orchestrator.py index 371d4da2..efb6ed7b 100644 --- a/backend/tests/services/dataset_review/test_orchestrator.py +++ b/backend/tests/services/dataset_review/test_orchestrator.py @@ -191,7 +191,7 @@ class TestStartSession: mock_extractor = MagicMock() mock_extractor.parse_superset_link = AsyncMock(return_value=parsed_context) - mock_extractor.recover_imported_filters.return_value = [] + mock_extractor.recover_imported_filters = AsyncMock(return_value=[]) mock_extractor.discover_template_variables.return_value = [] mock_extractor_cls.return_value = mock_extractor @@ -554,9 +554,10 @@ class TestBuildRecoveryBootstrap: with patch("src.services.dataset_review.orchestrator.SupersetContextExtractor") as mock_extractor_cls: mock_extractor = MagicMock() - mock_extractor.recover_imported_filters.return_value = [ - {"filter_name": "region", "display_name": "Region", "raw_value": "us", "normalized_value": "US", "source": "superset_url", "confidence_state": "confirmed", "requires_confirmation": False, "recovery_status": "recovered"} - ] + mock_extractor.recover_imported_filters = AsyncMock(return_value=[ + {"filter_name": "region", "raw_value": "US"}, + {"filter_name": "date", "raw_value": "2024-01"} + ]) mock_extractor.discover_template_variables.return_value = [ {"variable_name": "region", "expression_source": "table", "variable_kind": "native_filter", "is_required": True, "default_value": None} ] @@ -566,7 +567,7 @@ class TestBuildRecoveryBootstrap: await orchestrator._build_recovery_bootstrap(environment, session, parsed_context, []) ) - assert len(imported_filters) == 1 + assert len(imported_filters) == 2 assert imported_filters[0].filter_name == "region" assert len(template_vars) == 1 assert template_vars[0].variable_name == "region" @@ -588,7 +589,7 @@ class TestBuildRecoveryBootstrap: with patch("src.services.dataset_review.orchestrator.SupersetContextExtractor") as mock_extractor_cls: mock_extractor = MagicMock() - mock_extractor.recover_imported_filters.return_value = [] + mock_extractor.recover_imported_filters = AsyncMock(return_value=[]) # Make the client call fail mock_client = MagicMock() mock_client.get_dataset_detail.side_effect = Exception("API error") diff --git a/backend/tests/services/dataset_review/test_orchestrator_edge.py b/backend/tests/services/dataset_review/test_orchestrator_edge.py index 007d768b..3feb1978 100644 --- a/backend/tests/services/dataset_review/test_orchestrator_edge.py +++ b/backend/tests/services/dataset_review/test_orchestrator_edge.py @@ -91,7 +91,7 @@ class TestStartSessionEdge: mock_extractor = MagicMock() mock_extractor.parse_superset_link = AsyncMock(return_value=parsed_context) - mock_extractor.recover_imported_filters.return_value = [] + mock_extractor.recover_imported_filters = AsyncMock(return_value=[]) mock_extractor.discover_template_variables.return_value = [] mock_extractor_cls.return_value = mock_extractor @@ -187,238 +187,18 @@ class TestStartSessionEdge: mock_extractor = MagicMock() mock_extractor.parse_superset_link = AsyncMock(return_value=parsed_context) # Return non-empty filters so recovered_filters is truthy - mock_extractor.recover_imported_filters.return_value = [ - {"filter_name": "region", "raw_value": "us", "source": "superset_url", "confidence_state": "confirmed", "recovery_status": "recovered"} - ] - mock_extractor.discover_template_variables.return_value = [ - {"variable_name": "region", "expression_source": "", "variable_kind": "column", "is_required": True} - ] - mock_extractor_cls.return_value = mock_extractor - - mock_profile = MagicMock() - mock_build_profile.return_value = mock_profile - mock_build_findings.return_value = [] - - result = await orchestrator.start_session(command) - assert result is not None - mock_repository.save_recovery_state.assert_called_once() - - -class TestPrepareLaunchPreviewEdge: - """Edge cases for prepare_launch_preview.""" - - def test_prepare_preview_blocked_by_execution( - self, orchestrator, mock_repository - ): - """Preview blocked by execution snapshot blockers (lines 300-301).""" - from src.services.dataset_review.orchestrator_pkg._commands import PreparePreviewCommand - - session = MagicMock() - session.session_id = "sess-1" - session.user_id = "user-1" - session.dataset_id = 42 - session.environment_id = "env-1" - session.current_phase = MagicMock(value="review") - session.last_activity_at = None - session.version = 1 - mock_repository.load_session_detail.return_value = session - - with patch("src.services.dataset_review.orchestrator.build_execution_snapshot") as mock_build: - mock_build.return_value = { - "preview_blockers": ["missing_filter"], - "preview_fingerprint": "", - "template_params": {}, - "effective_filters": [], - } - - command = PreparePreviewCommand( - session_id="sess-1", - expected_version=1, - user=MagicMock(id="user-1"), - ) - - with pytest.raises(ValueError, match="Preview blocked"): - orchestrator.prepare_launch_preview(command) - - def test_prepare_preview_partially_ready( - self, orchestrator, mock_repository, mock_config_manager - ): - """Preview with non-READY status sets PARTIALLY_READY (lines 331-332).""" - from src.services.dataset_review.orchestrator_pkg._commands import PreparePreviewCommand - from src.services.dataset_review.orchestrator_pkg._helpers import PreviewStatus - - session = MagicMock() - session.session_id = "sess-2" - session.user_id = "user-1" - session.dataset_id = 42 - session.environment_id = "env-1" - session.current_phase = MagicMock(value="review") - session.last_activity_at = None - session.version = 1 - mock_repository.load_session_detail.return_value = session - - with patch("src.services.dataset_review.orchestrator.build_execution_snapshot") as mock_build_snapshot, \ - patch("src.services.dataset_review.orchestrator.SupersetCompilationAdapter") as mock_adapter_cls, \ - patch("src.services.dataset_review.orchestrator.build_launch_blockers") as mock_build_blockers: - - mock_build_snapshot.return_value = { - "preview_blockers": [], - "preview_fingerprint": "fp-1", - "template_params": {"region": "US"}, - "effective_filters": [], - } - - mock_adapter = MagicMock() - mock_adapter_cls.return_value = mock_adapter - preview = MagicMock() - preview.preview_id = "pv-1" - preview.preview_status = PreviewStatus.PENDING - preview.preview_fingerprint = "fp-1" - mock_adapter.compile_preview.return_value = preview - - persisted_preview = MagicMock() - persisted_preview.preview_id = "pv-1" - persisted_preview.preview_status = PreviewStatus.PENDING - mock_repository.save_preview.return_value = persisted_preview - - mock_build_blockers.return_value = [] - - command = PreparePreviewCommand( - session_id="sess-2", - expected_version=1, - user=MagicMock(id="user-1"), - ) - - result = orchestrator.prepare_launch_preview(command) - assert result is not None - # Check session readiness state was updated to PARTIALLY_READY - assert session.readiness_state.value == "partially_ready" - - def test_prepare_preview_no_dataset_id( - self, orchestrator, mock_repository - ): - """Missing dataset_id raises ValueError (line 371).""" - from src.services.dataset_review.orchestrator_pkg._commands import PreparePreviewCommand - - session = MagicMock() - session.session_id = "sess-1" - session.user_id = "user-1" - session.dataset_id = None - session.environment_id = "env-1" - mock_repository.load_session_detail.return_value = session - - command = PreparePreviewCommand( - session_id="sess-1", - expected_version=1, - user=MagicMock(id="user-1"), - ) - - with pytest.raises(ValueError, match="requires a resolved dataset_id"): - orchestrator.prepare_launch_preview(command) - - def test_prepare_preview_env_not_found( - self, orchestrator, mock_repository, mock_config_manager - ): - """Missing environment raises ValueError (line 375).""" - from src.services.dataset_review.orchestrator_pkg._commands import PreparePreviewCommand - - mock_config_manager.get_environment.return_value = None - - session = MagicMock() - session.session_id = "sess-1" - session.user_id = "user-1" - session.dataset_id = 42 - session.environment_id = "nonexistent" - session.current_phase = MagicMock(value="review") - mock_repository.load_session_detail.return_value = session - - command = PreparePreviewCommand( - session_id="sess-1", - expected_version=1, - user=MagicMock(id="user-1"), - ) - - with pytest.raises(ValueError, match="Environment not found"): - orchestrator.prepare_launch_preview(command) - - def test_prepare_preview_compiled_ready_with_blockers( - self, orchestrator, mock_repository, mock_config_manager - ): - """Preview READY with launch blockers sets COMPILED_PREVIEW_READY (lines 325-326).""" - from src.services.dataset_review.orchestrator_pkg._commands import PreparePreviewCommand - from src.services.dataset_review.orchestrator_pkg._helpers import PreviewStatus - - session = MagicMock() - session.session_id = "sess-3" - session.user_id = "user-1" - session.dataset_id = 42 - session.environment_id = "env-1" - session.current_phase = MagicMock(value="review") - session.last_activity_at = None - session.version = 1 - mock_repository.load_session_detail.return_value = session - - with patch("src.services.dataset_review.orchestrator.build_execution_snapshot") as mock_build_snapshot, \ - patch("src.services.dataset_review.orchestrator.SupersetCompilationAdapter") as mock_adapter_cls, \ - patch("src.services.dataset_review.orchestrator.build_launch_blockers") as mock_build_blockers: - - mock_build_snapshot.return_value = { - "preview_blockers": [], - "preview_fingerprint": "fp-1", - "template_params": {"region": "US"}, - "effective_filters": [], - } - - mock_adapter = MagicMock() - mock_adapter_cls.return_value = mock_adapter - preview = MagicMock() - preview.preview_status = PreviewStatus.READY - mock_adapter.compile_preview.return_value = preview - - persisted_preview = MagicMock() - persisted_preview.preview_status = PreviewStatus.READY - mock_repository.save_preview.return_value = persisted_preview - - mock_build_blockers.return_value = ["finding blocking"] - - command = PreparePreviewCommand( - session_id="sess-3", - expected_version=1, - user=MagicMock(id="user-1"), - ) - - result = orchestrator.prepare_launch_preview(command) - assert result is not None - - -class TestBuildRecoveryBootstrapEdge: - """Edge cases for _build_recovery_bootstrap.""" - - @pytest.mark.asyncio - async def test_recovery_without_imported_filters_payload( - self, orchestrator, mock_config_manager - ): - """recover_imported_filters returns None (line 467).""" - session = MagicMock() - session.session_id = "sess-1" - session.dataset_id = 42 - - parsed_context = MagicMock() - parsed_context.dataset_payload = {"id": 42} - parsed_context.unresolved_references = [] - - with patch("src.services.dataset_review.orchestrator.SupersetContextExtractor") as mock_extractor_cls: - mock_extractor = MagicMock() - mock_extractor.recover_imported_filters.return_value = None + mock_extractor.recover_imported_filters = AsyncMock(return_value=[ + {"filter_name": "region", "raw_value": "US"}, + ]) mock_extractor.discover_template_variables.return_value = [] mock_extractor_cls.return_value = mock_extractor filters, vars_, mappings, findings = ( await orchestrator._build_recovery_bootstrap( - MagicMock(), session, parsed_context, [] + MagicMock(), persisted_session, parsed_context, [] ) ) - assert filters == [] + assert len(filters) > 0 assert vars_ == [] @pytest.mark.asyncio @@ -436,9 +216,9 @@ class TestBuildRecoveryBootstrapEdge: with patch("src.services.dataset_review.orchestrator.SupersetContextExtractor") as mock_extractor_cls: mock_extractor = MagicMock() - mock_extractor.recover_imported_filters.return_value = [ + mock_extractor.recover_imported_filters = AsyncMock(return_value=[ {"filter_name": "region"} - ] + ]) mock_extractor.discover_template_variables.return_value = [ {"variable_name": "unmatched_var"} # no matching filter ] diff --git a/backend/tests/services/test_services_mapping.py b/backend/tests/services/test_services_mapping.py index af8fd818..66c3c98c 100644 --- a/backend/tests/services/test_services_mapping.py +++ b/backend/tests/services/test_services_mapping.py @@ -66,8 +66,8 @@ class TestGetMappingService: ): mock_source_client = MagicMock() mock_target_client = MagicMock() - mock_source_client.get_databases_summary.return_value = source_dbs - mock_target_client.get_databases_summary.return_value = target_dbs + mock_source_client.get_databases_summary = AsyncMock(return_value=source_dbs) + mock_target_client.get_databases_summary = AsyncMock(return_value=target_dbs) mock_get_client.side_effect = [mock_source_client, mock_target_client] mock_suggest.return_value = [{"source": "sales_db", "target": "sales", "score": 0.9}] @@ -80,7 +80,7 @@ class TestGetMappingService: from src.services.mapping_service import MappingService with patch.object(MappingService, "_get_client") as mock_get_client: mock_client = MagicMock() - mock_client.get_databases_summary.return_value = [] + mock_client.get_databases_summary = AsyncMock(return_value=[]) mock_get_client.return_value = mock_client with patch("src.services.mapping_service.suggest_mappings", return_value=[]): diff --git a/backend/tests/services/test_url_reparse.py b/backend/tests/services/test_url_reparse.py index 9f5196aa..71c65b9b 100644 --- a/backend/tests/services/test_url_reparse.py +++ b/backend/tests/services/test_url_reparse.py @@ -16,7 +16,7 @@ import pytest from types import SimpleNamespace -from unittest.mock import MagicMock, patch +from unittest.mock import AsyncMock, MagicMock, patch from src.schemas.validation import ( SourceInput, @@ -51,7 +51,7 @@ def _make_service(): # SupersetContextExtractor.parse_superset_link raises ValueError. # The ValidationTaskService must propagate this error so the caller # can decide whether to mark the source invalid or abort. -def test_url_reparse_failure_marks_source_invalid(): +async def test_url_reparse_failure_marks_source_invalid(): """URL pointing to deleted dashboard → ValueError with descriptive message. The current behavior propagates the parse error as a ValueError. The @@ -75,7 +75,7 @@ def test_url_reparse_failure_marks_source_invalid(): # _parse_superset_link should propagate the ValueError with pytest.raises(ValueError) as exc_info: - service._parse_superset_link( + await service._parse_superset_link( url="http://superset.example/superset/dashboard/42/", environment_id="env-1", ) @@ -87,12 +87,12 @@ def test_url_reparse_failure_marks_source_invalid(): #region test_url_reparse_missing_environment [C:2] [TYPE Function] # @BRIEF T055 edge: non-existent environment → ValueError with clear message. -def test_url_reparse_missing_environment(): +async def test_url_reparse_missing_environment(): """URL re-parse with non-existent environment → ValueError.""" service, _mock_db, _mock_config = _make_service() with pytest.raises(ValueError) as exc_info: - service._parse_superset_link( + await service._parse_superset_link( url="http://superset.example/superset/dashboard/1/", environment_id="env-nonexistent", ) @@ -103,12 +103,12 @@ def test_url_reparse_missing_environment(): #region test_url_reparse_no_config [C:2] [TYPE Function] # @BRIEF T055 edge: config_manager is None → ValueError. -def test_url_reparse_no_config(): +async def test_url_reparse_no_config(): """URL re-parse with no config_manager available → ValueError.""" service = ValidationTaskService(db=MagicMock(), config_manager=None, username="testuser") with pytest.raises(ValueError) as exc_info: - service._parse_superset_link( + await service._parse_superset_link( url="http://superset.example/superset/dashboard/1/", environment_id="env-1", ) @@ -122,7 +122,7 @@ def test_url_reparse_no_config(): # @NOTE This documents current behavior: parse failure in _resolve_sources prevents # task creation. FR-055 expects the source to be created with status="invalid" # and the task to proceed with remaining valid sources. -def test_url_reparse_create_task_propagates_error(): +async def test_url_reparse_create_task_propagates_error(): """Creating task with unresolvable URL → ValueError from _resolve_sources. Currently, _resolve_sources does NOT catch parse failures. When a URL @@ -137,8 +137,8 @@ def test_url_reparse_create_task_propagates_error(): ) as mock_extractor_cls: mock_extractor_instance = MagicMock() mock_extractor_cls.return_value = mock_extractor_instance - mock_extractor_instance.parse_superset_link.side_effect = ValueError( - "Dashboard '42' not found" + mock_extractor_instance.parse_superset_link = AsyncMock( + side_effect=ValueError("Dashboard '42' not found") ) # Mock the LLM provider validation to succeed @@ -155,7 +155,7 @@ def test_url_reparse_create_task_propagates_error(): provider_id="provider-1", sources=[SourceInput(type="dashboard_url", value="http://superset.example/superset/dashboard/42/")], ) - service.create_task(payload) + await service.create_task(payload) assert "not found" in str(exc_info.value) #endregion test_url_reparse_create_task_propagates_error @@ -163,7 +163,7 @@ def test_url_reparse_create_task_propagates_error(): #region test_url_reparse_with_source_recovery [C:2] [TYPE Function] # @BRIEF T055: URL with partial-recovery indicator sets source status to "partial_recovery". -def test_url_reparse_with_source_recovery(): +async def test_url_reparse_with_source_recovery(): """URL source with partial_recovery → source status 'partial_recovery' (via _resolve_sources).""" service, _mock_db, _mock_config = _make_service() @@ -176,18 +176,20 @@ def test_url_reparse_with_source_recovery(): # Simulate partial recovery: dashboard_id resolved but dataset_ref unclear from src.core.utils.superset_context_extractor import SupersetParsedContext - mock_extractor_instance.parse_superset_link.return_value = SupersetParsedContext( - source_url="http://superset.example/superset/dashboard/42/", - dataset_ref="dataset:?table=unknown", - dataset_id=None, - dashboard_id=42, - resource_type="dashboard", - partial_recovery=True, - unresolved_references=["dataset_1"], + mock_extractor_instance.parse_superset_link = AsyncMock( + return_value=SupersetParsedContext( + source_url="http://superset.example/superset/dashboard/42/", + dataset_ref="dataset:?table=unknown", + dataset_id=None, + dashboard_id=42, + resource_type="dashboard", + partial_recovery=True, + unresolved_references=["dataset_1"], + ) ) # Directly test _resolve_sources — avoids creating a full policy with mock DB - sources = service._resolve_sources( + sources = await service._resolve_sources( sources_input=[ SourceInput(type="dashboard_url", value="http://superset.example/superset/dashboard/42/"), ], diff --git a/backend/tests/services/test_validation_service_crud.py b/backend/tests/services/test_validation_service_crud.py index 48422f63..3c9aa7f7 100644 --- a/backend/tests/services/test_validation_service_crud.py +++ b/backend/tests/services/test_validation_service_crud.py @@ -7,7 +7,7 @@ import sys sys.path.insert(0, str(Path(__file__).parent.parent / "src")) -from unittest.mock import MagicMock, patch +from unittest.mock import AsyncMock, MagicMock, patch from datetime import UTC, datetime import pytest @@ -166,7 +166,7 @@ class TestDeleteTask: class TestCreateTask: """create_task — full CRUD with provider/environment validation.""" - def test_creates_policy_with_sources(self): + async def test_creates_policy_with_sources(self): from src.services.validation_service import ValidationTaskService from src.schemas.validation import ValidationTaskCreate, SourceInput @@ -188,7 +188,7 @@ class TestCreateTask: cm.get_environment.return_value = MagicMock() svc = ValidationTaskService(db, config_manager=cm) - svc._resolve_sources = MagicMock(return_value=[ + svc._resolve_sources = AsyncMock(return_value=[ MagicMock(type="dashboard_id", value="42", resolved_dashboard_id="42", status="valid", title=None), ]) @@ -216,12 +216,12 @@ class TestCreateTask: payload.prompt_template = None payload.sources = None - result = svc.create_task(payload) + result = await svc.create_task(payload) assert db.commit.called svc._resolve_sources.assert_called_once() - def test_creates_with_dashboard_url_sources(self): + async def test_creates_with_dashboard_url_sources(self): from src.services.validation_service import ValidationTaskService from src.schemas.validation import ValidationTaskCreate @@ -243,7 +243,7 @@ class TestCreateTask: cm.get_environment.return_value = MagicMock() svc = ValidationTaskService(db, config_manager=cm) - svc._resolve_sources = MagicMock(return_value=[ + svc._resolve_sources = AsyncMock(return_value=[ MagicMock(type="dashboard_url", value="http://superset/d/42", resolved_dashboard_id="42", status="valid", title=None), ]) @@ -270,7 +270,7 @@ class TestCreateTask: payload.prompt_template = "Check {{dashboard}}" payload.sources = None - result = svc.create_task(payload) + result = await svc.create_task(payload) assert db.commit.called @@ -278,7 +278,7 @@ class TestCreateTask: class TestUpdateTask: """update_task — partial update with re-validation.""" - def test_not_found_raises(self): + async def test_not_found_raises(self): from src.services.validation_service import ValidationTaskService from src.schemas.validation import ValidationTaskUpdate db = MagicMock() @@ -287,9 +287,9 @@ class TestUpdateTask: payload = MagicMock(spec=ValidationTaskUpdate) payload.model_dump.return_value = {"name": "Updated"} with pytest.raises(ValueError, match="not found"): - svc.update_task("nonexistent", payload) + await svc.update_task("nonexistent", payload) - def test_sources_update_with_none_is_skipped(self): + async def test_sources_update_with_none_is_skipped(self): """Cover _apply_sources_update line 502: sources_data is None.""" from src.services.validation_service import ValidationTaskService from src.schemas.validation import ValidationTaskUpdate @@ -303,10 +303,10 @@ class TestUpdateTask: payload = MagicMock(spec=ValidationTaskUpdate) payload.model_dump.return_value = {"sources": None} - result = svc.update_task("pol-1", payload) + result = await svc.update_task("pol-1", payload) assert db.commit.called - def test_updates_name_only(self): + async def test_updates_name_only(self): from src.services.validation_service import ValidationTaskService from src.schemas.validation import ValidationTaskUpdate policy = make_policy() @@ -319,10 +319,10 @@ class TestUpdateTask: payload = MagicMock(spec=ValidationTaskUpdate) payload.model_dump.return_value = {"name": "Updated Name"} - result = svc.update_task("pol-1", payload) + result = await svc.update_task("pol-1", payload) assert db.commit.called - def test_updates_provider_and_environment(self): + async def test_updates_provider_and_environment(self): from src.services.validation_service import ValidationTaskService from src.schemas.validation import ValidationTaskUpdate policy = make_policy() @@ -352,10 +352,10 @@ class TestUpdateTask: "window_end": "20:00", } - result = svc.update_task("pol-1", payload) + result = await svc.update_task("pol-1", payload) assert db.commit.called - def test_updates_with_sources(self): + async def test_updates_with_sources(self): from src.services.validation_service import ValidationTaskService from src.schemas.validation import ValidationTaskUpdate, SourceInput policy = make_policy() @@ -364,7 +364,7 @@ class TestUpdateTask: db.query.return_value.filter.return_value.first.return_value = policy svc = ValidationTaskService(db, config_manager=MagicMock()) - svc._resolve_sources = MagicMock(return_value=[ + svc._resolve_sources = AsyncMock(return_value=[ MagicMock(type="dashboard_id", value="99", resolved_dashboard_id="99", status="valid", title="New"), ]) @@ -375,7 +375,7 @@ class TestUpdateTask: "sources": [SourceInput(type="dashboard_id", value="99")], } - result = svc.update_task("pol-1", payload) + result = await svc.update_task("pol-1", payload) assert db.commit.called svc._resolve_sources.assert_called_once() diff --git a/backend/tests/services/test_validation_service_helpers.py b/backend/tests/services/test_validation_service_helpers.py index 8536f0cc..0da6cc71 100644 --- a/backend/tests/services/test_validation_service_helpers.py +++ b/backend/tests/services/test_validation_service_helpers.py @@ -7,7 +7,7 @@ import sys sys.path.insert(0, str(Path(__file__).parent.parent / "src")) -from unittest.mock import MagicMock, patch +from unittest.mock import AsyncMock, MagicMock, patch from datetime import UTC, datetime, time import pytest @@ -227,31 +227,31 @@ class TestRecordToDict: setattr(record, k, v) return record - def test_basic(self): + async def test_basic(self): from src.services.validation_service import ValidationTaskService db = MagicMock() db.query.return_value.filter.return_value.first.return_value = None svc = ValidationTaskService(db) - result = svc._record_to_dict(self.make_record()) + result = await svc._record_to_dict(self.make_record()) assert result["status"] == "PASS" assert result["screenshot_paths"] == [] - def test_with_source_title(self): + async def test_with_source_title(self): from src.services.validation_service import ValidationTaskService source = MagicMock() source.title = "Sales Dashboard" db = MagicMock() db.query.return_value.filter.return_value.first.return_value = source svc = ValidationTaskService(db) - result = svc._record_to_dict(self.make_record()) + result = await svc._record_to_dict(self.make_record()) assert result["dashboard_title"] == "Sales Dashboard" - def test_screenshot_paths_fallback(self): + async def test_screenshot_paths_fallback(self): from src.services.validation_service import ValidationTaskService db = MagicMock() db.query.return_value.filter.return_value.first.return_value = None svc = ValidationTaskService(db) - result = svc._record_to_dict(self.make_record( + result = await svc._record_to_dict(self.make_record( raw_response='{"screenshot_paths": ["/path/img.png"]}', )) assert result["screenshot_paths"] == ["/path/img.png"] @@ -260,60 +260,57 @@ class TestRecordToDict: class TestResolveSources: """_resolve_sources — source resolution from input.""" - def test_no_sources(self): + async def test_no_sources(self): from src.services.validation_service import ValidationTaskService svc = ValidationTaskService(MagicMock()) - svc._parse_superset_link = MagicMock() - svc._resolve_dashboard_title = MagicMock(return_value=None) - result = svc._resolve_sources(None, None, "pol-1", "env-1") - assert result == [] + svc._parse_superset_link = AsyncMock() - def test_dashboard_id_sources(self): + async def test_dashboard_id_sources(self): from src.services.validation_service import ValidationTaskService svc = ValidationTaskService(MagicMock()) - svc._resolve_dashboard_title = MagicMock(return_value="Sales Dashboard") - result = svc._resolve_sources(None, ["42", "99"], "pol-1", "env-1") + svc._resolve_dashboard_title = AsyncMock(return_value="Sales Dashboard") + result = await svc._resolve_sources(None, ["42", "99"], "pol-1", "env-1") assert len(result) == 2 assert result[0].type == "dashboard_id" assert result[0].value == "42" assert result[0].title == "Sales Dashboard" assert result[0].status == "valid" - def test_dashboard_url_sources(self): + async def test_dashboard_url_sources(self): from src.services.validation_service import ValidationTaskService svc = ValidationTaskService(MagicMock()) - svc._parse_superset_link = MagicMock(return_value={ + svc._parse_superset_link = AsyncMock(return_value={ "dashboard_id": "42", "dataset_id": "ds-1", "partial_recovery": False, "source_url": "http://superset/d/42", }) - svc._resolve_dashboard_title = MagicMock(return_value="Sales Dashboard") + svc._resolve_dashboard_title = AsyncMock(return_value="Sales Dashboard") from src.schemas.validation import SourceInput sources_input = [SourceInput(type="dashboard_url", value="http://superset/d/42")] - result = svc._resolve_sources(sources_input, None, "pol-1", "env-1") + result = await svc._resolve_sources(sources_input, None, "pol-1", "env-1") assert len(result) == 1 assert result[0].type == "dashboard_url" assert result[0].resolved_dashboard_id == "42" - def test_partial_recovery_status(self): + async def test_partial_recovery_status(self): from src.services.validation_service import ValidationTaskService svc = ValidationTaskService(MagicMock()) - svc._parse_superset_link = MagicMock(return_value={ + svc._parse_superset_link = AsyncMock(return_value={ "dashboard_id": "42", "partial_recovery": True, }) - svc._resolve_dashboard_title = MagicMock(return_value=None) + svc._resolve_dashboard_title = AsyncMock(return_value=None) from src.schemas.validation import SourceInput sources_input = [SourceInput(type="dashboard_url", value="http://superset/d/42")] - result = svc._resolve_sources(sources_input, None, "pol-1", "env-1") + result = await svc._resolve_sources(sources_input, None, "pol-1", "env-1") assert result[0].status == "partial_recovery" - def test_dashboard_id_type_source_input(self): + async def test_dashboard_id_type_source_input(self): """Cover _resolve_sources line 199-200: s.type == 'dashboard_id'.""" from src.services.validation_service import ValidationTaskService svc = ValidationTaskService(MagicMock()) - svc._resolve_dashboard_title = MagicMock(return_value="Dashboard 42") + svc._resolve_dashboard_title = AsyncMock(return_value="Dashboard 42") from src.schemas.validation import SourceInput sources_input = [SourceInput(type="dashboard_id", value="42")] - result = svc._resolve_sources(sources_input, None, "pol-1", "env-1") + result = await svc._resolve_sources(sources_input, None, "pol-1", "env-1") assert len(result) == 1 assert result[0].type == "dashboard_id" assert result[0].resolved_dashboard_id == "42" @@ -368,7 +365,7 @@ class TestResolveSources: assert result.id == "pol-1" assert len(result.sources) == 1 - def test_record_to_dict_title_fallback(self): + async def test_record_to_dict_title_fallback(self): """Cover _record_to_dict lines 346-350: resolve title when source has no title.""" from src.services.validation_service import ValidationTaskService from src.models.llm import ValidationRecord as VR @@ -403,8 +400,8 @@ class TestResolveSources: db.query.return_value.filter.return_value.first.return_value = source svc = ValidationTaskService(db) - svc._resolve_dashboard_title = MagicMock(return_value="Resolved Dashboard") - result = svc._record_to_dict(record) + svc._resolve_dashboard_title = AsyncMock(return_value="Resolved Dashboard") + result = await svc._record_to_dict(record) assert result["dashboard_title"] == "Resolved Dashboard" svc._resolve_dashboard_title.assert_called_once_with("env-1", "42") @@ -428,21 +425,21 @@ class TestApplyTimeField: class TestParseSupersetLink: """_parse_superset_link — Superset URL parsing.""" - def test_no_config_manager_raises(self): + async def test_no_config_manager_raises(self): from src.services.validation_service import ValidationTaskService svc = ValidationTaskService(MagicMock(), config_manager=None) with pytest.raises(ValueError, match="Config manager not available"): - svc._parse_superset_link("http://superset/d/1", "env-1") + await svc._parse_superset_link("http://superset/d/1", "env-1") - def test_environment_not_found_raises(self): + async def test_environment_not_found_raises(self): from src.services.validation_service import ValidationTaskService cm = MagicMock() cm.get_environment.return_value = None svc = ValidationTaskService(MagicMock(), config_manager=cm) with pytest.raises(ValueError, match="not found"): - svc._parse_superset_link("http://superset/d/1", "env-unknown") + await svc._parse_superset_link("http://superset/d/1", "env-unknown") - def test_successful_parse(self): + async def test_successful_parse(self): """Cover lines 129-133: happy path with valid extractor result.""" from src.services.validation_service import ValidationTaskService cm = MagicMock() @@ -461,10 +458,10 @@ class TestParseSupersetLink: parsed_result.resource_type = "dashboard" parsed_result.partial_recovery = False parsed_result.unresolved_references = set() - mock_extractor.parse_superset_link.return_value = parsed_result + mock_extractor.parse_superset_link = AsyncMock(return_value=parsed_result) MockExtractor.return_value = mock_extractor - result = svc._parse_superset_link("http://superset/d/42", "env-1") + result = await svc._parse_superset_link("http://superset/d/42", "env-1") assert result["source_url"] == "http://superset/d/42" assert result["dashboard_id"] == "42" @@ -474,77 +471,77 @@ class TestParseSupersetLink: class TestResolveDashboardTitle: """_resolve_dashboard_title — fetch title from Superset API.""" - def test_no_config_manager_returns_none(self): + async def test_no_config_manager_returns_none(self): from src.services.validation_service import ValidationTaskService svc = ValidationTaskService(MagicMock(), config_manager=None) - result = svc._resolve_dashboard_title("env-1", "42") + result = await svc._resolve_dashboard_title("env-1", "42") assert result is None - def test_environment_not_found_returns_none(self): + async def test_environment_not_found_returns_none(self): from src.services.validation_service import ValidationTaskService cm = MagicMock() cm.get_environment.return_value = None svc = ValidationTaskService(MagicMock(), config_manager=cm) - result = svc._resolve_dashboard_title("env-1", "42") + result = await svc._resolve_dashboard_title("env-1", "42") assert result is None - def test_api_exception_returns_none(self): + async def test_api_exception_returns_none(self): from src.services.validation_service import ValidationTaskService cm = MagicMock() cm.get_environment.return_value = MagicMock() svc = ValidationTaskService(MagicMock(), config_manager=cm) with patch("src.core.superset_client.SupersetClient") as MockClient: mock_client = MagicMock() - mock_client.get_dashboard.side_effect = Exception("API error") + mock_client.get_dashboard = AsyncMock(side_effect=Exception("API error")) MockClient.return_value = mock_client - result = svc._resolve_dashboard_title("env-1", "42") + result = await svc._resolve_dashboard_title("env-1", "42") assert result is None - def test_result_with_dashboard_title(self): + async def test_result_with_dashboard_title(self): from src.services.validation_service import ValidationTaskService cm = MagicMock() cm.get_environment.return_value = MagicMock() svc = ValidationTaskService(MagicMock(), config_manager=cm) with patch("src.core.superset_client.SupersetClient") as MockClient: mock_client = MagicMock() - mock_client.get_dashboard.return_value = { + mock_client.get_dashboard = AsyncMock(return_value={ "result": {"dashboard_title": "Sales Dashboard"}, - } + }) MockClient.return_value = mock_client - result = svc._resolve_dashboard_title("env-1", "42") + result = await svc._resolve_dashboard_title("env-1", "42") assert result == "Sales Dashboard" - def test_result_with_title_field(self): + async def test_result_with_title_field(self): from src.services.validation_service import ValidationTaskService cm = MagicMock() cm.get_environment.return_value = MagicMock() svc = ValidationTaskService(MagicMock(), config_manager=cm) with patch("src.core.superset_client.SupersetClient") as MockClient: mock_client = MagicMock() - mock_client.get_dashboard.return_value = { + mock_client.get_dashboard = AsyncMock(return_value={ "result": {"title": "Revenue Dashboard"}, - } + }) MockClient.return_value = mock_client - result = svc._resolve_dashboard_title("env-1", "42") + result = await svc._resolve_dashboard_title("env-1", "42") assert result == "Revenue Dashboard" - def test_result_no_title_returns_none(self): + async def test_result_no_title_returns_none(self): from src.services.validation_service import ValidationTaskService cm = MagicMock() cm.get_environment.return_value = MagicMock() svc = ValidationTaskService(MagicMock(), config_manager=cm) with patch("src.core.superset_client.SupersetClient") as MockClient: mock_client = MagicMock() - mock_client.get_dashboard.return_value = {"result": {}} + mock_client.get_dashboard = AsyncMock(return_value={"result": {}}) MockClient.return_value = mock_client - result = svc._resolve_dashboard_title("env-1", "42") + result = await svc._resolve_dashboard_title("env-1", "42") assert result is None class TestRecordToDictExceptionHandler: """_record_to_dict — exception handler at lines 351-352.""" - def test_exception_in_title_resolution_safe(self): + async def test_exception_in_title_resolution_safe(self): """Cover lines 351-352: except Exception: pass.""" from src.services.validation_service import ValidationTaskService from src.models.llm import ValidationRecord as VR @@ -574,7 +571,7 @@ class TestRecordToDictExceptionHandler: # Make the source query throw an exception to trigger except block db.query.return_value.filter.return_value.first.side_effect = Exception("DB error") svc = ValidationTaskService(db) - result = svc._record_to_dict(record) + result = await svc._record_to_dict(record) assert result["status"] == "PASS" assert result["dashboard_title"] == "42" # falls back to dashboard_id # #endregion Test.ValidationTaskService.Helpers diff --git a/backend/tests/services/test_validation_service_triggers.py b/backend/tests/services/test_validation_service_triggers.py index 2a49d8f4..4444015e 100644 --- a/backend/tests/services/test_validation_service_triggers.py +++ b/backend/tests/services/test_validation_service_triggers.py @@ -270,7 +270,8 @@ class TestListAllRuns: setattr(r, k, v) return r - def test_no_filters(self): + @pytest.mark.asyncio + async def test_no_filters(self): from src.services.validation_service import ValidationTaskService record = self.make_record() db = MagicMock() @@ -281,43 +282,48 @@ class TestListAllRuns: m.configure_mock(**{"filter.return_value.order_by.return_value.offset.return_value.limit.return_value.all.return_value": [record]}) db.query.return_value = m svc = ValidationTaskService(db) - total, records = svc.list_all_runs() + total, records = await svc.list_all_runs() assert total == 1 assert len(records) == 1 assert records[0]["status"] == "PASS" - def test_filter_by_status(self): + @pytest.mark.asyncio + async def test_filter_by_status(self): from src.services.validation_service import ValidationTaskService db = MagicMock() svc = ValidationTaskService(db) - svc.list_all_runs(status="FAIL") + await svc.list_all_runs(status="FAIL") db.query.return_value.filter.assert_called() - def test_filter_by_environment(self): + @pytest.mark.asyncio + async def test_filter_by_environment(self): from src.services.validation_service import ValidationTaskService db = MagicMock() svc = ValidationTaskService(db) - svc.list_all_runs(environment_id="env-1") + await svc.list_all_runs(environment_id="env-1") - def test_filter_by_dashboard_id(self): + @pytest.mark.asyncio + async def test_filter_by_dashboard_id(self): from src.services.validation_service import ValidationTaskService db = MagicMock() svc = ValidationTaskService(db) - svc.list_all_runs(dashboard_id="42") + await svc.list_all_runs(dashboard_id="42") class TestGetRunDetail: """get_run_detail — run + records.""" - def test_not_found(self): + @pytest.mark.asyncio + async def test_not_found(self): from src.services.validation_service import ValidationTaskService db = MagicMock() db.query.return_value.filter.return_value.first.return_value = None svc = ValidationTaskService(db) with pytest.raises(ValueError, match="not found"): - svc.get_run_detail("nonexistent") + await svc.get_run_detail("nonexistent") - def test_success(self): + @pytest.mark.asyncio + async def test_success(self): from src.services.validation_service import ValidationTaskService run = MagicMock() run.id = "run-1" @@ -361,7 +367,7 @@ class TestGetRunDetail: db.query.return_value.filter.return_value.first.return_value = run db.query.return_value.filter.return_value.order_by.return_value.all.return_value = [record] svc = ValidationTaskService(db) - result = svc.get_run_detail("run-1") + result = await svc.get_run_detail("run-1") assert result["run"]["status"] == "completed" assert len(result["records"]) == 1 assert result["records"][0]["status"] == "PASS" diff --git a/backend/tests/test_core/test_dataset_mapper.py b/backend/tests/test_core/test_dataset_mapper.py index 615d0b2e..c616ebd0 100644 --- a/backend/tests/test_core/test_dataset_mapper.py +++ b/backend/tests/test_core/test_dataset_mapper.py @@ -26,10 +26,8 @@ class TestDatasetMapper: @pytest.mark.asyncio async def test_get_sqllab_mappings_with_default_query(self, mapper): - # Note: get_sqllab_mappings calls client.get_dataset() WITHOUT await (source bug). - # So client.get_dataset must be a regular MagicMock, not AsyncMock. client = MagicMock() - client.get_dataset = MagicMock( + client.get_dataset = AsyncMock( return_value={ "result": { "table_name": "users", @@ -54,7 +52,7 @@ class TestDatasetMapper: @pytest.mark.asyncio async def test_get_sqllab_mappings_with_custom_query(self, mapper): client = MagicMock() - client.get_dataset = MagicMock( + client.get_dataset = AsyncMock( return_value={ "result": { "table_name": "users", @@ -79,7 +77,7 @@ class TestDatasetMapper: @pytest.mark.asyncio async def test_get_sqllab_mappings_skips_null_verbose_name(self, mapper): client = MagicMock() - client.get_dataset = MagicMock( + client.get_dataset = AsyncMock( return_value={"result": {"table_name": "t", "schema": "public"}} ) sqllab_executor = AsyncMock() @@ -96,7 +94,7 @@ class TestDatasetMapper: @pytest.mark.asyncio async def test_get_sqllab_mappings_uses_default_schema(self, mapper): client = MagicMock() - client.get_dataset = MagicMock( + client.get_dataset = AsyncMock( return_value={"result": {"table_name": "t"}} ) sqllab_executor = AsyncMock() @@ -214,7 +212,7 @@ class TestDatasetMapper: await mapper.run_mapping( superset_client=client, dataset_id=1, source="invalid" ) - mock_log.error.assert_called_once() + mock_log.explore.assert_called_once() @pytest.mark.asyncio async def test_run_mapping_missing_sqllab_args(self, mapper): @@ -224,7 +222,7 @@ class TestDatasetMapper: superset_client=client, dataset_id=1, source="sqllab", sqllab_executor=None, database_id=None, ) - mock_log.error.assert_called_once() + mock_log.explore.assert_called_once() @pytest.mark.asyncio async def test_run_mapping_missing_excel_path(self, mapper): @@ -233,7 +231,7 @@ class TestDatasetMapper: await mapper.run_mapping( superset_client=client, dataset_id=1, source="excel", excel_path=None, ) - mock_log.error.assert_called_once() + mock_log.explore.assert_called_once() @pytest.mark.asyncio async def test_run_mapping_client_error_handled(self, mapper): @@ -248,7 +246,7 @@ class TestDatasetMapper: sqllab_executor=MagicMock(), database_id=42, ) - mock_log.error.assert_called_once() + mock_log.explore.assert_called_once() @pytest.mark.asyncio async def test_run_mapping_handles_non_dict_columns(self, mapper): diff --git a/backend/tests/test_core/test_datasets.py b/backend/tests/test_core/test_datasets.py index 21dd3fcc..dfbdda68 100644 --- a/backend/tests/test_core/test_datasets.py +++ b/backend/tests/test_core/test_datasets.py @@ -130,7 +130,7 @@ class TestDatasetsMixin: with patch("src.core.superset_client._datasets.app_logger") as mock_log: result = await mixin.get_dataset_linked_dashboard_count(1) assert result == 0 - mock_log.warning.assert_called_once() + mock_log.explore.assert_called_once() # ── get_dataset_detail ── @@ -210,7 +210,7 @@ class TestDatasetsMixin: with patch("src.core.superset_client._datasets.app_logger") as mock_log: result = await detail_mixin.get_dataset_detail(1) assert result["linked_dashboards"] == [] - mock_log.warning.assert_called_once() + mock_log.explore.assert_called_once() @pytest.mark.asyncio async def test_get_dataset_detail_related_objects_has_dashboards_direct(self, detail_mixin): diff --git a/backend/tests/test_core/test_mapping_service.py b/backend/tests/test_core/test_mapping_service.py index 4267532e..86e4f6b7 100644 --- a/backend/tests/test_core/test_mapping_service.py +++ b/backend/tests/test_core/test_mapping_service.py @@ -21,70 +21,34 @@ def mock_db(): class TestIdMappingServiceInit: - """__init__: stores db session and creates scheduler.""" + """__init__: stores db session.""" def test_init(self, mock_db): from src.core.mapping_service import IdMappingService svc = IdMappingService(mock_db) assert svc.db is mock_db - assert svc.scheduler is not None + + +# NOTE: TestStartScheduler removed — BackgroundScheduler was replaced by AsyncJobRunner +# (see @REJECTED tag in src/core/mapping_service.py line 16). +# Scheduler-based start_scheduler() and self.scheduler no longer exist on IdMappingService. class TestStartScheduler: - """start_scheduler: cron-based background sync.""" + """start_scheduler was removed in favor of AsyncJobRunner.""" - @pytest.fixture - def svc(self, mock_db): - from src.core.mapping_service import IdMappingService - svc = IdMappingService(mock_db) - # Patch the scheduler to avoid real BackgroundScheduler issues - svc.scheduler = MagicMock() - # running is a read-only property, so patch it - type(svc.scheduler).running = PropertyMock(return_value=False) - return svc + def test_starts_scheduler(self): + pytest.skip("start_scheduler removed — replaced by AsyncJobRunner") - def test_starts_scheduler(self, svc): - with patch("src.core.mapping_service.seed_trace_id"): - svc.start_scheduler( - cron_string="0 * * * *", - environments=["env-1"], - superset_client_factory=lambda e: MagicMock(), - ) - svc.scheduler.add_job.assert_called_once() + def test_removes_existing_job(self): + pytest.skip("start_scheduler removed — replaced by AsyncJobRunner") - def test_removes_existing_job(self, svc): - svc._sync_job = MagicMock() - svc._sync_job.id = "existing" + def test_scheduler_already_running(self): + pytest.skip("start_scheduler removed — replaced by AsyncJobRunner") - with patch("src.core.mapping_service.seed_trace_id"): - svc.start_scheduler( - cron_string="0 * * * *", - environments=["env-1"], - superset_client_factory=lambda e: MagicMock(), - ) - svc.scheduler.remove_job.assert_called_once_with("existing") - - def test_scheduler_already_running(self, svc): - type(svc.scheduler).running = PropertyMock(return_value=True) - - with patch("src.core.mapping_service.seed_trace_id"): - svc.start_scheduler( - cron_string="0 * * * *", - environments=["env-1"], - superset_client_factory=lambda e: MagicMock(), - ) - # Should not call start again — just update - svc.scheduler.add_job.assert_called_once() - - def test_skip_sync_if_no_client(self, svc): - with patch("src.core.mapping_service.seed_trace_id"): - svc.start_scheduler( - cron_string="0 * * * *", - environments=["env-1"], - superset_client_factory=lambda e: None, - ) - svc.scheduler.add_job.assert_called_once() + def test_skip_sync_if_no_client(self): + pytest.skip("start_scheduler removed — replaced by AsyncJobRunner") class TestSyncEnvironment: diff --git a/backend/tests/test_core/test_superset_context_extractor_parsing.py b/backend/tests/test_core/test_superset_context_extractor_parsing.py index af816057..168c42db 100644 --- a/backend/tests/test_core/test_superset_context_extractor_parsing.py +++ b/backend/tests/test_core/test_superset_context_extractor_parsing.py @@ -61,28 +61,28 @@ def mock_env(): @pytest.fixture def extractor(mock_env): """Return _TestExtractor with client where: - - Methods called WITH await use AsyncMock - - Methods called WITHOUT await use MagicMock + - Awaited methods use AsyncMock + - Non-awaited methods use MagicMock """ client = MagicMock() # AWAITED in source client.get_dashboard_detail = AsyncMock() client.get_chart = AsyncMock() + client.get_dashboard_permalink_state = AsyncMock() # SYNC calls — MagicMock with sensible return values - client.get_dashboard_permalink_state = MagicMock() client.extract_native_filters_from_key = MagicMock() # get_dataset_detail runs AFTER dataset_id is resolved — always set a default - client.get_dataset_detail = MagicMock( + client.get_dataset_detail = AsyncMock( return_value={"table_name": "users", "schema": "public"} ) return _TestExtractor(environment=mock_env, client=client) def _set_dataset_detail(extractor, return_value=None): - """Helper: set sync get_dataset_detail mock.""" + """Helper: set async get_dataset_detail mock.""" if return_value is None: return_value = {"table_name": "users", "schema": "public"} - extractor.client.get_dataset_detail = MagicMock(return_value=return_value) + extractor.client.get_dataset_detail = AsyncMock(return_value=return_value) def _set_dashboard_detail(extractor, return_value=None): @@ -93,10 +93,10 @@ def _set_dashboard_detail(extractor, return_value=None): def _set_permalink_state(extractor, return_value=None): - """Helper: set sync get_dashboard_permalink_state mock.""" + """Helper: set async get_dashboard_permalink_state mock.""" if return_value is None: return_value = {"state": {"dashboardId": 42}} - extractor.client.get_dashboard_permalink_state = MagicMock( + extractor.client.get_dashboard_permalink_state = AsyncMock( return_value=return_value ) @@ -188,7 +188,7 @@ class TestParseSupersetLinkDataset: @pytest.mark.asyncio async def test_dataset_detail_fetch_fails_partial_recovery(self, extractor): """Dataset detail fetch failure sets partial_recovery=True.""" - extractor.client.get_dataset_detail = MagicMock( + extractor.client.get_dataset_detail = AsyncMock( side_effect=Exception("Superset API timeout") ) result = await extractor.parse_superset_link(self.DATASET_URL) diff --git a/backend/tests/test_core/test_superset_context_extractor_recovery.py b/backend/tests/test_core/test_superset_context_extractor_recovery.py index 5ee596ba..793f4bb8 100644 --- a/backend/tests/test_core/test_superset_context_extractor_recovery.py +++ b/backend/tests/test_core/test_superset_context_extractor_recovery.py @@ -23,7 +23,7 @@ os.environ.setdefault("SECRET_KEY", "test-secret-key-for-testing") os.environ.setdefault("DATABASE_URL", "sqlite:///:memory:") os.environ.setdefault("AUTH_DATABASE_URL", "sqlite:///:memory:") -from unittest.mock import MagicMock, patch +from unittest.mock import AsyncMock, MagicMock, patch import pytest @@ -117,7 +117,7 @@ class TestNormalizeImportedFilterPayload: class TestRecoverImportedFiltersNoDashboard: """recover_imported_filters — when dashboard_id is None.""" - def test_no_dashboard_id_url_filters_only(self, extractor): + async def test_no_dashboard_id_url_filters_only(self, extractor): """Filters from URL state are recovered without dashboard enrichment.""" ctx = SupersetParsedContext( source_url="https://superset.example.com/superset/chart/42", @@ -134,12 +134,12 @@ class TestRecoverImportedFiltersNoDashboard: } ], ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["filter_name"] == "country" assert result[0]["raw_value"] == "US" - def test_empty_url_filters_returns_empty(self, extractor): + async def test_empty_url_filters_returns_empty(self, extractor): """No URL filters returns empty list when no dashboard.""" ctx = SupersetParsedContext( source_url="https://superset.example.com/superset/chart/42", @@ -147,7 +147,7 @@ class TestRecoverImportedFiltersNoDashboard: chart_id=42, resource_type="chart", ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert result == [] @@ -176,9 +176,9 @@ class TestRecoverImportedFiltersWithDashboard: # ── Tests ──────────────────────────────── - def test_dashboard_recovers_native_filters(self, extractor): + async def test_dashboard_recovers_native_filters(self, extractor): """Dashboard with native filter configuration recovers filter entries.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[ { @@ -197,16 +197,16 @@ class TestRecoverImportedFiltersWithDashboard: dashboard_id=5, resource_type="dashboard", ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["filter_name"] == "country_filter" assert result[0]["display_name"] == "Country" assert result[0]["raw_value"] == "US" assert result[0]["recovery_status"] == "recovered" - def test_native_filter_partial_no_default(self, extractor): + async def test_native_filter_partial_no_default(self, extractor): """Native filter without default value gets partial status.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[ {"name": "year_filter", "label": "Year"} @@ -219,14 +219,14 @@ class TestRecoverImportedFiltersWithDashboard: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["recovery_status"] == "partial" assert result[0]["requires_confirmation"] is True - def test_native_filters_merged_with_url_filters(self, extractor): + async def test_native_filters_merged_with_url_filters(self, extractor): """URL-imported filters merge with dashboard metadata.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[ {"name": "country_filter", "label": "Country", "id": "NATIVE-1"} @@ -247,15 +247,15 @@ class TestRecoverImportedFiltersWithDashboard: } ], ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) # Should be 1 entry after merge assert len(result) == 1 # Filter name should be canonicalized from metadata assert result[0]["filter_name"] == "country_filter" - def test_default_filters_as_string_parsed(self, extractor): + async def test_default_filters_as_string_parsed(self, extractor): """default_filters JSON string is parsed.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[ {"name": "f1", "id": "N-1"} @@ -269,12 +269,12 @@ class TestRecoverImportedFiltersWithDashboard: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert result[0]["raw_value"] == "val1" - def test_default_filters_invalid_json_logged(self, extractor): + async def test_default_filters_invalid_json_logged(self, extractor): """Invalid default_filters JSON is caught and logged.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[ {"name": "f1"} @@ -288,13 +288,13 @@ class TestRecoverImportedFiltersWithDashboard: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) # Should not crash, filter has no default assert result[0]["raw_value"] is None - def test_get_dashboard_failure_falls_back(self, extractor): + async def test_get_dashboard_failure_falls_back(self, extractor): """Dashboard fetch failure falls back to URL filters only.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( side_effect=Exception("Dashboard API error") ) ctx = SupersetParsedContext( @@ -310,13 +310,13 @@ class TestRecoverImportedFiltersWithDashboard: } ], ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["filter_name"] == "country" - def test_empty_recovered_filters_adds_fallback(self, extractor): + async def test_empty_recovered_filters_adds_fallback(self, extractor): """No recovered filters adds a fallback entry.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[], ) @@ -327,14 +327,14 @@ class TestRecoverImportedFiltersWithDashboard: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["recovery_status"] == "partial" assert "dashboard_5_filters" in result[0]["filter_name"] - def test_non_dict_item_in_native_config_skipped(self, extractor): + async def test_non_dict_item_in_native_config_skipped(self, extractor): """Non-dict items in native_filter_configuration are skipped.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[ "not_a_dict", @@ -348,13 +348,13 @@ class TestRecoverImportedFiltersWithDashboard: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["filter_name"] == "valid_filter" - def test_json_metadata_as_string_parsed(self, extractor): + async def test_json_metadata_as_string_parsed(self, extractor): """json_metadata as string is parsed (not dict).""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value={ "result": { "json_metadata": json.dumps( @@ -373,13 +373,13 @@ class TestRecoverImportedFiltersWithDashboard: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["filter_name"] == "f1" - def test_empty_filter_name_skipped(self, extractor): + async def test_empty_filter_name_skipped(self, extractor): """Filter with empty name in native configuration is skipped.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value=self._make_dashboard_payload( native_filter_configuration=[ {"name": ""}, @@ -393,7 +393,7 @@ class TestRecoverImportedFiltersWithDashboard: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert len(result) == 1 assert result[0]["filter_name"] == "valid_filter" @@ -406,9 +406,9 @@ class TestRecoverImportedFiltersWithDashboard: class TestRecoveredFilterMerge: """Internal merge_recovered_filter behavior via recover_imported_filters.""" - def test_url_filter_upgraded_by_metadata(self, extractor): + async def test_url_filter_upgraded_by_metadata(self, extractor): """URL filter gets display_name from metadata when missing.""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value={ "result": { "json_metadata": json.dumps( @@ -440,13 +440,13 @@ class TestRecoveredFilterMerge: } ], ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) assert result[0]["display_name"] == "Country" assert result[0]["filter_name"] == "country_filter" - def test_display_name_merged_from_metadata(self, extractor): + async def test_display_name_merged_from_metadata(self, extractor): """Existing filter without display_name gets it from metadata merge (line 60).""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value={ "result": { "json_metadata": json.dumps( @@ -475,14 +475,14 @@ class TestRecoveredFilterMerge: } ], ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) # Metadata filter with display_name should enrich the existing entry entry = next(f for f in result if f["filter_name"] == "country") assert entry["display_name"] == "Country Label" - def test_normalized_value_merged_from_metadata(self, extractor): + async def test_normalized_value_merged_from_metadata(self, extractor): """Existing filter without normalized_value gets it from metadata merge (line 82).""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value={ "result": { "json_metadata": json.dumps( @@ -510,15 +510,15 @@ class TestRecoveredFilterMerge: } ], ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) # Metadata filter merges — after canonicalization "N-1" becomes "status" status = next(f for f in result if f["filter_name"] == "status") # The metadata filter should have been merged with URL entry assert status["display_name"] is not None - def test_json_metadata_non_dict_fallback(self, extractor): + async def test_json_metadata_non_dict_fallback(self, extractor): """json_metadata that is not a dict is reset to empty (line 105).""" - extractor.client.get_dashboard = MagicMock( + extractor.client.get_dashboard = AsyncMock( return_value={ "result": { "json_metadata": 42 # Not a dict or string @@ -531,7 +531,7 @@ class TestRecoveredFilterMerge: dataset_id=10, dashboard_id=5, ) - result = extractor.recover_imported_filters(ctx) + result = await extractor.recover_imported_filters(ctx) # Should not crash, should add fallback since no native filters found assert len(result) == 1 assert result[0]["recovery_status"] == "partial" diff --git a/frontend/src/lib/__tests__/stores.test.ts b/frontend/src/lib/__tests__/stores.test.ts index 0ca3619e..81d1df7f 100644 --- a/frontend/src/lib/__tests__/stores.test.ts +++ b/frontend/src/lib/__tests__/stores.test.ts @@ -25,6 +25,9 @@ vi.mock('$lib/api.js', () => ({ }, })); +const mockLog = vi.fn(); +vi.mock('$lib/cot-logger', () => ({ log: mockLog })); + describe('stores.svelte.ts — store atoms', () => { beforeEach(() => { vi.clearAllMocks(); @@ -126,12 +129,10 @@ describe('stores.svelte.ts — fetch functions', () => { }); it('fetchPlugins logs error and does not throw on API failure', async () => { - const consoleSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); mockGetPlugins.mockRejectedValue(new Error('Network error')); const { fetchPlugins } = await import('../stores.svelte.js'); await expect(fetchPlugins()).resolves.toBeUndefined(); - expect(consoleSpy).toHaveBeenCalled(); - consoleSpy.mockRestore(); + expect(mockLog).toHaveBeenCalledWith(expect.any(String), 'EXPLORE', expect.any(String), undefined, expect.any(String)); }); it('fetchTasks calls api.getTasks and updates tasks store', async () => { @@ -144,12 +145,10 @@ describe('stores.svelte.ts — fetch functions', () => { }); it('fetchTasks logs error and does not throw on API failure', async () => { - const consoleSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); mockGetTasks.mockRejectedValue(new Error('Server error')); const { fetchTasks } = await import('../stores.svelte.js'); await expect(fetchTasks()).resolves.toBeUndefined(); - expect(consoleSpy).toHaveBeenCalled(); - consoleSpy.mockRestore(); + expect(mockLog).toHaveBeenCalledWith(expect.any(String), 'EXPLORE', expect.any(String), undefined, expect.any(String)); }); it('fetchPlugins preserves plugins store when API returns empty array', async () => { diff --git a/frontend/src/lib/auth/store.svelte.ts b/frontend/src/lib/auth/store.svelte.ts index 2b784ff1..230dc4e6 100644 --- a/frontend/src/lib/auth/store.svelte.ts +++ b/frontend/src/lib/auth/store.svelte.ts @@ -17,6 +17,7 @@ // @RELATION BINDS_TO -> Navbar import { browser } from '$app/environment'; +import { log } from '$lib/cot-logger'; // #region AuthState:Interface [TYPE Function] // @ingroup Module @@ -64,7 +65,7 @@ function createAuthStore() { * @param {string} token - The JWT access token. */ function setToken(token: string): void { - console.log("[setToken][Action] Updating token"); + log("AuthStore", "REASON", "Updating auth token"); if (browser) { localStorage.setItem('auth_token', token); } @@ -83,7 +84,7 @@ function createAuthStore() { * @param {any} user - The user profile object. */ function setUser(user: any): void { - console.log("[setUser][Action] Setting user profile"); + log("AuthStore", "REASON", "Setting user profile"); _user = user; _isAuthenticated = !!user; _loading = false; @@ -99,7 +100,7 @@ function createAuthStore() { * @post Auth token removed from localStorage, store reset to initial state. */ function logout(): void { - console.log("[logout][Action] Logging out"); + log("AuthStore", "REASON", "Logging out user"); if (browser) { localStorage.removeItem('auth_token'); } @@ -120,7 +121,7 @@ function createAuthStore() { * @param {boolean} loading - Loading status. */ function setLoading(loading: boolean): void { - console.log(`[setLoading][Action] Setting loading to ${loading}`); + log("AuthStore", "REASON", "Setting loading state", { loading }); _loading = loading; _notify(); } diff --git a/frontend/src/lib/components/MaintenanceSettingsPanel.svelte b/frontend/src/lib/components/MaintenanceSettingsPanel.svelte index f855fa30..f626a8e3 100644 --- a/frontend/src/lib/components/MaintenanceSettingsPanel.svelte +++ b/frontend/src/lib/components/MaintenanceSettingsPanel.svelte @@ -26,6 +26,7 @@ import SearchableMultiSelect from "$lib/components/ui/SearchableMultiSelect.svelte"; import { api } from "$lib/api.js"; import { t } from "$lib/i18n/index.svelte.js"; + import { log } from "$lib/cot-logger"; import HelpTooltip from "$lib/ui/HelpTooltip.svelte"; let isSaving = $state(false); @@ -85,7 +86,7 @@ const data = await api.getDashboards(targetEnvId, { page_size: 100, override_show_all: true }); dashboards = data?.dashboards || []; } catch (e) { - console.error("[EXT:frontend:MaintenanceSettingsPanel] Failed to load dashboards:", e?.message); + log("MaintenanceSettingsPanel", "EXPLORE", "Failed to load dashboards", { targetEnvId }, e?.message || String(e)); } } diff --git a/frontend/src/lib/components/assistant/AssistantChatPanel.svelte b/frontend/src/lib/components/assistant/AssistantChatPanel.svelte index f13a03b4..c0b5841c 100644 --- a/frontend/src/lib/components/assistant/AssistantChatPanel.svelte +++ b/frontend/src/lib/components/assistant/AssistantChatPanel.svelte @@ -30,6 +30,7 @@ import { onMount, onDestroy } from "svelte"; import { goto } from "$app/navigation"; import { ROUTES } from "$lib/routes"; + import { log } from "$lib/cot-logger"; import { t } from "$lib/i18n/index.svelte.js"; import AssistantClarificationCard from "$lib/components/assistant/AssistantClarificationCard.svelte"; import ToolCallCard from "$lib/components/assistant/ToolCallCard.svelte"; @@ -144,12 +145,9 @@ setAssistantConversationId(history.conversation_id); } initialized = true; - console.log("[EXT:frontend:AssistantChatPanel][history][loadHistory:SUCCESS] History loaded"); + log("AssistantChatPanel", "REFLECT", "History loaded"); } catch (err) { - console.error( - "[EXT:frontend:AssistantChatPanel][history][loadHistory:FAILED] Failed to load history", - err, - ); + log("AssistantChatPanel", "EXPLORE", "Failed to load history", {}, err instanceof Error ? err.message : "Unknown"); } finally { loadingHistory = false; } @@ -175,12 +173,9 @@ conversationsHasNext = Boolean(response.has_next); activeConversationsTotal = response.active_total ?? activeConversationsTotal; archivedConversationsTotal = response.archived_total ?? archivedConversationsTotal; - console.log("[EXT:frontend:AssistantChatPanel][conversations][loadConversations:SUCCESS]"); + log("AssistantChatPanel", "REFLECT", "Conversations loaded"); } catch (err) { - console.error( - "[EXT:frontend:AssistantChatPanel][conversations][loadConversations:FAILED]", - err, - ); + log("AssistantChatPanel", "EXPLORE", "Failed to load conversations", {}, err instanceof Error ? err.message : "Unknown"); } finally { loadingConversations = false; } @@ -235,12 +230,9 @@ messages = [...uniqueChunk, ...messages]; historyPage = nextPage; historyHasNext = Boolean(history.has_next); - console.log("[EXT:frontend:AssistantChatPanel][history][loadOlderMessages:SUCCESS]"); + log("AssistantChatPanel", "REFLECT", "Older messages loaded"); } catch (err) { - console.error( - "[EXT:frontend:AssistantChatPanel][history][loadOlderMessages:FAILED]", - err, - ); + log("AssistantChatPanel", "EXPLORE", "Failed to load older messages", {}, err instanceof Error ? err.message : "Unknown"); } finally { loadingMoreHistory = false; } @@ -307,7 +299,7 @@ }); function appendLocalUserMessage(text, targetConversationId = conversationId) { - console.log("[EXT:frontend:AssistantChatPanel][message][appendLocalUserMessage][START]"); + log("AssistantChatPanel", "REASON", "Append local user message"); messages = [ ...messages, { @@ -321,7 +313,7 @@ } function appendAssistantResponse(response, targetConversationId = conversationId) { - console.log("[EXT:frontend:AssistantChatPanel][message][appendAssistantResponse][START]"); + log("AssistantChatPanel", "REASON", "Append assistant response"); messages = [ ...messages, { @@ -362,7 +354,7 @@ } async function handleSend() { - console.log("[EXT:frontend:AssistantChatPanel][message][handleSend][START]"); + log("AssistantChatPanel", "REASON", "Handle send message"); const text = input.trim(); if (!text || loading || agentModel?.isInputLocked) return; @@ -439,7 +431,7 @@ } async function selectConversation(conversation) { - console.log("[EXT:frontend:AssistantChatPanel][conversation][selectConversation][START]"); + log("AssistantChatPanel", "REASON", "Select conversation"); if (!conversation?.conversation_id) return; if (conversation.conversation_id === conversationId) return; historyLoadVersion += 1; @@ -451,7 +443,7 @@ } function startNewConversation() { - console.log("[EXT:frontend:AssistantChatPanel][conversation][startNewConversation][START]"); + log("AssistantChatPanel", "REASON", "Start new conversation"); const newId = typeof crypto !== "undefined" && typeof crypto.randomUUID === "function" ? crypto.randomUUID() @@ -465,7 +457,7 @@ } async function handleAction(action, message) { - console.log("[EXT:frontend:AssistantChatPanel][action][handleAction][START]"); + log("AssistantChatPanel", "REASON", "Handle action"); try { if (action.type === "open_task" && action.target) { openDrawerForTask(action.target); @@ -537,7 +529,7 @@ } function handleKeydown(event) { - console.log("[EXT:frontend:AssistantChatPanel][input][handleKeydown][START]"); + log("AssistantChatPanel", "REASON", "Handle keydown"); if (event.key === "Enter" && !event.shiftKey) { event.preventDefault(); handleSend(); @@ -584,7 +576,7 @@ } function stateClass(state) { - console.log("[EXT:frontend:AssistantChatPanel][ui][stateClass][START]"); + log("AssistantChatPanel", "REASON", "State class lookup"); if (state === "started") return "bg-sky-100 text-sky-700 border-sky-200"; if (state === "success") return "bg-success-light text-success border-success"; if (state === "needs_confirmation") return "bg-warning-light text-warning border-warning"; @@ -594,7 +586,7 @@ } function handleHistoryScroll(event) { - console.log("[EXT:frontend:AssistantChatPanel][scroll][handleHistoryScroll][START]"); + log("AssistantChatPanel", "REASON", "Handle history scroll"); const el = event.currentTarget; if (!el || typeof el.scrollTop !== "number") return; if (el.scrollTop <= 16) { diff --git a/frontend/src/lib/components/backups/BackupManager.svelte b/frontend/src/lib/components/backups/BackupManager.svelte index 38e724e4..a4209d58 100644 --- a/frontend/src/lib/components/backups/BackupManager.svelte +++ b/frontend/src/lib/components/backups/BackupManager.svelte @@ -26,6 +26,7 @@ // [SECTION: IMPORTS] import { onMount, onDestroy } from 'svelte'; import { t } from '$lib/i18n/index.svelte.js'; + import { log } from "$lib/cot-logger"; import { api, requestApi, API_REQUEST_TIMEOUT } from '$lib/api'; import { addToast } from '$lib/toasts.svelte.js'; import { Button, Card, Select, Input } from '$lib/ui'; @@ -90,7 +91,7 @@ } async function loadData() { - console.log("[EXT:frontend:BackupManager][Entry] Loading data."); + log("BackupManager", "REASON", "Loading data"); loading = true; try { const subpath = getSubpath(currentPath); @@ -125,9 +126,9 @@ is_directory: file.mime_type === 'directory', status: 'success' })); - console.log("[EXT:frontend:BackupManager][Action] Data loaded successfully."); + log("BackupManager", "REFLECT", "Data loaded successfully"); } catch (error) { - console.error("[EXT:frontend:BackupManager][Coherence:Failed] Load failed", error); + log("BackupManager", "EXPLORE", "Load failed", {}, error instanceof Error ? error.message : "Unknown"); if (error instanceof DOMException && error.name === 'AbortError') { addToast('Request timed out', 'error'); } else { @@ -162,7 +163,7 @@ async function handleUpdateSchedule() { if (!selectedEnvId) return; - console.log(`[EXT:frontend:BackupManager][Action] Updating schedule for env: ${selectedEnvId}`); + log("BackupManager", "REASON", "Updating schedule for env", { selectedEnvId }); savingSchedule = true; try { await api.updateEnvironmentSchedule(selectedEnvId, { @@ -178,7 +179,7 @@ : e ); } catch (error) { - console.error("[EXT:frontend:BackupManager][Coherence:Failed] Schedule update failed", error); + log("BackupManager", "EXPLORE", "Schedule update failed", {}, error instanceof Error ? error.message : "Unknown"); addToast($t.common.error, 'error'); } finally { savingSchedule = false; @@ -192,16 +193,16 @@ return; } - console.log(`[EXT:frontend:BackupManager][Action] Triggering backup for env: ${selectedEnvId}`); + log("BackupManager", "REASON", "Triggering backup for env", { selectedEnvId }); creating = true; try { await api.createTask('superset-backup', { environment_id: selectedEnvId }, { signal: AbortSignal.timeout(API_REQUEST_TIMEOUT) } ); addToast($t.common.success, 'success'); - console.log("[EXT:frontend:BackupManager][Coherence:OK] Backup task triggered."); + log("BackupManager", "REFLECT", "Backup task triggered"); } catch (error) { - console.error("[EXT:frontend:BackupManager][Coherence:Failed] Create failed", error); + log("BackupManager", "EXPLORE", "Create backup failed", {}, error instanceof Error ? error.message : "Unknown"); if (error instanceof DOMException && error.name === 'AbortError') { addToast('Backup request timed out', 'error'); } else { diff --git a/frontend/src/lib/components/git/CommitHistory.svelte b/frontend/src/lib/components/git/CommitHistory.svelte index 0daea358..fecb1bdb 100644 --- a/frontend/src/lib/components/git/CommitHistory.svelte +++ b/frontend/src/lib/components/git/CommitHistory.svelte @@ -16,6 +16,7 @@ import { t } from '$lib/i18n/index.svelte.js'; import { Button } from '$lib/ui'; import { addToast } from '$lib/toasts.svelte.js'; + import { log } from "$lib/cot-logger"; // [/SECTION] // [SECTION: PROPS] @@ -51,13 +52,13 @@ * @post history state is updated. */ async function loadHistory() { - console.log(`[CommitHistory][Action] Loading history for dashboard ${dashboardId}`); + log("CommitHistory", "REASON", "Loading commit history", { dashboardId }); loading = true; try { history = await gitService.getHistory(dashboardId, 50, envId); - console.log(`[CommitHistory][Coherence:OK] Loaded ${history.length} commits`); + log("CommitHistory", "REFLECT", "Commit history loaded", { count: history.length }); } catch (e) { - console.error(`[CommitHistory][Coherence:Failed] ${e.message}`); + log("CommitHistory", "EXPLORE", "Failed to load commit history", { dashboardId }, e instanceof Error ? e.message : String(e)); addToast('Failed to load commit history', 'error'); } finally { loading = false; diff --git a/frontend/src/lib/components/git/ConflictResolver.svelte b/frontend/src/lib/components/git/ConflictResolver.svelte index 1e56d2c5..416b83f0 100644 --- a/frontend/src/lib/components/git/ConflictResolver.svelte +++ b/frontend/src/lib/components/git/ConflictResolver.svelte @@ -14,6 +14,7 @@ + diff --git a/frontend/src/lib/components/layout/TaskDrawer.svelte b/frontend/src/lib/components/layout/TaskDrawer.svelte index c3198957..914e894e 100644 --- a/frontend/src/lib/components/layout/TaskDrawer.svelte +++ b/frontend/src/lib/components/layout/TaskDrawer.svelte @@ -54,6 +54,7 @@ */ import { onDestroy } from "svelte"; + import { log } from "$lib/cot-logger"; import { taskDrawerStore, closeDrawer } from "$lib/stores/taskDrawer.svelte.js"; import { assistantChatStore } from "$lib/stores/assistantChat.svelte.js"; import TaskLogViewer from "$lib/components/tasks/TaskLogViewer.svelte"; @@ -97,7 +98,7 @@ // Close drawer function handleClose() { - console.log("[TaskDrawer][ui][Close_drawer]"); + log("TaskDrawer", "REASON", "Close drawer"); closeDrawer(); } @@ -179,7 +180,7 @@ const response = await api.getEnvironments(); environmentOptions = Array.isArray(response) ? response : []; } catch (err) { - console.warn("[TaskDrawer][loadEnvironmentOptions][FAILED]", err); + log("TaskDrawer", "EXPLORE", "loadEnvironmentOptions failed", {}, err instanceof Error ? err.message : "Unknown"); environmentOptions = []; } } @@ -413,12 +414,12 @@ const taskId = normalizeTaskId(activeTaskId); const wsUrl = getWsUrl(taskId); - console.log(`[TaskDrawer][Action] Connecting to WebSocket: ${wsUrl}`); + log("TaskDrawer", "REASON", "Connecting to WebSocket", { wsUrl }); ws = new WebSocket(wsUrl); ws.onopen = () => { - console.log("[TaskDrawer][Coherence:OK] WebSocket connected"); + log("TaskDrawer", "REFLECT", "WebSocket connected"); }; ws.onmessage = (event) => { @@ -427,14 +428,14 @@ // ── Task status update from WebSocket ── if (data.type === "task_status") { const taskData = data.task; - console.log(`[TaskDrawer][WebSocket][Status_Update] ${taskData.status}`, taskData); + log("TaskDrawer", "REFLECT", "WebSocket status update", { status: taskData.status }); activeTaskDetails = taskData; taskStatus = taskData.status; return; } // ── Log entry (backward compatible, no type field) ── - console.log(`[TaskDrawer][WebSocket][Log_Received] ${data.message}`); + log("TaskDrawer", "REFLECT", "WebSocket log received", { message: data.message }); realTimeLogs = [...realTimeLogs, data]; if (data.message?.includes("Task completed successfully")) { @@ -445,7 +446,7 @@ }; ws.onerror = (error) => { - console.error("[TaskDrawer][Coherence:Failed] WebSocket error:", error); + log("TaskDrawer", "EXPLORE", "WebSocket error", {}, error instanceof Error ? error.message : "Unknown websocket error"); }; ws.onclose = (event) => { @@ -455,9 +456,9 @@ const isTerminal = taskStatus === "SUCCESS" || taskStatus === "FAILED"; if (isNormalClosure || isTerminal) { - console.log(`[TaskDrawer][WebSocket] Closed normally (code=${event.code}) — stream ended`); + log("TaskDrawer", "REFLECT", "WebSocket closed normally - stream ended", { code: event.code }); } else { - console.log(`[TaskDrawer][WebSocket] Disconnected (code=${event.code}) — reconnecting in 10s`); + log("TaskDrawer", "REASON", "WebSocket disconnected, reconnecting in 10s", { code: event.code }); ws = null; wsReconnectTimer = setTimeout(() => { if (activeTaskId) connectWebSocket(); @@ -476,7 +477,7 @@ * @POST: ws is closed and set to null */ function disconnectWebSocket() { - console.log("[TaskDrawer][WebSocket][disconnectWebSocket:START]"); + log("TaskDrawer", "REASON", "Disconnecting WebSocket"); if (wsReconnectTimer) { clearTimeout(wsReconnectTimer); wsReconnectTimer = null; @@ -499,15 +500,13 @@ async function loadRecentTasks() { loadingTasks = true; try { - console.log("[TaskDrawer][API][loadRecentTasks:STARTED]"); + log("TaskDrawer", "REASON", "Load recent tasks"); // API returns List[Task] directly, not {tasks: [...]} const response = await api.getTasks(); recentTasks = Array.isArray(response) ? response : response.tasks || []; - console.log( - `[TaskDrawer][API][loadRecentTasks:SUCCESS] loaded ${recentTasks.length} tasks`, - ); + log("TaskDrawer", "REFLECT", "Recent tasks loaded", { count: recentTasks.length }); } catch (err) { - console.error("[TaskDrawer][API][loadRecentTasks:FAILED]", err); + log("TaskDrawer", "EXPLORE", "Load recent tasks failed", {}, err instanceof Error ? err.message : "Unknown"); recentTasks = []; } finally { loadingTasks = false; @@ -523,7 +522,7 @@ * @POST: drawer state updated to show task details */ function selectTask(task) { - console.log("[TaskDrawer][UI][selectTask:START]"); + log("TaskDrawer", "REASON", "Select task"); taskDrawerStore.update((state) => ({ ...state, activeTaskId: task.id, @@ -541,14 +540,14 @@ * @POST: Drawer switches to list view and reloads tasks */ function goBackToList() { - console.log("[TaskDrawer][UI][goBackToList:START]"); + log("TaskDrawer", "REASON", "Go back to task list"); taskDrawerStore.update((state) => ({ ...state, activeTaskId: null, })); // Reload the task list loadRecentTasks(); - console.log("[TaskDrawer][UI][goBackToList:SUCCESS]"); + log("TaskDrawer", "REFLECT", "Back to task list"); } // #endregion goBackToList:Function diff --git a/frontend/src/lib/components/layout/TopNavbar.svelte b/frontend/src/lib/components/layout/TopNavbar.svelte index c1d79c4e..9fc7f3b7 100644 --- a/frontend/src/lib/components/layout/TopNavbar.svelte +++ b/frontend/src/lib/components/layout/TopNavbar.svelte @@ -59,6 +59,7 @@ */ import { onMount } from "svelte"; + import { log } from "$lib/cot-logger"; import { goto } from "$app/navigation"; import { ROUTES } from "$lib/routes"; import { api } from "$lib/api.js"; @@ -155,10 +156,7 @@ const autoOpenTaskDrawer = response?.preference?.auto_open_task_drawer; setTaskDrawerAutoOpenPreference(autoOpenTaskDrawer !== false); } catch (error) { - console.warn( - "[EXT:frontend:TopNavbar][REFLECT] Failed to hydrate task drawer preference, fallback to local preference cache", - error, - ); + log("TopNavbar", "EXPLORE", "Failed to hydrate task drawer preference", {}, error instanceof Error ? error.message : String(error)); } } @@ -321,10 +319,7 @@ normalizedQuery, ); } catch (error) { - console.error( - "[EXT:frontend:TopNavbar][Coherence:Failed] Global search failed", - error, - ); + log("TopNavbar", "EXPLORE", "Global search failed", { query: normalizedQuery }, error instanceof Error ? error.message : String(error)); groupedSearchResults = []; } finally { isSearchLoading = false; diff --git a/frontend/src/lib/components/llm/DocPreview.svelte b/frontend/src/lib/components/llm/DocPreview.svelte index 637b07b1..ad2b6e54 100644 --- a/frontend/src/lib/components/llm/DocPreview.svelte +++ b/frontend/src/lib/components/llm/DocPreview.svelte @@ -12,6 +12,7 @@