Фото (тест-режим): детальный отчёт ИИ — время, токены (приём/отдача), скорость ток/сек, детали ошибок

photo_bot/ai_validator.py

@@ -6,6 +6,7 @@ import base64
 import io
 import json
 import logging
+import time
 import urllib.request
 from PIL import Image
 
@@ -55,8 +56,12 @@ def validate_photo_with_ai(file_bytes: bytes) -> dict:
     """
     Прямая проверка фото ИИ (тестовый мод).
 
-    Возвращает {'ok': bool, 'verdict': str, 'reason': str, 'error': str}
+    Возвращает {'ok': bool, 'verdict': str, 'reason': str, 'error': str,
+                'metrics': {'total_time', 'prompt_tokens', 'completion_tokens',
+                            'prompt_per_second', 'predicted_per_second'},
+                'error_time': float}
     """
+    t0 = time.perf_counter()
     try:
         # Сжатие (PIL): разрешение настраивается в config (PHOTO_TEST_AI_MAX_SIDE)
         side = int(config.PHOTO_TEST_AI_MAX_SIDE)
@@ -88,6 +93,18 @@ def validate_photo_with_ai(file_bytes: bytes) -> dict:
 
         with urllib.request.urlopen(req, timeout=config.PHOTO_TEST_AI_TIMEOUT) as resp:
             res = json.loads(resp.read().decode('utf-8'))
+        total_time = time.perf_counter() - t0
+
+        # llama.cpp в ответ кладёт usage (токены) и timings (скорости)
+        usage = res.get('usage') or {}
+        timings = res.get('timings') or {}
+        metrics = {
+            'total_time': total_time,
+            'prompt_tokens': usage.get('prompt_tokens'),
+            'completion_tokens': usage.get('completion_tokens'),
+            'prompt_per_second': timings.get('prompt_per_second'),
+            'predicted_per_second': timings.get('predicted_per_second'),
+        }
 
         full_content = (res['choices'][0]['message'].get('content') or '').strip()
         clean_ans = full_content.split(THINK_CLOSE_TAG)[-1].strip() if THINK_CLOSE_TAG in full_content else full_content.strip()
@@ -114,10 +131,18 @@ def validate_photo_with_ai(file_bytes: bytes) -> dict:
         if not reason:
             reason = clean_ans.replace('\n', ' ').strip()
 
-        logger.info(f"[TEST MODE] ИИ-вердикт: {verdict} | мимика={mimi} | графика={grafika} | {reason}")
+        logger.info(
+            f"[TEST MODE] ИИ-вердикт: {verdict} | мимика={mimi} | графика={grafika} | {reason}"
+            f" | total={metrics['total_time']:.2f}s "
+            f"prompt={metrics['prompt_tokens']}tok/({metrics['prompt_per_second']:.1f} tps) "
+            f"gen={metrics['completion_tokens']}tok/({metrics['predicted_per_second']:.1f} tps)"
+        )
         return {'ok': True, 'verdict': verdict, 'reason': reason, 'error': '',
-                'mimi': mimi, 'grafika': grafika}
+                'mimi': mimi, 'grafika': grafika, 'metrics': metrics}
 
     except Exception as e:
-        logger.error(f"[TEST MODE] Ошибка обращения к ИИ: {e}")
-        return {'ok': False, 'verdict': '', 'reason': '', 'error': str(e)}
+        err = f"{type(e).__name__}: {e}"
+        elapsed = time.perf_counter() - t0
+        logger.error(f"[TEST MODE] Ошибка обращения к ИИ через {elapsed:.1f} сек: {err}")
+        return {'ok': False, 'verdict': '', 'reason': '', 'error': err,
+                'error_time': elapsed}