diff --git a/app/core/logger.py b/app/core/logger.py index 0b0290f..879fc59 100644 --- a/app/core/logger.py +++ b/app/core/logger.py @@ -110,17 +110,19 @@ def setup_logging( # 控制台输出 if json_console: logger.add( - _make_json_sink(sys.stdout), + _make_json_sink(sys.stderr), level=level, format="{message}", colorize=False, + enqueue=True, ) else: logger.add( - sys.stdout, + sys.stderr, level=level, format="{time:YYYY-MM-DD HH:mm:ss} | {level: <8} | {file.name}:{line} - {message}", colorize=True, + enqueue=True, ) # 文件输出 diff --git a/app/services/grok/services/video.py b/app/services/grok/services/video.py index ec47d5d..ff993e8 100644 --- a/app/services/grok/services/video.py +++ b/app/services/grok/services/video.py @@ -5,6 +5,7 @@ Grok video generation service. import asyncio import uuid import re +import time from typing import Any, AsyncGenerator, AsyncIterable, Optional import orjson @@ -1089,10 +1090,20 @@ class VideoStreamProcessor(BaseProcessor): if self.upscale_on_finish: yield self._sse("正在对视频进行超分辨率\n") video_url = await self._upscale_video_url(video_url) + render_started_at = time.perf_counter() + logger.info( + f"Video render pipeline started: video_url={video_url}, " + f"thumbnail_url={thumbnail_url or '-'}, post_id={video_post_id or '-'}" + ) dl_service = self._get_dl() rendered = await dl_service.render_video( video_url, self.token, thumbnail_url ) + render_duration_ms = (time.perf_counter() - render_started_at) * 1000 + logger.info( + f"Video render pipeline completed: rendered={rendered}, " + f"post_id={video_post_id or '-'}, duration_ms={render_duration_ms:.2f}" + ) yield self._sse(rendered) logger.info(f"Video generated: {video_url} (post_id={video_post_id})") @@ -1307,10 +1318,20 @@ class VideoCollectProcessor(BaseProcessor): if video_url: if self.upscale_on_finish: video_url = await self._upscale_video_url(video_url) + render_started_at = time.perf_counter() + logger.info( + f"Video collect render started: video_url={video_url}, " + f"thumbnail_url={thumbnail_url or '-'}, post_id={fallback_video_id or '-'}" + ) dl_service = self._get_dl() content = await dl_service.render_video( video_url, self.token, thumbnail_url ) + render_duration_ms = (time.perf_counter() - render_started_at) * 1000 + logger.info( + f"Video collect render completed: content={content}, " + f"post_id={fallback_video_id or '-'}, duration_ms={render_duration_ms:.2f}" + ) self.video_post_id = fallback_video_id logger.info(f"Video generated: {video_url} (post_id={fallback_video_id})") elif model_resp := resp.get("modelResponse"): @@ -1375,10 +1396,20 @@ class VideoCollectProcessor(BaseProcessor): if asset_video_path: if self.upscale_on_finish: asset_video_path = await self._upscale_video_url(asset_video_path) + render_started_at = time.perf_counter() + logger.info( + f"Video assets fallback render started: video_url={asset_video_path}, " + f"thumbnail_url={(asset_thumb_path or fallback_thumb or '-')}, post_id={fallback_video_id}" + ) dl_service = self._get_dl() content = await dl_service.render_video( asset_video_path, self.token, asset_thumb_path or fallback_thumb ) + render_duration_ms = (time.perf_counter() - render_started_at) * 1000 + logger.info( + f"Video assets fallback render completed: content={content}, " + f"post_id={fallback_video_id}, duration_ms={render_duration_ms:.2f}" + ) response_id = response_id or f"chatcmpl-{uuid.uuid4().hex[:24]}" logger.info( "Video generated via assets fallback: " diff --git a/app/services/grok/utils/download.py b/app/services/grok/utils/download.py index edfb279..8a33e6e 100644 --- a/app/services/grok/utils/download.py +++ b/app/services/grok/utils/download.py @@ -8,6 +8,7 @@ import asyncio import base64 import hashlib import os +import time from pathlib import Path from typing import List, Optional, Tuple from urllib.parse import urlparse @@ -93,10 +94,19 @@ class DownloadService: fmt = fmt.lower() if isinstance(fmt, str) else "url" if fmt not in ("url", "markdown", "html"): fmt = "url" + started_at = time.perf_counter() + logger.info( + f"Render video started: video_url={video_url}, thumbnail_url={thumbnail_url or '-'}, format={fmt}" + ) final_video_url = await self.resolve_url(video_url, token, "video") final_thumb_url = "" if thumbnail_url: final_thumb_url = await self.resolve_url(thumbnail_url, token, "image") + duration_ms = (time.perf_counter() - started_at) * 1000 + logger.info( + f"Render video resolved: final_video_url={final_video_url}, " + f"final_thumbnail_url={final_thumb_url or '-'}, duration_ms={duration_ms:.2f}" + ) if fmt == "url": return final_video_url if fmt == "markdown": @@ -186,11 +196,15 @@ class DownloadService: Returns: Tuple[Optional[Path], str]: The path of the downloaded file and the MIME type. """ + started_at = time.perf_counter() async with _get_download_semaphore(): file_path = self._normalize_path(file_path) cache_dir = self.image_dir if media_type == "image" else self.video_dir filename = file_path.lstrip("/").replace("/", "-") cache_path = cache_dir / filename + logger.info( + f"Download started: media_type={media_type}, file_path={file_path}, cache_path={cache_path}" + ) lock_name = ( f"dl_{media_type}_{hashlib.sha1(str(cache_path).encode()).hexdigest()[:16]}" @@ -199,6 +213,11 @@ class DownloadService: async with _file_lock(lock_name, timeout=lock_timeout): session = await self.create() response = await AssetsDownloadReverse.request(session, token, file_path) + logger.info( + f"Download response received: media_type={media_type}, file_path={file_path}, " + f"status={getattr(response, 'status_code', '-')}, " + f"content_type={(response.headers.get('content-type', 'application/octet-stream').split(';')[0])}" + ) tmp_path = cache_path.with_suffix(cache_path.suffix + ".tmp") try: @@ -220,7 +239,16 @@ class DownloadService: mime = response.headers.get( "content-type", "application/octet-stream" ).split(";")[0] - logger.info(f"Downloaded: {file_path}") + file_size = 0 + try: + file_size = cache_path.stat().st_size + except Exception: + file_size = 0 + duration_ms = (time.perf_counter() - started_at) * 1000 + logger.info( + f"Downloaded: {file_path}, media_type={media_type}, cache_path={cache_path}, " + f"size_bytes={file_size}, mime={mime}, duration_ms={duration_ms:.2f}" + ) asyncio.create_task(self._check_limit()) diff --git a/app/services/token/manager.py b/app/services/token/manager.py index df57155..13e4ac2 100644 --- a/app/services/token/manager.py +++ b/app/services/token/manager.py @@ -255,8 +255,8 @@ class TokenManager: 根据视频需求智能选择 Token 池 路由策略: - - 如果 resolution 是 "720p" 或 video_length > 6: 优先使用 "ssoSuper" 池 - - 否则优先使用 "ssoBasic" 池 + - 当前已放开视频规格限制,不再根据分辨率或时长强制要求 Super 池 + - 默认优先使用 "ssoBasic" 池 - 当提供 pool_candidates 时,按候选池顺序回退 Args: @@ -267,9 +267,9 @@ class TokenManager: Returns: TokenInfo 对象或 None(无可用 token) """ - # 确定首选池 - requires_super = resolution == "720p" or video_length > 6 - primary_pool = SUPER_POOL_NAME if requires_super else BASIC_POOL_NAME + # 已放开视频规格限制:所有视频请求默认优先走 Basic,Super 仅作为回退池。 + requires_super = False + primary_pool = BASIC_POOL_NAME if pool_candidates: ordered_pools = list(pool_candidates) diff --git a/main.py b/main.py index 1178a9c..c400443 100644 --- a/main.py +++ b/main.py @@ -46,15 +46,14 @@ from app.api.v1.video_api import router as video_router from app.api.pages import router as pages_router from fastapi.staticfiles import StaticFiles -# 初始化日志 -setup_logging( - level=os.getenv("LOG_LEVEL", "INFO"), json_console=False, file_logging=True -) - - @asynccontextmanager async def lifespan(app: FastAPI): """应用生命周期管理""" + # 在 worker 启动阶段初始化日志,避免 Granian 下模块导入时绑定的标准流失效。 + setup_logging( + level=os.getenv("LOG_LEVEL", "INFO"), json_console=False, file_logging=True + ) + # 1. 注册服务默认配置 from app.core.config import config, register_defaults from app.services.grok.defaults import get_grok_defaults