пофиксил баг отправки уведомлений

This commit is contained in:
vrubelroman 2025-12-06 00:28:53 +03:00
parent 6d51cf135d
commit b3b6a54e2d
5 changed files with 253 additions and 32 deletions

View file

@ -1458,14 +1458,13 @@ class LichessBot:
task_key = f"{gamer['id']}_{user_id}" task_key = f"{gamer['id']}_{user_id}"
username = gamer['username'] username = gamer['username']
# Инициализируем время начала отслеживания как текущее время # НЕ устанавливаем period_start_times при инициализации
# Первая проверка произойдет через period_minutes минут # Это позволит использовать логику первой проверки (else блок)
start_time = datetime.now()
self.period_start_times[task_key] = start_time
logger.info(f"🔄 Started periodic monitoring for {username} (user {user_id}) with {period_minutes} minute intervals") logger.info(f"🔄 Started periodic monitoring for {username} (user {user_id}) with {period_minutes} minute intervals")
consecutive_errors = 0 consecutive_errors = 0
max_consecutive_errors = 5 max_consecutive_errors = 5
is_first_check = True # Флаг для первой проверки
while True: while True:
try: try:
@ -1493,21 +1492,48 @@ class LichessBot:
logger.info(f"Period changed for {gamer['username']} from {period_minutes} to {current_period} minutes") logger.info(f"Period changed for {gamer['username']} from {period_minutes} to {current_period} minutes")
period_minutes = current_period period_minutes = current_period
# Ждем заданное количество минут перед следующей проверкой # Получаем сохраненное время последней проверки для расчета следующего периода
logger.info(f"⏳ Waiting {period_minutes} minutes before next check for {username}") # Используем флаг is_first_check для первой проверки вместо проверки наличия ключа
last_check_time = self.period_start_times.get(task_key)
if is_first_check:
last_check_time = None # Принудительно делаем первую проверку
is_first_check = False
if last_check_time:
# Уже была хотя бы одна проверка
# Рассчитываем, когда должен начаться следующий период
next_period_start = last_check_time + timedelta(minutes=period_minutes)
now = datetime.now()
# Если следующий период еще не наступил, ждем
if next_period_start > now:
wait_seconds = (next_period_start - now).total_seconds()
logger.info(f"⏳ Waiting {wait_seconds:.1f} seconds until next period start ({next_period_start}) for {username}")
await asyncio.sleep(wait_seconds)
# Используем сохраненное время как начало периода
since_time = last_check_time
# Конец периода - это момент, когда должен был начаться следующий период
period_end_approx = next_period_start
logger.info(f"📌 Using saved period: from {since_time} to {period_end_approx}")
else:
# Первая проверка - ждем period_minutes минут от момента запуска
logger.info(f"⏳ First check: waiting {period_minutes} minutes before first check for {username}")
await asyncio.sleep(period_minutes * 60) await asyncio.sleep(period_minutes * 60)
# Получаем текущее время # Получаем текущее время
now = datetime.now() period_end_approx = datetime.now()
# Начало периода - текущее время минус period_minutes
since_time = period_end_approx - timedelta(minutes=period_minutes)
logger.info(f"📌 First check: period from {since_time} to {period_end_approx}")
# Рассчитываем период: от (текущее время - период) до текущего времени
# Это гарантирует, что мы проверяем последний период активности
since_time = now - timedelta(minutes=period_minutes)
since_timestamp = int(since_time.timestamp() * 1000) since_timestamp = int(since_time.timestamp() * 1000)
until_timestamp = int(now.timestamp() * 1000) # Используем приблизительное время как until_timestamp
# После получения ответа пересчитаем фактическое время
until_timestamp_approx = int(period_end_approx.timestamp() * 1000)
logger.info(f"🔍 Checking activity for {username} (user {user_id}): period from {since_time} to {now} (last {period_minutes} minutes)") logger.info(f"🔍 Checking activity for {username} (user {user_id}): period from {since_time} to {period_end_approx} (approx, last {period_minutes} minutes)")
logger.info(f"📅 Unix timestamps: since={since_timestamp}, until={until_timestamp}") logger.info(f"📅 Unix timestamps: since={since_timestamp}, until_approx={until_timestamp_approx}")
# Делаем запросы к API через очередь с обработкой ошибок # Делаем запросы к API через очередь с обработкой ошибок
games_data = None games_data = None
@ -1518,18 +1544,21 @@ class LichessBot:
logger.info(f"📥 Adding games request to queue for {gamer['username']}") logger.info(f"📥 Adding games request to queue for {gamer['username']}")
games_data = await self.request_queue.add_request( games_data = await self.request_queue.add_request(
self.lichess_api.get_games_period, self.lichess_api.get_games_period,
gamer['username'], since_timestamp, until_timestamp gamer['username'], since_timestamp, until_timestamp_approx
) )
logger.info(f"✅ Games API response received for {gamer['username']}") # Фиксируем фактическое время получения ответа
request_end_time = datetime.now()
logger.info(f"✅ Games API response received for {gamer['username']} at {request_end_time}")
except Exception as e: except Exception as e:
logger.error(f"❌ Error getting games data for {gamer['username']}: {e}") logger.error(f"❌ Error getting games data for {gamer['username']}: {e}")
consecutive_errors += 1 consecutive_errors += 1
if consecutive_errors >= max_consecutive_errors: if consecutive_errors >= max_consecutive_errors:
logger.error(f"Too many consecutive errors for {gamer['username']}, stopping periodic check") logger.error(f"Too many consecutive errors for {gamer['username']}, stopping periodic check")
break break
# Продолжаем с обновлением времени начала, чтобы не зацикливаться # Продолжаем с обновлением времени начала на планируемое время окончания периода
now = datetime.now() # чтобы не создавать пропусков в следующих проверках
self.period_start_times[task_key] = now self.period_start_times[task_key] = period_end_approx
logger.warning(f"⚠️ Error occurred, updated period_start_time to {period_end_approx} (planned period end)")
continue continue
if gamer.get('token'): if gamer.get('token'):
@ -1538,9 +1567,11 @@ class LichessBot:
logger.info(f"📥 Adding puzzles request to queue for {gamer['username']}") logger.info(f"📥 Adding puzzles request to queue for {gamer['username']}")
puzzles_data = await self.request_queue.add_request( puzzles_data = await self.request_queue.add_request(
self.lichess_api.get_puzzles_period, self.lichess_api.get_puzzles_period,
gamer['token'], since_timestamp, until_timestamp, 150 gamer['token'], since_timestamp, until_timestamp_approx, 150
) )
logger.info(f"✅ Puzzles API response received for {gamer['username']}") # Обновляем фактическое время после получения ответа по пазлам
request_end_time = datetime.now()
logger.info(f"✅ Puzzles API response received for {gamer['username']} at {request_end_time}")
except Exception as e: except Exception as e:
logger.warning(f"⚠️ Error getting puzzles data for {gamer['username']}: {e}") logger.warning(f"⚠️ Error getting puzzles data for {gamer['username']}: {e}")
# Продолжаем без данных по пазлам # Продолжаем без данных по пазлам
@ -1556,15 +1587,29 @@ class LichessBot:
logger.info(f"📊 Games data structure for {username}: {games_data}") logger.info(f"📊 Games data structure for {username}: {games_data}")
# Проверяем games_count на верхнем уровне (приоритет) # Проверяем games_count на верхнем уровне (приоритет)
if games_data.get('games_count', 0) > 0: top_level_count = games_data.get('games_count', 0)
total_games = games_data.get('games_count', 0) logger.debug(f"🔍 Top-level games_count: {top_level_count}")
if top_level_count > 0:
total_games = top_level_count
has_games = True has_games = True
logger.info(f"✅ Found {total_games} games via games_count field") logger.info(f"✅ Found {total_games} games via games_count field")
else:
# Также проверяем data.total.games_played # Также проверяем data.total.games_played
elif games_data.get('data') and games_data.get('data', {}).get('total', {}).get('games_played', 0) > 0: games_data_dict = games_data.get('data')
total_games = games_data.get('data', {}).get('total', {}).get('games_played', 0) if games_data_dict:
data_total = games_data_dict.get('total', {})
total_games_played = data_total.get('games_played', 0) if data_total else 0
else:
total_games_played = 0
logger.debug(f"🔍 data.total.games_played: {total_games_played}")
if total_games_played > 0:
total_games = total_games_played
has_games = True has_games = True
logger.info(f"✅ Found {total_games} games via data.total.games_played field") logger.info(f"✅ Found {total_games} games via data.total.games_played field")
else:
logger.warning(f"⚠️ No games found: games_count={top_level_count}, data.total.games_played={total_games_played}")
else: else:
logger.warning(f"⚠️ No games_data returned for {username}") logger.warning(f"⚠️ No games_data returned for {username}")
@ -1618,8 +1663,22 @@ class LichessBot:
else: else:
logger.debug(f"⏭️ No activity found for {gamer['username']} in the last {period_minutes} minutes") logger.debug(f"⏭️ No activity found for {gamer['username']} in the last {period_minutes} minutes")
# Всегда обновляем время начала на текущее время после проверки (независимо от наличия активности) # Обновляем время начала следующего периода на ПЛАНИРУЕМОЕ время окончания текущего периода
self.period_start_times[task_key] = now # (period_end_approx), а не на фактическое время завершения запроса (request_end_time).
# Это гарантирует непрерывность периодов без пропусков:
# - Проверяем период A-B
# - Следующая проверка будет периода B-C
# - Без пропусков между A-B и B-C
#
# Использование request_end_time приведет к пропуску диапазона между period_end_approx и request_end_time
#
# period_end_approx уже установлено в начале итерации
self.period_start_times[task_key] = period_end_approx
logger.info(f"📌 Updated period_start_time for {username} to {period_end_approx} (planned period end, next period will start from here)")
if 'request_end_time' in locals():
delay = (request_end_time - period_end_approx).total_seconds()
if delay > 0:
logger.info(f"⏱️ Request completed with {delay:.1f}s delay after planned period end")
except asyncio.CancelledError: except asyncio.CancelledError:
logger.info(f"Periodic check cancelled for {gamer['username']}") logger.info(f"Periodic check cancelled for {gamer['username']}")
@ -1638,6 +1697,17 @@ class LichessBot:
del self.period_start_times[task_key] del self.period_start_times[task_key]
break break
# Важно: обновляем period_start_times даже при ошибке, чтобы не зациклиться на одном периоде
# Используем period_end_approx, если он был установлен, иначе используем текущее время
if 'period_end_approx' in locals():
self.period_start_times[task_key] = period_end_approx
logger.warning(f"⚠️ Error occurred, updated period_start_time to {period_end_approx} to prevent loop")
else:
# Если period_end_approx не был установлен (например, ошибка в начале), используем текущее время
now = datetime.now()
self.period_start_times[task_key] = now
logger.warning(f"⚠️ Error occurred early, updated period_start_time to {now} to prevent loop")
# Ждем перед повторной попыткой при ошибке # Ждем перед повторной попыткой при ошибке
await asyncio.sleep(60) # 1 minute delay before retry await asyncio.sleep(60) # 1 minute delay before retry

144
check_recent_games.py Normal file
View file

@ -0,0 +1,144 @@
#!/usr/bin/env python3
"""Скрипт для проверки недавних игр пользователя через Lichess API"""
import requests
import json
from datetime import datetime, timedelta
import sys
def get_recent_games(username: str, minutes: int = 30):
"""Получить игры за последние N минут"""
# Вычисляем временные метки
now = datetime.now()
since_time = now - timedelta(minutes=minutes)
since_ms = int(since_time.timestamp() * 1000)
until_ms = int(now.timestamp() * 1000)
print(f"🔍 Проверяем игры для {username}")
print(f"⏰ Период: с {since_time.strftime('%Y-%m-%d %H:%M:%S')} до {now.strftime('%Y-%m-%d %H:%M:%S')}")
print(f"📅 Timestamps: since={since_ms}, until={until_ms}")
print()
# Делаем запрос к Lichess API
url = f"https://lichess.org/api/games/user/{username}"
params = {
'since': since_ms,
'until': until_ms,
'max': 1000,
'rated': 'true' # Только рейтинговые
}
headers = {
'Accept': 'application/x-ndjson'
}
try:
response = requests.get(url, params=params, headers=headers, timeout=30)
if response.status_code == 404:
print(f"❌ Пользователь {username} не найден (404)")
return []
elif response.status_code != 200:
print(f"❌ Ошибка API: {response.status_code} - {response.text[:200]}")
return []
# Парсим NDJSON
games = []
content = response.text.strip()
if content:
for line in content.split('\n'):
if line.strip():
try:
game = json.loads(line)
games.append(game)
except json.JSONDecodeError as e:
print(f"⚠️ Ошибка парсинга JSON: {e}")
continue
return games
except Exception as e:
print(f"❌ Ошибка при запросе: {e}")
return []
def format_game_time(created_at_ms: int) -> str:
"""Форматирует время создания игры"""
dt = datetime.fromtimestamp(created_at_ms / 1000)
return dt.strftime('%Y-%m-%d %H:%M:%S')
def main():
username = sys.argv[1] if len(sys.argv) > 1 else "vrubelroman"
minutes = int(sys.argv[2]) if len(sys.argv) > 2 else 40
games = get_recent_games(username, minutes)
if not games:
print("❌ Игры не найдены")
return
print(f"✅ Найдено игр: {len(games)}")
print()
print("=" * 80)
now = datetime.now()
for i, game in enumerate(games, 1):
game_id = game.get('id', 'N/A')
created_at_ms = game.get('createdAt', 0)
speed = game.get('speed', 'unknown')
rated = game.get('rated', False)
# Результат
white = game.get('players', {}).get('white', {})
black = game.get('players', {}).get('black', {})
white_user = white.get('user', {}).get('name', 'N/A')
black_user = black.get('user', {}).get('name', 'N/A')
winner = game.get('winner')
# Определяем результат для пользователя
if white_user == username:
result = "Победа" if winner == "white" else ("Поражение" if winner == "black" else "Ничья")
opponent = black_user
elif black_user == username:
result = "Победа" if winner == "black" else ("Поражение" if winner == "white" else "Ничья")
opponent = white_user
else:
result = "N/A"
opponent = "N/A"
game_time = format_game_time(created_at_ms)
time_ago = now - datetime.fromtimestamp(created_at_ms / 1000)
minutes_ago = int(time_ago.total_seconds() / 60)
print(f"\n🎮 Игра #{i}")
print(f" ID: {game_id}")
print(f" Время: {game_time} ({minutes_ago} минут назад)")
print(f" Скорость: {speed}")
print(f" Рейтинговая: {'Да' if rated else 'Нет'}")
print(f" Соперник: {opponent}")
print(f" Результат: {result}")
# Рейтинг
if white_user == username:
rating_change = white.get('ratingDiff', 0)
final_rating = white.get('rating', 0)
elif black_user == username:
rating_change = black.get('ratingDiff', 0)
final_rating = black.get('rating', 0)
else:
rating_change = 0
final_rating = 0
if rating_change != 0 or final_rating != 0:
print(f" Рейтинг: {final_rating} ({rating_change:+d})")
print()
print("=" * 80)
print(f"\n📊 Всего игр за последние {minutes} минут: {len(games)}")
if __name__ == "__main__":
main()

View file

@ -11,10 +11,11 @@ services:
- ./LichessWebServices:/app - ./LichessWebServices:/app
restart: always restart: always
healthcheck: healthcheck:
test: ["CMD", "curl", "-f", "http://localhost:8000/health"] test: ["CMD", "python", "-c", "import urllib.request; urllib.request.urlopen('http://localhost:8000/health').read()"]
interval: 30s interval: 30s
timeout: 10s timeout: 10s
retries: 3 retries: 3
start_period: 40s
# Telegram Bot # Telegram Bot
lichess-bot: lichess-bot:

0
export_db.sh Normal file → Executable file
View file

6
logs.sh Executable file
View file

@ -0,0 +1,6 @@
GNU nano 6.2 logchecker.sh
# Последние 500 строк, отфильтрованные по периодическим проверкам
docker logs --tail=1000 lichess-telegram-bot 2>&1 | grep -E "periodic|Checking activity|queue|Activity detected"
# Смотреть логи периодических проверок в реальном времени
#docker logs -f lichess-telegram-bot 2>&1 | grep --line-buffered -E "🔄|⏳|🔍|📥|✅|📊|periodic|queue|Activity"
docker logs -f lichess-telegram-bot 2>&1 | grep --line-buffered -E "Checking activity for|Games data structure for"