diff --git a/app/config_parser.py b/app/config_parser.py index 68fb14b..488d0da 100644 --- a/app/config_parser.py +++ b/app/config_parser.py @@ -1,8 +1,11 @@ import json, os +import logging from app import arg_parser args = arg_parser.ArgParser().parse() +logger = logging.getLogger(__name__) + class ConfigParser: config = None @@ -11,22 +14,71 @@ class ConfigParser: self.loadConfig() def loadConfig(self): - ROOT_DIR = os.path.dirname(os.path.abspath(__file__)) - path = os.path.join(ROOT_DIR, '../config.json') + try: + ROOT_DIR = os.path.dirname(os.path.abspath(__file__)) + path = os.path.join(ROOT_DIR, '../config.json') + logger.info(f"Ruta base del config: {path}") - if args.config: - path = args.config + if args.config: + path = args.config + logger.info(f"Usando ruta de config personalizada: {path}") - with open(path, 'r') as f: - self.config = json.load(f) + if not os.path.exists(path): + error_msg = f"Archivo de configuración no encontrado: {path}" + logger.error(error_msg) + raise FileNotFoundError(error_msg) - if args.geoLatitude: - self.config['geo']['latitude'] = args.geoLatitude - if args.geoLongitude: - self.config['geo']['longitude'] = args.geoLongitude - if args.user: - self.config['user'] = args.user - if args.geoAccuracy: - self.config['geo']['accuracy'] = args.geoAccuracy + logger.info(f"Cargando configuración desde: {path}") + with open(path, 'r', encoding='utf-8') as f: + try: + self.config = json.load(f) + logger.info("Configuración cargada correctamente") + except json.JSONDecodeError as e: + error_msg = f"Error al parsear JSON del archivo de configuración: {str(e)}" + logger.error(error_msg, exc_info=True) + raise ValueError(error_msg) - return self.config \ No newline at end of file + # Validar estructura básica + if not isinstance(self.config, dict): + error_msg = "El archivo de configuración no contiene un objeto JSON válido" + logger.error(error_msg) + raise ValueError(error_msg) + + # Aplicar overrides de argumentos + try: + if args.geoLatitude: + if 'geo' not in self.config: + self.config['geo'] = {} + self.config['geo']['latitude'] = args.geoLatitude + logger.info(f"Latitud sobrescrita por argumento: {args.geoLatitude}") + + if args.geoLongitude: + if 'geo' not in self.config: + self.config['geo'] = {} + self.config['geo']['longitude'] = args.geoLongitude + logger.info(f"Longitud sobrescrita por argumento: {args.geoLongitude}") + + if args.user: + self.config['user'] = args.user + logger.info(f"Usuario sobrescrito por argumento: {args.user}") + + if args.geoAccuracy: + if 'geo' not in self.config: + self.config['geo'] = {} + self.config['geo']['accuracy'] = args.geoAccuracy + logger.info(f"Precisión geográfica sobrescrita por argumento: {args.geoAccuracy}") + except Exception as e: + logger.warning(f"Error al aplicar overrides de argumentos: {str(e)}") + + logger.info("Configuración procesada correctamente") + return self.config + except FileNotFoundError as e: + logger.error(f"Archivo de configuración no encontrado: {str(e)}", exc_info=True) + raise + except json.JSONDecodeError as e: + logger.error(f"Error de sintaxis JSON en configuración: {str(e)}", exc_info=True) + raise + except Exception as e: + error_msg = f"Error inesperado al cargar configuración: {str(e)}" + logger.error(error_msg, exc_info=True) + raise \ No newline at end of file diff --git a/app/google_calendar.py b/app/google_calendar.py index 99f3093..9bb8384 100644 --- a/app/google_calendar.py +++ b/app/google_calendar.py @@ -1,4 +1,5 @@ import google.oauth2.credentials +import logging from google.auth.transport.requests import Request from google.oauth2.credentials import Credentials @@ -11,51 +12,120 @@ from dateutil.relativedelta import relativedelta import os +logger = logging.getLogger(__name__) + class GoogleCalendar: def __init__(self): - self.creds = None - self.service = None - self.SCOPES = ['https://www.googleapis.com/auth/calendar.readonly'] - self.authfile = os.path.join(os.path.dirname(__file__), '../googleoauth.json') - self.grantfile = os.path.join(os.path.dirname(__file__), '../googleoauth_grant.json') + try: + logger.info("Inicializando GoogleCalendar...") + self.creds = None + self.service = None + self.SCOPES = ['https://www.googleapis.com/auth/calendar.readonly'] + self.authfile = os.path.join(os.path.dirname(__file__), '../googleoauth.json') + self.grantfile = os.path.join(os.path.dirname(__file__), '../googleoauth_grant.json') + + logger.info(f"Auth file: {self.authfile}, Grant file: {self.grantfile}") - if os.path.exists(self.authfile): - try: - self.creds = Credentials.from_authorized_user_file(self.authfile, self.SCOPES) - except ValueError as error: - print(error) + if os.path.exists(self.authfile): + try: + logger.info("Cargando credenciales desde archivo...") + self.creds = Credentials.from_authorized_user_file(self.authfile, self.SCOPES) + logger.info("Credenciales cargadas correctamente") + except ValueError as error: + logger.error(f"Error al cargar credenciales: {error}", exc_info=True) + print(f"Error al cargar credenciales: {error}") + except Exception as e: + logger.error(f"Error inesperado al cargar credenciales: {str(e)}", exc_info=True) + print(f"Error inesperado al cargar credenciales: {str(e)}") + else: + logger.info("No se encontró archivo de credenciales, se solicitará autenticación") - self.checkAuth() - self.buildService() + logger.info("Verificando autenticación...") + self.checkAuth() + logger.info("Construyendo servicio...") + self.buildService() + logger.info("GoogleCalendar inicializado correctamente") + except Exception as e: + logger.error(f"Error al inicializar GoogleCalendar: {str(e)}", exc_info=True) + print(f"Error al inicializar GoogleCalendar: {str(e)}") + raise def serverAuth(self): - flow = InstalledAppFlow.from_client_secrets_file(self.grantfile, self.SCOPES) - self.creds = flow.run_local_server(port=0) + try: + logger.info("Iniciando autenticación del servidor...") + if not os.path.exists(self.grantfile): + error_msg = f"Archivo de grant no encontrado: {self.grantfile}" + logger.error(error_msg) + raise FileNotFoundError(error_msg) + + flow = InstalledAppFlow.from_client_secrets_file(self.grantfile, self.SCOPES) + self.creds = flow.run_local_server(port=0) + logger.info("Autenticación del servidor completada") + except FileNotFoundError as e: + logger.error(f"Archivo de grant no encontrado: {str(e)}", exc_info=True) + raise + except Exception as e: + logger.error(f"Error durante autenticación del servidor: {str(e)}", exc_info=True) + raise def saveAuth(self): - with open(self.authfile, 'w') as token: - token.write(self.creds.to_json()) + try: + logger.info("Guardando credenciales...") + with open(self.authfile, 'w') as token: + token.write(self.creds.to_json()) + logger.info("Credenciales guardadas correctamente") + except Exception as e: + logger.error(f"Error al guardar credenciales: {str(e)}", exc_info=True) + raise def refreshAuth(self): - self.creds.refresh(Request()) + try: + logger.info("Refrescando credenciales...") + self.creds.refresh(Request()) + logger.info("Credenciales refrescadas correctamente") + except google.oauth2.credentials.exceptions.RefreshError as e: + logger.warning(f"Error al refrescar credenciales: {str(e)}") + raise + except Exception as e: + logger.error(f"Error inesperado al refrescar credenciales: {str(e)}", exc_info=True) + raise def checkAuth(self): - if not self.creds or not self.creds.valid: - if self.creds and self.creds.expired and self.creds.refresh_token: - try: - self.refreshAuth() - except google.oauth2.credentials.exceptions.RefreshError as rerror: + try: + logger.info("Verificando estado de autenticación...") + if not self.creds or not self.creds.valid: + logger.info("Credenciales no válidas o no existentes") + if self.creds and self.creds.expired and self.creds.refresh_token: + try: + logger.info("Intentando refrescar credenciales expiradas...") + self.refreshAuth() + except google.oauth2.credentials.exceptions.RefreshError as rerror: + logger.warning(f"No se pudo refrescar credenciales: {str(rerror)}, solicitando nueva autenticación") + self.serverAuth() + except Exception as e: + logger.error(f"Error inesperado al refrescar: {str(e)}", exc_info=True) + self.serverAuth() + else: + logger.info("Solicitando nueva autenticación...") self.serverAuth() - else: - self.serverAuth() - self.saveAuth() + logger.info("Guardando credenciales después de autenticación...") + self.saveAuth() + else: + logger.info("Credenciales válidas") + except Exception as e: + logger.error(f"Error durante checkAuth: {str(e)}", exc_info=True) + raise def buildService(self): - self.service = build('calendar', 'v3', credentials=self.creds) - # self.service.calendars().get(calendarId='e51d3bfb6b352c48afb8bd7a5d494599cc3eaa686800a856796306f50c6d72fd@group.calendar.google.com') - # self.service.create_notification_channel() + try: + logger.info("Construyendo servicio de Google Calendar...") + self.service = build('calendar', 'v3', credentials=self.creds) + logger.info("Servicio de Google Calendar construido correctamente") + except Exception as e: + logger.error(f"Error al construir servicio de Google Calendar: {str(e)}", exc_info=True) + raise def getNow(self): return datetime.utcnow().strftime('%Y-%m-%dT00:00:00Z') @@ -65,43 +135,88 @@ class GoogleCalendar: def getEvent(self): try: + logger.info("Obteniendo eventos de Google Calendar...") now = self.getNow() now_after_one_day = self.getNowAfterOneDay() + logger.info(f"Buscando eventos entre {now} y {now_after_one_day}") - events_result_autoficher = self.service.events().list( - calendarId='e51d3bfb6b352c48afb8bd7a5d494599cc3eaa686800a856796306f50c6d72fd@group.calendar.google.com', - timeMin=now, - timeMax=now_after_one_day, maxResults=10, singleEvents=True, - orderBy='startTime').execute() - events_result_holiday = self.service.events().list( - calendarId='es.spain#holiday@group.v.calendar.google.com', - timeMin=now, - timeMax=now_after_one_day, - maxResults=10, singleEvents=True, - orderBy='startTime').execute() + try: + logger.info("Consultando calendario autoficher...") + events_result_autoficher = self.service.events().list( + calendarId='e51d3bfb6b352c48afb8bd7a5d494599cc3eaa686800a856796306f50c6d72fd@group.calendar.google.com', + timeMin=now, + timeMax=now_after_one_day, maxResults=10, singleEvents=True, + orderBy='startTime').execute() + logger.info(f"Eventos de autoficher obtenidos: {len(events_result_autoficher.get('items', []))}") + except HttpError as e: + logger.error(f"Error HTTP al consultar calendario autoficher: {str(e)}", exc_info=True) + events_result_autoficher = {'items': []} + except Exception as e: + logger.error(f"Error inesperado al consultar calendario autoficher: {str(e)}", exc_info=True) + events_result_autoficher = {'items': []} + + try: + logger.info("Consultando calendario de festivos...") + events_result_holiday = self.service.events().list( + calendarId='es.spain#holiday@group.v.calendar.google.com', + timeMin=now, + timeMax=now_after_one_day, + maxResults=10, singleEvents=True, + orderBy='startTime').execute() + logger.info(f"Eventos de festivos obtenidos: {len(events_result_holiday.get('items', []))}") + except HttpError as e: + logger.warning(f"Error HTTP al consultar calendario de festivos (puede ser normal): {str(e)}") + events_result_holiday = {'items': []} + except Exception as e: + logger.warning(f"Error inesperado al consultar calendario de festivos: {str(e)}") + events_result_holiday = {'items': []} events = events_result_autoficher.get('items', []) + events_result_holiday.get('items', []) + logger.info(f"Total de eventos encontrados: {len(events)}") if not events: + logger.info("No se encontraron eventos") return False # Prints the start and name of the next 10 events for event in events: - start = event['start'].get('dateTime', event['start'].get('date')) - end = event['end'].get('dateTime', event['end'].get('date')) + try: + start = event['start'].get('dateTime', event['start'].get('date')) + end = event['end'].get('dateTime', event['end'].get('date')) + logger.debug(f"Evaluando evento: {event.get('summary', 'Sin título')} - {start} a {end}") - if datetime.fromisoformat(start).timestamp() <= datetime.now().timestamp() <= datetime.fromisoformat( - end).timestamp(): - if event['organizer']['displayName'] == 'autoficher': - return 'Forzado desde autoficher - ' + event.get("summary", "Sin Título") + if datetime.fromisoformat(start).timestamp() <= datetime.now().timestamp() <= datetime.fromisoformat( + end).timestamp(): + logger.info(f"Evento activo encontrado: {event.get('summary', 'Sin título')}") + if event.get('organizer', {}).get('displayName') == 'autoficher': + result = 'Forzado desde autoficher - ' + event.get("summary", "Sin Título") + logger.info(f"Evento de autoficher activo: {result}") + return result - #Desactivado por que no funcionaba muy bien ese calendario... se han puesto en el calendario autoficher los dias festivos correctos - #if 'description' in event and ("Cataluña" in event['description'] or 'Día festivo' in event[ - # 'description'] or 'Celebración\n' in event['description']) and not 'Cambio de horario' in event[ - # 'summary']: - # return event['summary'] + #Desactivado por que no funcionaba muy bien ese calendario... se han puesto en el calendario autoficher los dias festivos correctos + #if 'description' in event and ("Cataluña" in event['description'] or 'Día festivo' in event[ + # 'description'] or 'Celebración\n' in event['description']) and not 'Cambio de horario' in event[ + # 'summary']: + # return event['summary'] + except KeyError as e: + logger.warning(f"Evento sin campo requerido: {str(e)}, evento: {event.get('summary', 'Sin título')}") + continue + except ValueError as e: + logger.warning(f"Error al parsear fecha del evento: {str(e)}, evento: {event.get('summary', 'Sin título')}") + continue + except Exception as e: + logger.warning(f"Error al procesar evento: {str(e)}, evento: {event.get('summary', 'Sin título')}") + continue + + logger.info("No se encontraron eventos activos") + return False except HttpError as error: + error_msg = f'Error HTTP de Google Calendar: {error}' + logger.error(error_msg, exc_info=True) print(f'An error occurred: {error}') - return 'Error de llama a Google Calendar' - - return False + return 'Error de llamada a Google Calendar' + except Exception as e: + error_msg = f'Error inesperado en getEvent: {str(e)}' + logger.error(error_msg, exc_info=True) + print(f'Error inesperado: {error_msg}') + return 'Error de llamada a Google Calendar' diff --git a/app/telegram_bot.py b/app/telegram_bot.py index 92b8715..40f7c1f 100644 --- a/app/telegram_bot.py +++ b/app/telegram_bot.py @@ -2,37 +2,86 @@ from app import config_parser import telegram from importlib.metadata import version import asyncio +import logging config = config_parser.ConfigParser().loadConfig() +logger = logging.getLogger(__name__) + class telegramBot: bot = None async def sendMessage(self, message): - ver = version("python-telegram-bot") - major = int(ver.split(".")[0]) + try: + logger.info(f"Preparando envío de mensaje por Telegram (longitud: {len(str(message))} caracteres)") + + ver = version("python-telegram-bot") + major = int(ver.split(".")[0]) + logger.info(f"Versión de python-telegram-bot: {ver} (major: {major})") + token = config.get("telegram", {}).get("token") + chat_id = config.get("telegram", {}).get("chat_id") + + if not token: + error_msg = "Token de Telegram no configurado" + logger.error(error_msg) + print(f"Error: {error_msg}") + return + + if not chat_id: + error_msg = "Chat ID de Telegram no configurado" + logger.error(error_msg) + print(f"Error: {error_msg}") + return - token = config["telegram"]["token"] - chat_id = config["telegram"]["chat_id"] + # -------------------- + # PTB v20+ (async) + # -------------------- + if major >= 20: + logger.info("Usando API async de python-telegram-bot v20+") + try: + self.bot = telegram.Bot(token) + await self.bot.send_message(chat_id=chat_id, text=str(message)) + logger.info("Mensaje enviado correctamente por Telegram (v20+)") + return + except telegram.error.TelegramError as e: + error_msg = f"Error de Telegram API al enviar mensaje (v20+): {str(e)}" + logger.error(error_msg, exc_info=True) + print(f"Error: {error_msg}") + raise + except Exception as e: + error_msg = f"Error inesperado al enviar mensaje por Telegram (v20+): {str(e)}" + logger.error(error_msg, exc_info=True) + print(f"Error: {error_msg}") + raise - # -------------------- - # PTB v20+ (async) - # -------------------- - if major >= 20: - self.bot = telegram.Bot(token) - await self.bot.send_message(chat_id=chat_id, text=str(message)) - return + # -------------------- + # PTB v12/v13 (sync) + # -------------------- + else: + logger.info("Usando API sync de python-telegram-bot v12/v13") + try: + self.bot = telegram.Bot(token) - # -------------------- - # PTB v12/v13 (sync) - # -------------------- - else: - self.bot = telegram.Bot(token) - - # ejecuta el método sync en un hilo para no romper asyncio.run() - loop = asyncio.get_running_loop() - await loop.run_in_executor( - None, - lambda: self.bot.send_message(chat_id=chat_id, text=str(message)) - ) + # ejecuta el método sync en un hilo para no romper asyncio.run() + loop = asyncio.get_running_loop() + await loop.run_in_executor( + None, + lambda: self.bot.send_message(chat_id=chat_id, text=str(message)) + ) + logger.info("Mensaje enviado correctamente por Telegram (v12/v13)") + except telegram.error.TelegramError as e: + error_msg = f"Error de Telegram API al enviar mensaje (v12/v13): {str(e)}" + logger.error(error_msg, exc_info=True) + print(f"Error: {error_msg}") + raise + except Exception as e: + error_msg = f"Error inesperado al enviar mensaje por Telegram (v12/v13): {str(e)}" + logger.error(error_msg, exc_info=True) + print(f"Error: {error_msg}") + raise + except Exception as e: + error_msg = f"Error crítico al enviar mensaje por Telegram: {str(e)}" + logger.error(error_msg, exc_info=True) + print(f"Error crítico: {error_msg}") + # No re-lanzamos la excepción para evitar que rompa el flujo principal diff --git a/app/timenet_manager.py b/app/timenet_manager.py index 7714ddb..2b201f6 100644 --- a/app/timenet_manager.py +++ b/app/timenet_manager.py @@ -1,4 +1,5 @@ import asyncio +import logging import requests, json, pytz from datetime import datetime @@ -11,71 +12,167 @@ config = config_parser.ConfigParser().loadConfig() from app import strings +# Configurar logging +logging.basicConfig( + level=logging.INFO, + format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', + datefmt='%Y-%m-%d %H:%M:%S' +) +logger = logging.getLogger(__name__) + class timenetManager: telegram = None message_acumulator = "" headers = {} def __init__(self): - self.telegram = telegram_bot.telegramBot() + try: + logger.info("Inicializando timenetManager...") + self.telegram = telegram_bot.telegramBot() + logger.info("Telegram bot inicializado correctamente") - if args.pin is None: - # if pin is None, prompt for it - args.pin = int(input("Introduzca su pin: ")) + if args.pin is None: + # if pin is None, prompt for it + logger.info("PIN no proporcionado, solicitando al usuario...") + args.pin = int(input("Introduzca su pin: ")) + logger.info("PIN recibido") - self.headers = { - "Content-type": "application/x-www-form-urlencoded; charset=UTF-8", - "Accept": "application/json, text/plain, */*", - "Referer": "https://timenet-wcp.gpisoftware.com/", - "Sec-Ch-Ua-Mobile": "?0", - "Sec-Ch-Ua-Platform": "\"Linux\"", - "Sec-Ch-Ua": "\"Chromium\";v=\"138\", \"Not=A?Brand\";v=\"8\", \"Google Chrome\";v=\"138\"", - "Sec-Fetch-Dest": "empty", - "Sec-Fetch-Mode": "cors", - "Sec-Fetch-Site": "same-origin", - strings.tnv_string: "wcp_8.0.0.2", - "User-Agent": strings.user_agent, - "Tn-U": strings.tn_u - } - self.login() + self.headers = { + "Content-type": "application/x-www-form-urlencoded; charset=UTF-8", + "Accept": "application/json, text/plain, */*", + "Referer": "https://timenet-wcp.gpisoftware.com/", + "Sec-Ch-Ua-Mobile": "?0", + "Sec-Ch-Ua-Platform": "\"Linux\"", + "Sec-Ch-Ua": "\"Chromium\";v=\"138\", \"Not=A?Brand\";v=\"8\", \"Google Chrome\";v=\"138\"", + "Sec-Fetch-Dest": "empty", + "Sec-Fetch-Mode": "cors", + "Sec-Fetch-Site": "same-origin", + strings.tnv_string: "wcp_8.0.0.2", + "User-Agent": strings.user_agent, + "Tn-U": strings.tn_u + } + logger.info("Headers configurados, iniciando login...") + self.login() + logger.info("timenetManager inicializado correctamente") + except Exception as e: + error_msg = f"Error al inicializar timenetManager: {str(e)}" + logger.error(error_msg, exc_info=True) + try: + asyncio.run(self.telegram.sendMessage(f"🟥🕐 {error_msg}")) + except: + pass + raise def get(self, url, data={}, headers={}): - furl = config['api_url'] + url - if url != "version": - furl = config['api_url'] + "v1/" + url + try: + furl = config['api_url'] + url + if url != "version": + furl = config['api_url'] + "v1/" + url - print("[GET] %s con headers %s y data %s" % (furl, headers, data)) - return requests.get(furl, data=data, headers=headers) + logger.info(f"[GET] {furl} con headers {headers} y data {data}") + print("[GET] %s con headers %s y data %s" % (furl, headers, data)) + + response = requests.get(furl, data=data, headers=headers, timeout=30) + logger.info(f"[GET] Respuesta recibida: status_code={response.status_code}") + return response + except requests.exceptions.Timeout as e: + error_msg = f"Timeout al hacer GET a {url}: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise + except requests.exceptions.RequestException as e: + error_msg = f"Error de conexión al hacer GET a {url}: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise + except Exception as e: + error_msg = f"Error inesperado al hacer GET a {url}: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise def post(self, url, data={}, headers={}): - furl = config['api_url'] + url - if url != "version": - furl = config['api_url'] + "v1/" + url + try: + furl = config['api_url'] + url + if url != "version": + furl = config['api_url'] + "v1/" + url - print("[POST] %s con headers %s y data %s" % (furl, headers, data)) - return requests.post(furl, data=data, headers=headers) + logger.info(f"[POST] {furl} con headers {headers} y data {data}") + print("[POST] %s con headers %s y data %s" % (furl, headers, data)) + + response = requests.post(furl, data=data, headers=headers, timeout=30) + logger.info(f"[POST] Respuesta recibida: status_code={response.status_code}, text={response.text[:200]}") + return response + except requests.exceptions.Timeout as e: + error_msg = f"Timeout al hacer POST a {url}: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise + except requests.exceptions.RequestException as e: + error_msg = f"Error de conexión al hacer POST a {url}: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise + except Exception as e: + error_msg = f"Error inesperado al hacer POST a {url}: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise def login(self): - self.updateTime() + try: + logger.info(f"Iniciando login para usuario: {config.get('user', 'N/A')}") + self.updateTime() - response = self.post("cp/login/" + config['user'], { - "p": args.pin, - }, self.headers) - - if response.status_code != 200: - print("Error al iniciar sesión: %s" % response.text) - exit(20) + response = self.post("cp/login/" + config['user'], { + "p": args.pin, + }, self.headers) + + logger.info(f"Login response status: {response.status_code}") + + if response.status_code != 200: + error_msg = f"Error al iniciar sesión: status_code={response.status_code}, response={response.text}" + logger.error(error_msg) + print("Error al iniciar sesión: %s" % response.text) + self.addMessage(f"🟥🕐 Error al iniciar sesión: {response.text}") + self.sendReport() + exit(20) - self.headers["Token"] = response.text.replace("\"", "") + token = response.text.replace("\"", "") + self.headers["Token"] = token + logger.info("Login exitoso, token obtenido") + except Exception as e: + error_msg = f"Error durante el login: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise def addMessage(self, message): self.message_acumulator += message + "\n" def sendReport(self): - # self.telegram.sendMessage(self.message_acumulator) - asyncio.run(self.telegram.sendMessage(self.message_acumulator)) - self.message_acumulator = "" + try: + if self.message_acumulator.strip(): + logger.info(f"Enviando reporte por Telegram: {self.message_acumulator[:100]}...") + asyncio.run(self.telegram.sendMessage(self.message_acumulator)) + logger.info("Reporte enviado correctamente") + else: + logger.debug("No hay mensajes para enviar") + self.message_acumulator = "" + except Exception as e: + error_msg = f"Error al enviar reporte por Telegram: {str(e)}" + logger.error(error_msg, exc_info=True) + print(f"Error al enviar mensaje por Telegram: {error_msg}") + # No acumulamos este error para evitar loops infinitos + self.message_acumulator = "" def updateTime(self): now = datetime.now().astimezone(pytz.UTC) @@ -93,96 +190,208 @@ class timenetManager: return self.get('check/info?guid=' + config['user'], {}, self.headers) def checkLastCheck(self, typ): - response = self.get('cp/checks?start=' + datetime.now().strftime("%d/%m/%Y") + '&end=' + datetime.now().strftime("%d/%m/%Y"), {}, self.headers) - if response.status_code != 200: - self.addMessage("Error al obtener los checks: %s" % response.text) + try: + logger.info(f"Verificando último check de tipo {typ}") + date_str = datetime.now().strftime("%d/%m/%Y") + url = f'cp/checks?start={date_str}&end={date_str}' + logger.info(f"Consultando checks para fecha: {date_str}") + + response = self.get(url, {}, self.headers) + + if response.status_code != 200: + error_msg = f"Error al obtener los checks: status_code={response.status_code}, response={response.text}" + logger.error(error_msg) + self.addMessage(f"🟥🕐 Error al obtener los checks: {response.text}") + self.sendReport() + return False + + try: + today_checks = json.loads(response.text) + logger.info(f"Checks obtenidos: {today_checks}") + except json.JSONDecodeError as e: + error_msg = f"Error al parsear JSON de checks: {str(e)}, response={response.text}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 Error al procesar los checks: {str(e)}") + self.sendReport() + return False + + if today_checks.get('C') and today_checks['C'][0] and today_checks['C'][0].get('C') and today_checks['C'][0]['C'] and today_checks['C'][0]['C'][-1] and today_checks['C'][0]['C'][-1].get('T') == typ: + hora = today_checks['C'][0]['C'][-1].get('H', 'N/A') + logger.info(f"Ya se ha realizado este marcaje antes a las {hora}") + self.addMessage(f"🟥🕐 Ya se ha realizado este marcaje antes a las {hora}") + self.sendReport() + return True + + logger.info("No se encontró un check previo del mismo tipo") + return False + except Exception as e: + error_msg = f"Error inesperado al verificar último check: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") self.sendReport() return False - - - today_checks = json.loads(response.text) - if today_checks['C'] and today_checks['C'][0] and today_checks['C'][0]['C'] and today_checks['C'][0]['C'][-1] and today_checks['C'][0]['C'][-1]['T'] == typ: - self.addMessage("Ya se ha realizado este marcaje antes a las %s" % today_checks['C'][0]['C'][-1]['H']) - self.sendReport() - return True - - - return False def sendUpdate(self): - - calendar = google_calendar.GoogleCalendar() - calendar = calendar.getEvent() - if calendar and not args.force: - self.addMessage("🟥🕐 Comprobación de calendario: " + calendar) - self.sendReport() - return - - typ = 0 - if args.basedtime and not args.type: - hour = datetime.now().strftime("%H") - - hIN = config['in_hours'] - - hOUT = config['out_hours'] - - if hour in hIN: - typ = 0 - elif hour in hOUT: - typ = 1 - else: - self.addMessage("No se ha fichado ni desfichado ya que estamos en horario laboral, fuerze el estado con el parametro --type <0 = Entrada, 1 = Salida>") - else: - typ = args.type - - - if self.checkLastCheck(typ): - return; - - response = None - if not args.debug: - self.addMessage("####HACIENDO CHECK####") - rand = utils.numero_aleatorio_con_probabilidad(230, 0.5) - self.addMessage("Esperando %s segundos para %s en un minuto aleatorio" % (rand,strings.conditional_response[int(typ)]["text2"])) - self.sendReport() - sleep(rand) - self.updateTime() - data = { - "typ": typ, - "date": self.headers[strings.tnd_string], - "geoLatitude": config['geo']['latitude'], - "geoLongitude": config['geo']['longitude'], - "geoError": "", - "dStr": self.headers["dStr"].replace("\"", "") - } - response = self.post("cp/checks", data, self.headers) - else: - self.addMessage('Corriendo en modo debug. No se realizará ninguna acción') - self.sendReport() - exit(20) - - if response.text == "no valid worker": - self.addMessage("El trabajador no ha podido ser identificado") - self.sendReport() - exit(20) - try: - rj = json.loads(response.text) - except: - self.addMessage("La respuesta al hacer check no es correcta... algo ha pasado :/ - %s - %s" % (response.text, response.status_code)) - self.sendReport() - exit(20) + logger.info("Iniciando sendUpdate...") + + # Verificar calendario + try: + logger.info("Consultando Google Calendar...") + calendar = google_calendar.GoogleCalendar() + calendar_event = calendar.getEvent() + logger.info(f"Resultado de calendario: {calendar_event}") + + if calendar_event and not args.force: + logger.info(f"Evento de calendario encontrado: {calendar_event}, cancelando fichaje") + self.addMessage("🟥🕐 Comprobación de calendario: " + calendar_event) + self.sendReport() + return + except Exception as e: + error_msg = f"Error al consultar Google Calendar: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + # Continuamos con el fichaje aunque falle el calendario - if response.status_code == 200: - if rj['Repeated']: - time = datetime.strptime(rj['RepeatedTime'], "%Y-%m-%dT%H:%M:%SZ").replace( - tzinfo=pytz.utc).astimezone(pytz.timezone("Europe/Madrid")).strftime("%H:%M") - self.addMessage("🕐 Ya se ha realizado este marcaje antes a las %s" % time) + # Determinar tipo de fichaje + typ = 0 + try: + if args.basedtime and not args.type: + hour = datetime.now().strftime("%H") + logger.info(f"Hora actual: {hour}") + + hIN = config.get('in_hours', []) + hOUT = config.get('out_hours', []) + + logger.info(f"Horas de entrada: {hIN}, Horas de salida: {hOUT}") + + if hour in hIN: + typ = 0 + logger.info("Tipo determinado: Entrada (0) por horario") + elif hour in hOUT: + typ = 1 + logger.info("Tipo determinado: Salida (1) por horario") + else: + logger.warning(f"No se puede determinar el tipo de fichaje para la hora {hour}") + self.addMessage("🟥🕐 No se ha fichado ni desfichado ya que estamos en horario laboral, fuerze el estado con el parametro --type <0 = Entrada, 1 = Salida>") + self.sendReport() + return + else: + typ = args.type + logger.info(f"Tipo determinado por argumento: {typ}") + except Exception as e: + error_msg = f"Error al determinar tipo de fichaje: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + return + + # Verificar último check + logger.info("Verificando último check...") + if self.checkLastCheck(typ): + logger.info("Check ya realizado previamente, cancelando") + return + + # Realizar check + response = None + if not args.debug: + try: + logger.info("Iniciando proceso de fichaje...") + self.addMessage("####HACIENDO CHECK####") + rand = utils.numero_aleatorio_con_probabilidad(230, 0.5) + logger.info(f"Esperando {rand} segundos antes de fichar") + self.addMessage("Esperando %s segundos para %s en un minuto aleatorio" % (rand,strings.conditional_response[int(typ)]["text2"])) + self.sendReport() + sleep(rand) + + self.updateTime() + data = { + "typ": typ, + "date": self.headers[strings.tnd_string], + "geoLatitude": config.get('geo', {}).get('latitude', ''), + "geoLongitude": config.get('geo', {}).get('longitude', ''), + "geoError": "", + "dStr": self.headers["dStr"].replace("\"", "") + } + logger.info(f"Enviando check con datos: typ={typ}, date={data['date']}") + response = self.post("cp/checks", data, self.headers) + logger.info(f"Respuesta del check recibida: status={response.status_code}, text={response.text[:200]}") + except Exception as e: + error_msg = f"Error durante el proceso de fichaje: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise else: - time = datetime.now().astimezone(pytz.timezone("Europe/Madrid")).strftime("%H:%M") - self.addMessage('%s Has %s correctamente a las %s' % (strings.conditional_response[int(typ)]['emoji'], strings.conditional_response[int(typ)]['text'], time)) - else: - self.addMessage("🟥🕐 No se ha podido fichar, la web no ha devuelto 200 OK") + logger.info("Modo debug activado, no se realizará fichaje") + self.addMessage('Corriendo en modo debug. No se realizará ninguna acción') + self.sendReport() + exit(20) - self.sendReport() + # Validar respuesta + if not response: + error_msg = "No se recibió respuesta del servidor" + logger.error(error_msg) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + exit(20) + + if response.text == "no valid worker": + error_msg = "El trabajador no ha podido ser identificado" + logger.error(error_msg) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + exit(20) + + try: + rj = json.loads(response.text) + logger.info(f"JSON parseado correctamente: {rj}") + except json.JSONDecodeError as e: + error_msg = f"La respuesta al hacer check no es correcta... algo ha pasado :/ - response={response.text[:200]} - status_code={response.status_code} - error={str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + exit(20) + except Exception as e: + error_msg = f"Error al procesar respuesta del check: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + exit(20) + + # Procesar resultado + if response.status_code == 200: + if rj.get('Repeated'): + try: + time = datetime.strptime(rj['RepeatedTime'], "%Y-%m-%dT%H:%M:%SZ").replace( + tzinfo=pytz.utc).astimezone(pytz.timezone("Europe/Madrid")).strftime("%H:%M") + logger.info(f"Check repetido a las {time}") + self.addMessage("🕐 Ya se ha realizado este marcaje antes a las %s" % time) + except Exception as e: + error_msg = f"Error al procesar tiempo de check repetido: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + else: + try: + time = datetime.now().astimezone(pytz.timezone("Europe/Madrid")).strftime("%H:%M") + logger.info(f"Check exitoso a las {time}") + self.addMessage('%s Has %s correctamente a las %s' % (strings.conditional_response[int(typ)]['emoji'], strings.conditional_response[int(typ)]['text'], time)) + except Exception as e: + error_msg = f"Error al formatear tiempo de check exitoso: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + else: + error_msg = f"No se ha podido fichar, la web no ha devuelto 200 OK - status_code={response.status_code}, response={response.text[:200]}" + logger.error(error_msg) + self.addMessage(f"🟥🕐 {error_msg}") + + self.sendReport() + logger.info("sendUpdate completado") + except Exception as e: + error_msg = f"Error crítico en sendUpdate: {str(e)}" + logger.error(error_msg, exc_info=True) + self.addMessage(f"🟥🕐 {error_msg}") + self.sendReport() + raise diff --git a/main.py b/main.py index 308e910..f020318 100755 --- a/main.py +++ b/main.py @@ -12,11 +12,79 @@ # # Creado: Omar Sánchez 04-05-2019 # Importamos App Principal -from app import timenet_manager +import sys +import traceback +import logging +import asyncio +from app import timenet_manager, telegram_bot + +# Configurar logging +logging.basicConfig( + level=logging.INFO, + format='%(asctime)s - %(name)s - %(levelname)s - %(message)s', + datefmt='%Y-%m-%d %H:%M:%S' +) +logger = logging.getLogger(__name__) if __name__ == '__main__': - af = timenet_manager.timenetManager() - af.sendUpdate() + telegram = None + try: + logger.info("=" * 50) + logger.info("Iniciando autoficher...") + logger.info("=" * 50) + + af = timenet_manager.timenetManager() + telegram = af.telegram + af.sendUpdate() + + logger.info("=" * 50) + logger.info("Autoficher completado exitosamente") + logger.info("=" * 50) + except KeyboardInterrupt: + logger.info("Interrupción por el usuario (Ctrl+C)") + sys.exit(0) + except SystemExit as e: + logger.info(f"Salida del sistema con código: {e.code}") + sys.exit(e.code if e.code else 0) + except Exception as e: + error_msg = f"Error crítico no manejado: {str(e)}" + error_traceback = traceback.format_exc() + + logger.error("=" * 50) + logger.error("ERROR CRÍTICO NO MANEJADO") + logger.error("=" * 50) + logger.error(error_msg) + logger.error(error_traceback) + logger.error("=" * 50) + + # Intentar enviar error por Telegram + try: + if telegram: + full_error = f"🟥🕐 ERROR CRÍTICO EN AUTOFICHER\n\n{error_msg}\n\n```\n{error_traceback}\n```" + asyncio.run(telegram.sendMessage(full_error)) + logger.info("Error enviado por Telegram") + else: + # Intentar crear un bot temporal para enviar el error + try: + temp_telegram = telegram_bot.telegramBot() + full_error = f"🟥🕐 ERROR CRÍTICO EN AUTOFICHER\n\n{error_msg}\n\n```\n{error_traceback}\n```" + asyncio.run(temp_telegram.sendMessage(full_error)) + logger.info("Error enviado por Telegram (bot temporal)") + except: + logger.error("No se pudo enviar el error por Telegram") + except Exception as telegram_error: + logger.error(f"Error al intentar enviar mensaje por Telegram: {str(telegram_error)}") + + # Imprimir error en consola también + print(f"\n{'=' * 50}") + print("ERROR CRÍTICO") + print(f"{'=' * 50}") + print(error_msg) + print(f"\nTraceback completo:") + print(error_traceback) + print(f"{'=' * 50}\n") + + sys.exit(1)