diff --git a/backend/app.py b/backend/app.py index 15712d87..73312996 100644 --- a/backend/app.py +++ b/backend/app.py @@ -50,7 +50,11 @@ load_dotenv() # CWD .env (fallback) # Set up clean logging for end users from logging_config import configure_logging +<<<<<<< HEAD configure_logging(bootstrap_source="asgi-import") +======= +configure_logging(mode="default", app_name="ALwrity") +>>>>>>> pr-422 # Import middleware from middleware.auth_middleware import get_current_user diff --git a/backend/logging_config.py b/backend/logging_config.py index 4e9bccd3..193bf542 100644 --- a/backend/logging_config.py +++ b/backend/logging_config.py @@ -13,6 +13,7 @@ from loguru import logger _LOGGING_CONFIGURED = False +<<<<<<< HEAD DEFAULT_LOG_OVERRIDES: Dict[str, str] = { "sqlalchemy": "ERROR", "sqlalchemy.engine": "ERROR", @@ -105,6 +106,130 @@ def _apply_logger_overrides(verbose_mode: bool) -> None: "Invalid log level override '{}' for logger '{}'; defaulting to INFO", level_name, logger_name, +======= +_LOGGING_CONFIGURED = False + + +class LoguruInterceptHandler(logging.Handler): + """Forward stdlib logging records to Loguru.""" + + def emit(self, record: logging.LogRecord) -> None: + try: + level = logger.level(record.levelname).name + except ValueError: + level = record.levelno + + frame, depth = logging.currentframe(), 2 + while frame and frame.f_code.co_filename == logging.__file__: + frame = frame.f_back + depth += 1 + + logger.opt(depth=depth, exception=record.exc_info).log(level, record.getMessage()) + + +def configure_logging(mode: str = "default", verbose: bool | None = None, app_name: str = "alwrity") -> bool: + """Configure Loguru and stdlib logging into one shared pipeline.""" + global _LOGGING_CONFIGURED + + if verbose is None: + verbose_mode = mode == "verbose" or os.getenv("ALWRITY_VERBOSE", "false").lower() == "true" + else: + verbose_mode = verbose + + if _LOGGING_CONFIGURED: + return verbose_mode + + logger.remove() + + if not verbose_mode: + # Suppress verbose logging for end users - be more aggressive + logging.getLogger('sqlalchemy.engine').setLevel(logging.CRITICAL) + logging.getLogger('sqlalchemy.pool').setLevel(logging.CRITICAL) + logging.getLogger('sqlalchemy.dialects').setLevel(logging.CRITICAL) + logging.getLogger('sqlalchemy.orm').setLevel(logging.CRITICAL) + logging.getLogger('sqlalchemy').setLevel(logging.CRITICAL) + logging.getLogger('sqlalchemy.engine.Engine').setLevel(logging.CRITICAL) + + # Suppress service initialization logs + logging.getLogger('services').setLevel(logging.WARNING) + logging.getLogger('api').setLevel(logging.WARNING) + logging.getLogger('models').setLevel(logging.WARNING) + + # Suppress specific noisy loggers + noisy_loggers = [ + 'linkedin_persona_service', + 'facebook_persona_service', + 'core_persona_service', + 'persona_analysis_service', + 'ai_service_manager', + 'ai_engine_service', + 'website_analyzer', + 'competitor_analyzer', + 'keyword_researcher', + 'content_gap_analyzer', + 'onboarding_data_service', + 'comprehensive_user_data', + 'strategy_data', + 'gap_analysis_data', + 'phase1_steps', + 'daily_schedule_generator', + 'gsc_service', + 'wordpress_oauth', + 'data_filter', + 'source_mapper', + 'grounding_engine', + 'blog_content_seo_analyzer', + 'linkedin_service', + 'citation_manager', + 'content_analyzer', + 'linkedin_prompt_generator', + 'linkedin_image_storage', + 'hallucination_detector', + 'writing_assistant', + 'onboarding_data_service', + 'enhanced_linguistic_analyzer', + 'persona_quality_improver', + 'logging_middleware', + 'exa_service', + 'step3_research_service', + 'sitemap_service', + 'linkedin_image_generator', + 'linkedin_prompt_generator', + 'linkedin_image_storage', + 'router_manager', + 'frontend_serving', + 'database', + 'user_business_info', + 'auth_middleware', + 'pricing_service', + 'create_billing_tables' + ] + + for logger_name in noisy_loggers: + logging.getLogger(logger_name).setLevel(logging.WARNING) + + # Configure loguru to be less verbose (only show warnings and errors) + def warning_only_filter(record): + return record["level"].name in ["WARNING", "ERROR", "CRITICAL"] + + logger.add( + sys.stdout.write, + level="WARNING", + format=f"{app_name} | {{time:HH:mm:ss}} | {{level: <8}} | {{name}}:{{function}}:{{line}} - {{message}}\n", + filter=warning_only_filter + ) + # Add a focused sink to surface Story Video Generation INFO logs in console + def video_generation_filter(record): + msg = record.get("message", "") + name = record.get("name", "") + service = record.get("extra", {}).get("service") + return ( + "[StoryVideoGeneration]" in msg + or "services.story_writer.video_generation_service" in name + or "[video_gen]" in msg + or service == "video_generation_service" + or "services.llm_providers.main_video_generation" in name +>>>>>>> pr-422 ) logging.getLogger(logger_name).setLevel(level_no) @@ -184,14 +309,20 @@ def _configure_loguru_sinks(verbose_mode: bool) -> None: logger.add( sys.stdout, level="INFO", +<<<<<<< HEAD format=console_format, filter=_video_generation_filter, enqueue=True, +======= + format=f"{app_name} | {{time:HH:mm:ss}} | {{level: <8}} | {{name}}:{{function}}:{{line}} - {{message}}\n", + filter=video_generation_filter +>>>>>>> pr-422 ) log_file = os.getenv("ALWRITY_LOG_FILE", "").strip() if log_file: logger.add( +<<<<<<< HEAD log_file, level="DEBUG" if verbose_mode else "INFO", format=console_format, @@ -272,11 +403,33 @@ def configure_logging(*, verbose_mode: Optional[bool] = None, force: bool = Fals verbose_mode, bootstrap_source, ) +======= + sys.stdout.write, + level="DEBUG", + format=f"{app_name} | {{time:HH:mm:ss}} | {{level: <8}} | {{name}}:{{function}}:{{line}} - {{message}}\n" + ) + + intercept_handler = LoguruInterceptHandler() + root_logger = logging.getLogger() + root_logger.handlers = [intercept_handler] + root_logger.setLevel(logging.DEBUG if verbose_mode else logging.WARNING) + + logging.captureWarnings(True) + warnings_logger = logging.getLogger("py.warnings") + warnings_logger.handlers = [intercept_handler] + warnings_logger.propagate = True + + for existing_logger in logging.root.manager.loggerDict.values(): + if isinstance(existing_logger, logging.Logger): + existing_logger.handlers = [] + existing_logger.propagate = True +>>>>>>> pr-422 _LOGGING_CONFIGURED = True return verbose_mode +<<<<<<< HEAD def bind_logger_context(*, request_id: Optional[str] = None, job_id: Optional[str] = None, user_id: Optional[str] = None): """Return a context-bound logger for request/job/user correlation.""" @@ -295,4 +448,14 @@ def setup_clean_logging() -> bool: def get_uvicorn_log_level() -> str: """Get uvicorn log level based on verbose mode.""" verbose_mode = _env_bool("ALWRITY_VERBOSE", default=False) +======= +def setup_clean_logging(): + """Backward-compatible wrapper for existing startup files.""" + return configure_logging(mode="default") + + +def get_uvicorn_log_level(): + """Get appropriate uvicorn log level based on verbose mode.""" + verbose_mode = os.getenv("ALWRITY_VERBOSE", "false").lower() == "true" +>>>>>>> pr-422 return "debug" if verbose_mode else "warning" diff --git a/backend/main.py b/backend/main.py index f6b59c61..7ba10ae3 100644 --- a/backend/main.py +++ b/backend/main.py @@ -50,7 +50,11 @@ load_dotenv() # CWD .env (fallback) # Set up clean logging for end users from logging_config import configure_logging +<<<<<<< HEAD configure_logging(bootstrap_source="asgi-import") +======= +configure_logging(mode="default", app_name="ALwrity") +>>>>>>> pr-422 # Import middleware from middleware.auth_middleware import get_current_user diff --git a/backend/start_alwrity_backend.py b/backend/start_alwrity_backend.py index e297e13d..6d2076e4 100644 --- a/backend/start_alwrity_backend.py +++ b/backend/start_alwrity_backend.py @@ -228,7 +228,11 @@ def start_backend(enable_reload=False, production_mode=False): log_video_stack_diagnostics = None assert_supported_moviepy = None +<<<<<<< HEAD verbose_mode = configure_logging(verbose_mode=verbose_mode, bootstrap_source="start_alwrity_backend") +======= + verbose_mode = configure_logging(mode="default", app_name="ALwrity") +>>>>>>> pr-422 uvicorn_log_level = get_uvicorn_log_level() # Log diagnostics and assert versions (fail fast if misconfigured)