#!/usr/bin/env python3 """ FINAL hardened booking script — Portugal Tardes (cola I), Oct 19, 2026. Addresses all concerns: - Clean motivo (no tracking ID, natural Spanish reason) - Full browser-like headers (Accept, X-Requested-With, Origin, Referer, UA) - Realtime in-memory log of every attempt - Duplicate prevention (sequential, pre-flight check, post-verify) - Benchmark/timing of every step, persisted to /tmp/booking_log.txt - Cancel procedure function (for emergency duplicate cleanup) - Careful loop review (no accidental re-firing) - T-3 pre-connect (not T-5): server closes idle TLS after ~5s; T-3 keeps conn alive - Contrarian slot order: post-15h middle slots (15:15-15:45) tried first - getHorasCitas pre-fired at T-500ms to overlap with pre-midnight idle — saves ~157ms - Booking request pre-fired at T-40ms to absorb one-way RTT — saves ~40ms - TCP_NODELAY on all connections to disable Nagle's algorithm - Skew retry with three-phase backoff (43ms×1.5^n for 6 aggressive, then 1.15x gradual, then 2s×1.2^n gradual to 120s budget — catches cancellations); each slot retries independently; only gives up on certified signals: "Hora no permitida" = taken, "Cita insertada" = booked, duplicate = STOP) """ import http.client, ssl, json, time, sys, socket, argparse from datetime import datetime # ── USER DATA ─────────────────────────────────────────────── HOST = "webservices.alicante.es" PORT = 443 API = "/WsCitaPreviaPublic-RESTWebService-context-root/rest/1" ENDPOINT = API + "/ScCitaVo1" CT = "application/vnd.oracle.adf.action+json" # REQUIRED by ADF REST server SERVICIO = "S" COLA = "I" FECHA = "19-10-2026" DOC = "X2491454W" NOMBRE = "Humberto" APE1 = "Normey" APE2 = "Gomez" TIPO = "2" # NIE TEL = "687915599" EMAIL = "hj@normey.net" COMENTARIO = "Solicitud de Alta en el Padrón" # CLEAN, natural reason # impuestos is NOT visible on the cita itself — it's an internal API param. # For service S (not L), the frontend hardcodes resumen.impuestos = 'N'. # The validation (controllers.js line 611) only blocks service 'L' (Bono). # The verCita display model ($scope.cita = {...}) does NOT include impuestos. # City staff see: nombre, apellidos, NIF, fecha, hora, oficina, codigoCita only. IMPUESTOS = "N" # hardcoded by frontend for servicio != 'L' — sent to API but never displayed IP = "0.0.0.0" ALL_HORAS = ["14:30","14:45","15:00","15:15","15:30","15:45","16:00","16:15","16:30"] # Contrarian strategy: most bots target 16:00 (preferred) or 14:30 (earliest), # leaving 15:15-15:45 under-contested during the midnight rush. # Post-15h slots tried first; pre-15h (14:30-15:00) as absolute fallback. PRIORITY = ["15:15","15:30","15:45","16:15","16:30","16:00","15:00","14:45","14:30"] # Browser-like headers (matching what Angular $http + browser would send) HEADERS = { "Content-Type": CT, "Accept": "application/json, text/plain, */*", "X-Requested-With": "XMLHttpRequest", "Origin": "https://citaprevia.alicante.es", "Referer": "https://citaprevia.alicante.es/CitaPrevia/", "User-Agent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/120.0.0.0 Safari/537.36", } # ── TIMING TARGET ─────────────────────────────────────────── # Oct 4, 2026 00:00:00 CEST (when the 15-day window slides to include Oct 19) TARGET_TS = datetime(2026, 10, 4, 0, 0, 0).timestamp() # ── SKEW RETRY CONFIG ─────────────────────────────────────── # Three-phase backoff for "Fecha posterior" responses. # Each slot retries independently until CERTIFIED taken or success: # Phase 1 (aggressive): 43ms × 1.5^n for first 6 retries — midnight fast # Phase 2 (gradual): 330ms × 1.15^n, capped 500ms — less spammy # Phase 3 (extended): 2s × 1.2^n, capped 15s — catches post-midnight cancellations # Only stops retrying when: # - Booking succeeds ("Cita insertada") # - Slot certified taken ("Hora no permitida") → give up THIS slot # - Duplicate detected ("already exists" / "DNI" / "existe") → STOP entirely # - Time budget exhausted (120s) → cannot certify, move to next slot # "Fecha posterior" alone is NEVER a give-up reason — server date hasn't rolled. # "Hora no permitida" is the ONLY certification that a slot is taken. SKEW_RETRY_BASE = 0.043 # 43ms: server lift (~40ms) + 3ms buffer SKEW_AGGRESSIVE_N = 6 # first 6 retries at aggressive growth SKEW_AGGRESSIVE_GROWTH = 1.5 # 43, 65, 98, 147, 220, 330ms SKEW_GRADUAL_GROWTH = 1.15 # Phase 2: 380, 437, 500ms (slower = less bot-spammy) SKEW_MAX_DELAY = 0.500 # Phase 1+2 cap: 500ms SKEW_PHASE3_START = 2.5 # start Phase 3 after 2.5s SKEW_EXTENDED_BASE = 2.0 # 2s base for Phase 3 SKEW_EXTENDED_GROWTH = 1.2 # 1.2x growth (gentle): 2, 2.4, 2.88, 3.46, ... SKEW_EXTENDED_CAP = 15.0 # cap Phase 3 delay at 15s SKEW_MAX_BUDGET = 120.0 # 120s per slot (covers cancellations up to 2min after midnight) SKEW_MAX_RETRIES = 200 # hard safety cap (budget hits first at ~40 retries) # ── DUPLICATE DETECTION ────────────────────────────────────── # Strings that indicate the server already has a cita for this NIE + servicio/cola. # When ANY of these substrings appear in the result, STOP immediately — do NOT # retry, do NOT try other slots. This prevents accidental duplicate bookings. DUPLICATE_PATTERNS = ( "ya existente", "DNI", "existe", "Usted ya tiene cita previa", # ← discovered: server returns this when NIE already has a cita for the servicio/cola "cita previa en la gestion", # sub-string match for the above ) def _is_duplicate(result): """Check if the result string indicates an existing cita for this NIE.""" rl = result.lower() return any(p.lower() in rl for p in DUPLICATE_PATTERNS) # ── CITA TYPES CATALOG ───────────────────────────────────────── # Static catalog from live API query (ScServicioFiltrado1 + ScColaVo). # Maps (servicio, cola) → metadata dict. # motivo_requerido: True when cola.Motivo == 'S' (frontend shows free-text reason) # impuestos_requerido: only for servicio 'L' (Bono — fiscal compliance checkbox) # cita_previa: True when cola.CitaPrevia == 'S' (bookable online) # Catalog auto-refreshable via: --refresh-citas (fetch live from API) CITA_TYPES = { # ── Servicio S (SAC / SAIC) — 10 gestiones ── ('S', 'A'): {'nombre': 'Labradores MAÑANA - Altas y modificaciones de Padrón', 'direccion': 'C/LABRADORES 14', 'horario': 'MAÑANA', 'motivo_requerido': True, 'max_cita': 21, 'activa': True, 'cita_previa': True}, ('S', 'B'): {'nombre': 'Labradores MAÑANA - Trámites Municipales', 'direccion': 'C/LABRADORES 14', 'horario': 'MAÑANA', 'motivo_requerido': True, 'max_cita': 21, 'activa': True, 'cita_previa': True}, ('S', 'D'): {'nombre': 'Labradores MAÑANA - Tarjeta Ciudadana', 'direccion': 'C/LABRADORES 14', 'horario': 'MAÑANA', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': False}, ('S', 'E'): {'nombre': 'Labradores TARDE - Altas y modificaciones de Padrón', 'direccion': 'C/LABRADORES 14', 'horario': 'TARDE', 'motivo_requerido': True, 'max_cita': 21, 'activa': True, 'cita_previa': True}, ('S', 'F'): {'nombre': 'Labradores TARDE - Trámites Municipales', 'direccion': 'C/LABRADORES 14', 'horario': 'TARDE', 'motivo_requerido': True, 'max_cita': 21, 'activa': True, 'cita_previa': True}, ('S', 'G'): {'nombre': 'Portugal MAÑANA - Altas y modificaciones de Padrón', 'direccion': 'C/PORTUGAL 17', 'horario': 'MAÑANA', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('S', 'H'): {'nombre': 'Portugal MAÑANA - Trámites Municipales', 'direccion': 'C/PORTUGAL 17', 'horario': 'MAÑANA', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('S', 'I'): {'nombre': 'Portugal TARDE - Altas y modificaciones de Padrón', 'direccion': 'C/PORTUGAL 17', 'horario': 'TARDE', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('S', 'J'): {'nombre': 'Portugal TARDE - Trámites Municipales', 'direccion': 'C/PORTUGAL 17', 'horario': 'TARDE', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('S', 'L'): {'nombre': 'Pino Santo MAÑANA - Trámites Municipales', 'direccion': 'C/PINO SANTO 1', 'horario': 'MAÑANA', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('S', 'M'): {'nombre': 'Pino Santo TARDE - Trámites Municipales', 'direccion': 'C/PINO SANTO 1', 'horario': 'TARDE', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, # ── Servicio I (Inmigración) — 10 gestiones (active + cita_previa) ── ('I', 'C'): {'nombre': 'I- VALORACIÓN ARRAIGO (ENTREVISTA)', 'direccion': 'SARGENTO VAILLO, 30', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'D'): {'nombre': 'II-VALORACIÓN ARRAIGO (ACTUACIONES)', 'direccion': 'SARGENTO VAILLO, 30', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'E'): {'nombre': 'INFORMACIÓN, TRÁMITES Y DOCUMENTOS', 'direccion': 'SARGENTO VAILLO, 30', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'G'): {'nombre': 'ARRAIGO SOCIOFORMATIVO', 'direccion': 'SARGENTO VAILLO, 30', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'H'): {'nombre': 'I- VALORACIÓN ARRAIGO SOCIAL (ENTREVISTA)', 'direccion': 'PZA.ARGEL, 5-2º', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'I'): {'nombre': 'II-VALORACIÓN ARRAIGO SOCIAL (ACTUACIONES)', 'direccion': 'PZA.ARGEL, 5-2º', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'J'): {'nombre': 'INFORMACIÓN TRÁMITES Y DOCUMENTOS (ARRAIGO)', 'direccion': 'PZA.ARGEL, 5-2º', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'L'): {'nombre': 'ARRAIGO SOCIOFORMATIVO', 'direccion': 'PZA.ARGEL, 5-2º', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'U'): {'nombre': 'ESCOLARIZACIÓN Y RETORNO', 'direccion': 'PZA.ARGEL, 5-2º', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, ('I', 'V'): {'nombre': 'ESCOLARIZACIÓN Y RETORNO', 'direccion': 'SARGENTO VAILLO, 30', 'horario': '', 'motivo_requerido': False, 'max_cita': 30, 'activa': True, 'cita_previa': True}, # ── Servicio T (Trámites) — 4 gestiones ── ('T', 'A'): {'nombre': 'APLAZAMIENTOS Y FRACCIONAMIENTOS', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('T', 'B'): {'nombre': 'ALTA DE TERCEROS', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('T', 'C'): {'nombre': 'AVALES Y FIANZAS', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('T', 'D'): {'nombre': 'CERTIFICADOS DE NO DÉBITOS', 'motivo_requerido': False, 'max_cita': 15, 'activa': True, 'cita_previa': True}, # ── Servicio F (Ayuntamiento) — 3 activas ── ('F', 'A'): {'nombre': 'SUBVENCIONES Y CONTRATACIÓN', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('F', 'C'): {'nombre': 'CASA DE SAN NICOLÁS', 'motivo_requerido': False, 'max_cita': 0, 'activa': True, 'cita_previa': True}, ('F', 'D'): {'nombre': 'CAMPAMENTO CARTEROS REALES', 'motivo_requerido': False, 'max_cita': 0, 'activa': True, 'cita_previa': True}, # ── Servicio P (Distritos) — 5 activas ── ('P', 'A'): {'nombre': 'DISTRITO 1 (BARÓN DE FINESTRAT)', 'telefono_oficina': '965212072', 'motivo_requerido': True, 'max_cita': 7, 'activa': True, 'cita_previa': True}, ('P', 'B'): {'nombre': 'DISTRITO 2 (PLAZA DE ARGEL)', 'telefono_oficina': '965128400', 'motivo_requerido': True, 'max_cita': 7, 'activa': True, 'cita_previa': True}, ('P', 'C'): {'nombre': 'DISTRITO 3 MAÑANA (ALC. LORENZO CARBONELL)', 'telefono_oficina': '965103947', 'motivo_requerido': True, 'max_cita': 7, 'activa': True, 'cita_previa': True}, ('P', 'D'): {'nombre': 'DISTRITO 4 MAÑANA (AVDA COSTA BLANCA)', 'telefono_oficina': '965264057', 'motivo_requerido': True, 'max_cita': 7, 'activa': True, 'cita_previa': True}, ('P', 'F'): {'nombre': 'DISTRITO 3 TARDE (ALC. LORENZO CARBONELL)', 'telefono_oficina': '965103947', 'motivo_requerido': True, 'max_cita': 7, 'activa': True, 'cita_previa': True}, # ── Servicio A (Visitas / Eventos) — 1 activa ── ('A', 'A'): {'nombre': 'VISITA COLEGIOS', 'motivo_requerido': True, 'max_cita': 270, 'activa': True, 'cita_previa': True}, # ── Servicio B (Bicicletas / Patinetes) — 1 activa ── ('B', 'A'): {'nombre': 'BICIESCUELA / TALLER PATINETES ELÉCTRICOS', 'motivo_requerido': True, 'max_cita': 257, 'activa': True, 'cita_previa': True}, # ── Servicio L (Bonos) — 3 gestiones, impuestos REQUERIDO ── ('L', 'A'): {'nombre': 'BONO COMERCIO', 'motivo_requerido': False, 'max_cita': 0, 'activa': False, 'cita_previa': False, 'impuestos_requerido': True}, ('L', 'B'): {'nombre': 'BONO GASTRONÓMICO', 'motivo_requerido': False, 'max_cita': 1, 'activa': False, 'cita_previa': False, 'impuestos_requerido': True}, ('L', 'C'): {'nombre': 'BONO CULTURAL', 'motivo_requerido': False, 'max_cita': 0, 'activa': False, 'cita_previa': False, 'impuestos_requerido': True}, # ── Servicio U (Urbanismo) — 10 gestiones, 6 with cita_previa ── ('U', 'B'): {'nombre': 'B: INFORMACIÓN GENERAL NO TÉCNICA', 'motivo_requerido': True, 'max_cita': 10, 'activa': True, 'cita_previa': True}, ('U', 'F'): {'nombre': 'F: ATENCIÓN TÉCNICA CONSERVACIÓN DE INMUEBLES', 'motivo_requerido': True, 'max_cita': 0, 'activa': True, 'cita_previa': True}, ('U', 'G'): {'nombre': 'G: ATENCIÓN TÉCNICA OBRAS Y ACTIVIDADES', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('U', 'H'): {'nombre': 'H: ATENCIÓN TÉCNICA OBRAS Y ACTIVIDADES', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('U', 'I'): {'nombre': 'I: ATENCIÓN TÉCNICA OBRAS Y ACTIVIDADES', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, ('U', 'J'): {'nombre': 'J: ATENCIÓN TÉCNICA OBRAS Y ACTIVIDADES', 'motivo_requerido': True, 'max_cita': 15, 'activa': True, 'cita_previa': True}, } # Document types from ScTipoDocumentoVo1 (API: tipo → descripción) DOC_TYPES = { '1': 'DNI', '2': 'NIE', '3': 'PASS', '4': 'CIF', } # Fields always required for any booking REQUIRED_FIELDS = ['nif', 'tipo', 'nombre', 'ape1', 'fecha', 'tel', 'email'] # ── BENCHMARK & TIMING INFRASTRUCTURE ───────────────────────── BENCH = [] # in-memory log of {step, time, ms, detail, category} # Server load estimation — tracks RTT over time to estimate server pressure _rtt_history = [] # list of response times in ms # ── GLOBAL CONNECTION ───────────────────────────────────────────────── # Pre-connected at T-3 (TARGET_TS - 3), reused across all requests to avoid # redundant TLS handshakes. conn = None means not yet connected. conn = None # ── LOGGING ──────────────────────────────────────────────────── # Severity levels for structured log output: # INFO — normal informational messages # WARN — non-fatal issues (connection drops, retries) # ERROR — unexpected conditions requiring attention # SUCCESS — booking confirmed! # PHASE — phase transitions (pre-fire, midnight, etc.) # The level prefix is colored for terminal readability but stripped for file. def _skew_delay(n): """Compute retry delay for attempt n (0-indexed). Phase 1 (n < 6): aggressive — 43ms × 1.5^n (midnight-fast) Phase 2 (n < 12): gradual — 330ms × 1.15^(n-6), capped at 500ms Phase 3 (n >= 12): extended — 2s × 1.2^(n-12), capped at 15s (cancellation catcher)""" if n < SKEW_AGGRESSIVE_N: return min(SKEW_RETRY_BASE * (SKEW_AGGRESSIVE_GROWTH ** n), SKEW_MAX_DELAY) elif n < SKEW_AGGRESSIVE_N + 6: grad_base = min(SKEW_RETRY_BASE * (SKEW_AGGRESSIVE_GROWTH ** (SKEW_AGGRESSIVE_N - 1)), SKEW_MAX_DELAY) return min(grad_base * (SKEW_GRADUAL_GROWTH ** (n - SKEW_AGGRESSIVE_N)), SKEW_MAX_DELAY) else: ext_n = n - SKEW_AGGRESSIVE_N - 6 return min(SKEW_EXTENDED_BASE * (SKEW_EXTENDED_GROWTH ** ext_n), SKEW_EXTENDED_CAP) import sys as _sys if _sys.stderr.isatty(): _LVL_COLOR = { "INFO": "\033[36m", # cyan "WARN": "\033[33m", # yellow "ERROR": "\033[31m", # red "SUCCESS": "\033[32m", # green "PHASE": "\033[35m", # magenta "_RESET": "\033[0m", } else: _LVL_COLOR = {} def log(message, level="INFO"): """Print a timestamped, severity-leveled message with flush=True.""" ts = datetime.now().strftime('%H:%M:%S.%f')[:-3] color = _LVL_COLOR.get(level, "") reset = _LVL_COLOR.get("_RESET", "") tag = f"{color}[{level}]{reset}" if color else f"[{level}]" print(f"[{ts}] {tag} {message}", flush=True) def bench(step, detail="", t0=None, category="REQUEST"): """Record a benchmark timing entry and print to console. Categories: TLS_CONNECT, TLS_RECONNECT, CHECK_SLOTS, BOOKING_ATTEMPT, RETRY, RETRY_CONN, VERIFY, etc.""" now = datetime.now() elapsed = (time.time() - t0) * 1000 if t0 else 0 BENCH.append({ "step": step, "time": now.strftime("%H:%M:%S.%f")[:-3], "ms": round(elapsed, 1), "detail": detail, "category": category }) print(f"[{now.strftime('%H:%M:%S.%f')[:-3]}] [{category}] [{elapsed:.0f}ms] {step}: {detail}", flush=True) return time.time() def _track_rtt(response_ms): """Track response time for server load estimation. HOT PATH — only appends to history (O(1)). Use _compute_load() to get the load descriptor only when logging is needed.""" _rtt_history.append(response_ms) def _compute_load(): """Compute server load descriptor from tracked RTTs. Only call when you need to log the load — NOT on every request.""" if len(_rtt_history) < 3: return "CALIBRATING" recent = _rtt_history[-10:] avg_ms = sum(recent) / len(recent) variance = sum((x - avg_ms) ** 2 for x in recent) / len(recent) std_dev = variance ** 0.5 if std_dev < 25: return f"LOW (avg={avg_ms:.0f}ms σ={std_dev:.0f}ms)" elif std_dev < 100: return f"MODERATE (avg={avg_ms:.0f}ms σ={std_dev:.0f}ms)" else: return f"HIGH (avg={avg_ms:.0f}ms σ={std_dev:.0f}ms)" def _current_load(): """Get current server load estimate from already-tracked RTTs. Does NOT append — call _track_rtt() for each new measurement instead.""" return _compute_load() def _load_trend(): """Analyze RTT trend over the session to estimate server load changes. Returns (trend_label, first_half_avg, second_half_avg).""" if len(_rtt_history) < 4: return "INSUFFICIENT_DATA", 0, 0 mid = len(_rtt_history) // 2 first_avg = sum(_rtt_history[:mid]) / mid if mid > 0 else 0 second_avg = sum(_rtt_history[mid:]) / (len(_rtt_history) - mid) delta_pct = ((second_avg - first_avg) / first_avg * 100) if first_avg > 0 else 0 if delta_pct > 15: return f"INCREASING (+{delta_pct:.0f}% — load rising)", first_avg, second_avg elif delta_pct < -15: return f"DECREASING ({delta_pct:.0f}% — load easing)", first_avg, second_avg else: return f"STABLE (±{abs(delta_pct):.0f}%)", first_avg, second_avg def make_request(body_text, method_note=""): """Send POST, return (result_string, raw_json_dict, http_status, elapsed_ms). Handles connection drops by reconnecting and retrying ONCE.""" global conn t0 = time.time() try: conn.request("POST", ENDPOINT, body=body_text, headers=HEADERS) resp = conn.getresponse() raw = resp.read().decode() elapsed = (time.time() - t0) * 1000 _track_rtt(elapsed) # HOT PATH: O(1) append only — no computation try: dj = json.loads(raw) result = dj.get('result', '') except: result = raw[:300] if raw else "(empty)" dj = None return result, dj, resp.status, elapsed except (http.client.RemoteDisconnected, ConnectionResetError, BrokenPipeError, http.client.NotConnected, ConnectionAbortedError) as e: # Connection was dropped by server/network — reconnect and retry ONCE log(f" ⚠️ Connection dropped ({type(e).__name__}) — reconnecting...", level="WARN") try: ctx = ssl.create_default_context() conn = http.client.HTTPSConnection(HOST, PORT, context=ctx, timeout=20) conn.connect() conn.sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1) log(" Re-connected ✓ — retrying request", level="WARN") bench("TLS_RECONNECT", "reconnect after drop", time.time(), category="RECOVERY") t0 = time.time() conn.request("POST", ENDPOINT, body=body_text, headers=HEADERS) resp = conn.getresponse() raw = resp.read().decode() elapsed = (time.time() - t0) * 1000 _track_rtt(elapsed) # O(1) append — load computed lazily on log try: dj = json.loads(raw) result = dj.get('result', '') except: result = raw[:300] if raw else "(empty)" dj = None return result, dj, resp.status, elapsed except Exception as e2: elapsed = (time.time() - t0) * 1000 return f"EXCEPTION: {e2}", None, 0, elapsed except Exception as e: elapsed = (time.time() - t0) * 1000 return f"EXCEPTION: {e}", None, 0, elapsed def build_booking_body(hora): # Clean motivo: just the natural reason — NO timestamp, NO tracking IDs return json.dumps({ "name": "insertarCitaPrevia", "parameters": [ {"servicio": SERVICIO}, {"cola": COLA}, {"fecha": FECHA}, {"hora": hora}, {"documento": DOC}, {"ip": IP}, {"nombre": NOMBRE}, {"apellido1": APE1}, {"apellido2": APE2}, {"tipo": TIPO}, {"telefono": TEL}, {"email": EMAIL}, {"impuestos": IMPUESTOS}, {"motivo": COMENTARIO}, {"procedencia": "NULO"}, ] }, separators=(',', ':')) def build_check_body(): return json.dumps({ "name": "getHorasCitas", "parameters": [ {"servicio": SERVICIO}, {"cola": COLA}, {"fecha": FECHA}, ] }, separators=(',', ':')) def cancel_cita(codigo_cita=None): """Emergency cancel procedure. Flow: obtenerCitaInsertada (find cita by NIF) → anularCitaInsertadaCodigo (cancel by code) """ print("\n⚠️ CANCEL PROCEDURE (emergency only)", flush=True) print(" Step 1: Look up cita via obtenerCitaInsertada...", flush=True) body = json.dumps({ "name": "obtenerCitaInsertada", "parameters": [ {"servicio": SERVICIO}, {"cola": COLA}, {"documento": DOC}, ] }, separators=(',', ':')) result, dj, status, elapsed = make_request(body, "CANCEL-LOOKUP") print(f" Lookup result: {result[:200]}", flush=True) # The response contains cita details — extract codigoCita # Then call anularCitaInsertadaCodigo with servicio, cola, documento, codigoCita # (Full implementation available if needed — API confirmed in services.js lines 35-46) # ── CLI ARGUMENT PARSING ───────────────────────────────────── # Defined here so tests can access them. Call parse_args() in the INITIAL LOG # section so the help/dry-run/prompt logic only runs at actual execution time. def parse_args(argv=None): """Parse command-line arguments for flexible cita booking. Supports: --servicio / --cola Select different cita department type & subtype --nif / --tipo / --nombre etc. Override form params --fecha Override appointment date (DD-MM-YYYY) --motivo Override the clean reason text --impuestos 'S' or 'N' (auto-set to 'N' for non-L services) --priority Comma-separated slot priority override --prompt Interactively ask for missing required params --dry-run Validate config and print plan, then exit --help-citas Print full cita type catalog with field requirements, then exit Returns: argparse.Namespace with all fields. May call sys.exit() for --help-citas or argparse --help. """ parser = argparse.ArgumentParser( prog="book_final.py", description="Cita previa booking bot for Alicante (webservices.alicante.es)", formatter_class=argparse.RawDescriptionHelpFormatter, epilog="""\ Examples: # Default (service S / cola I — Padrón, Portugal Tardes) ./book_final.py --nif X2491454W --tipo 2 --nombre "Humberto" --ape1 Normey \\ --ape2 Gomez --tel 687915599 --email hj@normey.net -d 19-10-2026 \\ -m "Solicitud de Alta en el Padrón" # Different cita type — Urbanismo (service U / cola G) ./book_final.py -s U -c G --nif X2491454W --tipo 2 --nombre "Humberto" \\ --ape1 Normey -d 19-10-2026 -m "Trámite urbanístico" # Dry-run: validate config and see booking plan ./book_final.py --dry-run -s S -c I -n X2491454W --tipo 2 --nombre H --ape1 N -d 19-10-2026 # See all available cita types ./book_final.py --help-citas """, ) # ── Cita type selection ────────────────────────────────── parser.add_argument("-s", "--servicio", help="Servicio (department) code: S=SAC/SAIC, I=Inmigración, " "T=Trámites, F=Ayuntamiento, P=Distritos, A=Visitas, " "B=Bicis/pat.Eléc., L=Bonos, U=Urbanismo. Default: S") parser.add_argument("-c", "--cola", help="Cola (subtype) code for the selected servicio. " "Required if --servicio is given. " "See --help-citas for valid combos.") # ── Booking date ───────────────────────────────────────── parser.add_argument("-d", "--fecha", help="Appointment date in DD-MM-YYYY format. " "Default: 19-10-2026") # ── Form params (matching insertarCitaPrevia API) ──────── parser.add_argument("-n", "--nif", help="Document number (NIE/NIF/PASS/CIF)") parser.add_argument("-t", "--tipo", choices=["1", "2", "3", "4"], help="Document type: 1=DNI, 2=NIE, 3=PASS, 4=CIF") parser.add_argument("--nombre", help="First name(s)") parser.add_argument("--ape1", help="Primer apellido / Razón Social (REQUIRED)") parser.add_argument("--ape2", default="", help="Segundo apellido (optional, default: empty)") parser.add_argument("--tel", help="Teléfono de contacto (REQUIRED)") parser.add_argument("-e", "--email", help="Correo electrónico (REQUIRED)") parser.add_argument("-m", "--motivo", help="Motivo / reason text. REQUIRED when servicio/cola " "has motivo='S'") parser.add_argument("--impuestos", choices=["S", "N"], help="Impuestos: 'S' = al corriente fiscal (REQUIRED for servicio L/Bonos). " "Auto-set to 'N' for other services.") parser.add_argument("--ip", default="0.0.0.0", help="IP address for the booking (default: 0.0.0.0)") # ── Priority slots override ──────────────────────────────── parser.add_argument("-r", "--priority", help="Comma-separated slot priority (e.g. '15:15,15:30,16:00'). " "Default: contrarian order for service S.") # ── Mode flags ─────────────────────────────────────────── parser.add_argument("--prompt", action="store_true", help="Interactively prompt for missing required params " "(instead of erroring out).") parser.add_argument("--dry-run", action="store_true", help="Validate config and print booking plan, then exit " "(no midnight wait, no booking).") parser.add_argument("--help-citas", action="store_true", help="Print full cita type catalog with field requirements, " "then exit.") return parser.parse_args(argv) def print_cita_types(): """Print the full CITA_TYPES catalog organized by servicio, with field requirements.""" # Group by servicio servicios = {} for (svc, cola), meta in sorted(CITA_TYPES.items()): servicios.setdefault(svc, []).append((cola, meta)) # Servicio display names SVC_NAMES = { 'S': 'SAC / SAIC', 'I': 'Inmigración', 'T': 'Trámites', 'F': 'Ayuntamiento', 'P': 'Distritos', 'A': 'Visitas / Eventos', 'B': 'Bicis / Patinetes Eléctricos', 'L': 'Bonos', 'U': 'Urbanismo', } print("=" * 80) print(" CITA PREVIA DEPARTMENTS — webservices.alicante.es") print("=" * 80) total = sum(1 for v in CITA_TYPES.values() if v.get('cita_previa') and v.get('activa')) inactive = sum(1 for v in CITA_TYPES.values() if not v.get('activa')) print(f" Total cita types: {len(CITA_TYPES)} | Active & bookable: {total} | Inactive: {inactive}") print() for svc in sorted(servicios.keys()): svc_name = SVC_NAMES.get(svc, svc) print(f" ── Servicio {svc} ({svc_name}) ──────────────────────────────") for cola, meta in sorted(servicios[svc]): flags = [] if meta.get('motivo_requerido'): flags.append("motivo=✓") if meta.get('impuestos_requerido'): flags.append("impuestos=✓") if not meta.get('activa'): flags.append("INACTIVA") if not meta.get('cita_previa'): flags.append("sin_cita_previa") addr = meta.get('direccion', '') horario = meta.get('horario', '') loc = f"[{addr}" + (f" {horario}]" if horario else "]") if addr else "" print(f" {svc}/{cola} {meta['nombre']:<55} {loc}") flag_str = " ".join(flags) if flags else "—" print(f" max_días={meta['max_cita']:<4} motiv:{meta.get('motivo_requerido','—')} imp:{'S' if meta.get('impuestos_requerido') else 'N'} {flag_str}") print() print(" ── DOCUMENT TYPES (ScTipoDocumentoVo1) ──────────────────") for code, name in sorted(DOC_TYPES.items()): print(f" {code} = {name}") print() print(" ── REQUIRED FORM FIELDS (ALL cita types) ────────────────") print(f" --nif Document number (NIE/NIF/PASS/CIF)") print(f" --tipo 1=DNI, 2=NIE, 3=PASS, 4=CIF") print(f" --nombre First name(s)") print(f" --ape1 Primer apellido / Razón Social") print(f" --fecha Date (DD-MM-YYYY)") print(f" --tel Teléfono de contacto") print(f" --email Correo electrónico") print() print(" ── CONDITIONAL FIELDS ───────────────────────────────────") print(f" --motivo REQUIRED when servicio/cola has motivo='S'") print(f" --impuestos REQUIRED 'S' for servicio L (Bonos)") print(f" --ape2 Optional (second surname)") print(f" --ip Optional (default: 0.0.0.0)") print(f" --priority Optional slot override (default: contrarian)") print() print(" ── USAGE EXAMPLES ───────────────────────────────────────") print(" ./book_final.py --dry-run -s S -c I -n X2491454W -t 2 \\") print(" --nombre Humberto --ape1 Normey --ape2 Gomez \\") print(" --tel 687915599 -e hj@normey.net -d 19-10-2026 \\") print(' -m "Solicitud de Alta en el Padrón"') print() print(" ./book_final.py -s U -c G --help-citas # show Urbanismo types") print() print("=" * 80) def validate_config(args): """Validate CLI args against CITA_TYPES. Returns (ok: bool, missing: list, errors: list). Checks: 1. If --servicio given, --cola must also be given 2. (servicio, cola) must exist in CITA_TYPES 3. Service must be active + bookable (cita_previa == True) 4. All REQUIRED_FIELDS must be provided 5. --motivo required when cita type has motivo_requerido=True 6. --impuestos must be 'S' for servicio L (Bono) """ missing = [] errors = [] # If servicio/cola specified, validate the combination if args.servicio is not None: if args.cola is None: errors.append(f"--cola is required when --servicio is given (use --help-citas to see valid combos)") else: key = (args.servicio.upper(), args.cola.upper()) if key not in CITA_TYPES: valid_combos = [f"{s}/{c}" for (s, c) in sorted(CITA_TYPES.keys())] errors.append(f"Invalid servicio/cola: ({args.servicio}, {args.cola}). " f"Valid combos: {', '.join(valid_combos)}") else: meta = CITA_TYPES[key] if not meta.get('activa'): errors.append(f"servicio {args.servicio}/cola {args.cola} ({meta['nombre']}) — INACTIVA") if not meta.get('cita_previa'): errors.append(f"servicio {args.servicio}/cola {args.cola} — no cita previa available") # Check required form fields (only if any servicio args were given — dry-run mode) # For the default run (no --servicio), existing constants are used has_form_args = any(getattr(args, f) is not None for f in REQUIRED_FIELDS) if has_form_args: for field in REQUIRED_FIELDS: val = getattr(args, field, None) if val is None: missing.append(f"--{field}") elif args.dry_run or args.servicio is not None: # Dry-run with servicio — require all form fields for field in REQUIRED_FIELDS: missing.append(f"--{field}") # Check motivo for cita types that require it if args.servicio and args.cola: key = (args.servicio.upper(), args.cola.upper()) if key in CITA_TYPES: meta = CITA_TYPES[key] if meta.get('motivo_requerido') and not args.motivo: missing.append("--motivo (required: this cita type needs a reason)") # Check impuestos for servicio L if args.servicio and args.servicio.upper() == 'L': if args.impuestos != 'S': errors.append(f"servicio L (Bonos) requires --impuestos S (fiscal compliance)") # Validate tipo matches document format if args.tipo and args.nif: # Quick format check if args.tipo == '1': # DNI pass # 8 digits + letter elif args.tipo == '2': # NIE if not args.nif[0].upper() in ('X', 'Y', 'Z'): errors.append(f"NIE (tipo=2) must start with X/Y/Z. Got: {args.nif}") elif args.tipo == '3': # PASS pass # any elif args.tipo == '4': # CIF if not args.nif[0].upper() in ('A', 'B', 'C', 'D', 'E', 'F', 'G', 'H', 'J', 'N', 'P', 'Q', 'R', 'S', 'U', 'V'): errors.append(f"CIF (tipo=4) must start with company letter. Got: {args.nif}") # Validate fecha format if args.fecha: try: datetime.strptime(args.fecha, "%d-%m-%Y") except ValueError: errors.append(f"--fecha format must be DD-MM-YYYY. Got: {args.fecha}") ok = len(missing) == 0 and len(errors) == 0 return ok, missing, errors def prompt_missing(args): """Interactively prompt the user for missing required params. Modifies `args` in place.""" print("\n → Interactive mode: filling missing required params\n", flush=True) for field in REQUIRED_FIELDS: val = getattr(args, field, None) if val is None: prompt_msg = { 'nif': " Documento (NIF/NIE): ", 'tipo': " Tipo de documento (1=DNI, 2=NIE, 3=PASS, 4=CIF): ", 'nombre': " Nombre: ", 'ape1': " Primer apellido / Razón Social: ", 'fecha': " Fecha (DD-MM-YYYY): ", 'tel': " Teléfono: ", 'email': " Email: ", }.get(field, f" {field}: ") val = input(prompt_msg).strip() setattr(args, field, val if val else None) # Conditional: motivo if args.servicio and args.cola and not args.motivo: key = (args.servicio.upper(), args.cola.upper()) if key in CITA_TYPES and CITA_TYPES[key].get('motivo_requerido'): val = input(" Motivo / razón: ").strip() if val: args.motivo = val # Conditional: impuestos for servicio L if args.servicio and args.servicio.upper() == 'L' and args.impuestos != 'S': val = input(" Impuestos (S=al corriente): ").strip().upper() if val: args.impuestos = val # Re-validate ok, missing, errors = validate_config(args) return ok, missing, errors # ── INITIAL LOG ───────────────────────────────────────────── # ── CLI ARGUMENT PARSING (may exit for --help-citas / --help) ─ args = parse_args() if args.help_citas: print_cita_types() sys.exit(0) # Override defaults with CLI args (only if provided) if args.servicio: SERVICIO = args.servicio.upper() if args.cola: COLA = args.cola.upper() if args.fecha: FECHA = args.fecha if args.nif: DOC = args.nif.upper() if args.tipo: TIPO = args.tipo if args.nombre: NOMBRE = args.nombre if args.ape1: APE1 = args.ape1 if args.ape2: APE2 = args.ape2 if args.tel: TEL = args.tel if args.email: EMAIL = args.email if args.motivo: COMENTARIO = args.motivo if args.ip: IP = args.ip if args.priority: PRIORITY = [h.strip() for h in args.priority.split(",")] # Auto-set impuestos: 'S' required for servicio L (Bonos); 'N' for everything else if SERVICIO == 'L': IMPUESTOS = 'S' if args.impuestos is None else args.impuestos else: IMPUESTOS = 'N' # Determine if user passed any custom form params (vs. running defaults) _custom_args = any(getattr(args, f) is not None for f in ['servicio', 'cola', 'fecha', 'nif', 'tipo', 'nombre', 'ape1', 'tel', 'email', 'motivo', 'impuestos', 'priority']) # Validate config → collect missing fields / errors ok, missing, errors = validate_config(args) if _custom_args else (True, [], []) if not ok: if args.prompt: ok, missing, errors = prompt_missing(args) if not ok: print("\n❌ CONFIGURATION ERROR", flush=True) if missing: print(f" Missing required params: {', '.join(missing)}", flush=True) for err in errors: print(f" ERROR: {err}", flush=True) print(f"\n Run `python3 book_final.py --help-citas` for all cita types & required fields.", flush=True) print(f" Add `--prompt` for interactive mode.", flush=True) sys.exit(1) # Apply params that prompt_missing may have filled in if args.prompt and ok: if args.nif: DOC = args.nif.upper() if args.tipo: TIPO = args.tipo if args.nombre: NOMBRE = args.nombre if args.ape1: APE1 = args.ape1 if args.fecha: FECHA = args.fecha if args.tel: TEL = args.tel if args.email: EMAIL = args.email if args.motivo: COMENTARIO = args.motivo # ── DRY-RUN MODE ─────────────────────────────────────────── if args.dry_run: _cita_meta = CITA_TYPES.get((SERVICIO, COLA), {}) now = datetime.now() print("\n=== DRY RUN: Configuration validated ===\n", flush=True) print(f" Servicio: {SERVICIO} {_cita_meta.get('nombre', '?')}", flush=True) print(f" Cola: {COLA}", flush=True) print(f" Oficina: {_cita_meta.get('direccion', 'N/A')}", flush=True) print(f" Fecha: {FECHA} max_días={_cita_meta.get('max_cita', '?')}", flush=True) print(f" Documento: {DOC} (tipo {TIPO} = {DOC_TYPES.get(TIPO, '?')})", flush=True) print(f" Nombre: {NOMBRE} {APE1} {APE2}", flush=True) print(f" Teléfono: {TEL}", flush=True) print(f" Email: {EMAIL}", flush=True) print(f" Motivo: {COMENTARIO}", flush=True) print(f" Impuestos: {IMPUESTOS}", flush=True) print(f" IP: {IP}", flush=True) print(f" Priority: {PRIORITY}", flush=True) print(f" Target TS: {datetime.fromtimestamp(TARGET_TS).strftime('%Y-%m-%d %H:%M:%S')} " f"(in {(TARGET_TS - now.timestamp()):.0f}s)", flush=True) print(f"\n ✅ Config valid — ready for booking.", flush=True) sys.exit(0) # ── STARTUP LOG ───────────────────────────────────────────── log_file = "/tmp/booking_log.txt" now = datetime.now() _cita_meta = CITA_TYPES.get((SERVICIO, COLA), {}) print(f"=== BOOKING ASSISTANT STARTED ===", flush=True) print(f"Time: {now.strftime('%Y-%m-%d %H:%M:%S.%f')[:-3]}", flush=True) _target_str = datetime.fromtimestamp(TARGET_TS).strftime('%b %d %H:%M:%S') print(f"Target: {_target_str} CEST (in {(TARGET_TS - now.timestamp()):.0f}s)", flush=True) print(f"Service: {SERVICIO} ({_cita_meta.get('nombre', 'SAC/SAIC')}) Cola: {COLA}", flush=True) print(f"Documento: NIE {DOC} Nombre: {NOMBRE} {APE1} {APE2}", flush=True) print(f"Fecha: {FECHA} Priority slots: {PRIORITY}", flush=True) log(f" Motivo: '{COMENTARIO}' (clean, natural Spanish — no timestamp, no IDs)", level="INFO") print("", flush=True) # ── PHASE 1: Sleep until 3s before midnight (low CPU) ──────── # T-3 (not T-5) to keep the TLS connection alive through midnight — # the server closes idle TLS connections after ~5s, so a T-5 preconnect # risks the connection being dropped right at midnight. now = datetime.now() preconnect_ts = TARGET_TS - 3 log(f"Starting Phase 1: Sleeping until 23:59:57 (T-3s to midnight)", level="PHASE") log("Target midnight: " + datetime.fromtimestamp(TARGET_TS).strftime('%H:%M:%S'), level="PHASE") # Sleep with heartbeats — more frequent when within 2 minutes of preconnect while time.time() < preconnect_ts: remaining = preconnect_ts - time.time() hours_left = int(remaining / 3600) mins_left = int((remaining % 3600) / 60) secs_left = int(remaining % 60) # Every 60s normally, every 10s when within 2 minutes of pre-connect if remaining < 120: log(f" Heartbeat: {mins_left}m {secs_left}s until pre-connect phase (tight watch)", level="PHASE") sleep_time = min(10, remaining) else: log(f" Heartbeat: {hours_left}h {mins_left}m {secs_left}s until pre-connect phase", level="PHASE") sleep_time = min(60, remaining) time.sleep(sleep_time) # ── PHASE 2: Pre-establish TLS at T-3 ──────────────────────── log(f"\n*** Phase 2: Pre-connecting TLS (3s before midnight) ***", level="PHASE") t0 = time.time() try: ctx = ssl.create_default_context() conn = http.client.HTTPSConnection(HOST, PORT, context=ctx, timeout=20) conn.connect() conn.sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1) # disable Nagle t1 = bench("TLS_CONNECT", "webservices.alicante.es:443", t0) log("TLS connection established ✓", level="INFO") except Exception as e: log(f"TLS connect failed: {e}", level="ERROR") conn = None # ── PHASE 3: Busy-wait until T-500ms, then fire getHorasCitas early ── # The slot-verification call is pre-fired 500ms before midnight so its # response is already in hand when the busy-wait reaches 00:00:00.000. # This saves ~157ms vs waiting until midnight to start the check. log("Phase 3: Busy-wait until T-500ms (pre-fire slot verification)...", level="PHASE") while time.time() < TARGET_TS - 0.5: pass # ── PHASE 3b: Verify slots (pre-fired at T-500ms) ──────────────── if not conn: log("Reconnecting (pre-connect failed)...", level="WARN") t0 = time.time() ctx = ssl.create_default_context() conn = http.client.HTTPSConnection(HOST, PORT, context=ctx, timeout=20) conn.connect() conn.sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1) t1 = bench("TLS_RECONNECT", "", t0) log(f"Phase 3b: Verify available slots (getHorasCitas, pre-fired) ...", level="PHASE") t0 = time.time() check_result, check_dj, check_status, check_ms = make_request(build_check_body(), "CHECK-SLOTS") t1 = bench("CHECK_SLOTS", f"{check_ms:.0f}ms — {check_result[:100]}", t0) available_slots = [] if check_dj: try: slots = json.loads(check_dj.get('result', '[]')) available_slots = [s['hora'] for s in slots] log(f" {len(available_slots)} slots available: {available_slots}", level="INFO") except Exception as e: log(f" Parse warning: {e}", level="WARN") available_slots = ALL_HORAS # safe fallback else: available_slots = ALL_HORAS # fallback on parse error # ── PHASE 3c: Busy-wait to T-40ms (pre-fire window for booking) ── # Fire the first booking request 40ms before OUR midnight. The one-way network # latency (~40ms) means it arrives at the server AT their midnight, making the # network delay FREE. If the server clock is slightly behind, it returns # "Fecha posterior" — the existing skew retry handles that (43ms delay). PREFIRE_OFFSET = 0.040 # one-way RTT to webservices.alicante.es (~38-48ms) log(f"Phase 3c: Busy-wait to T-{PREFIRE_OFFSET*1000:.0f}ms (pre-fire booking window) ...", level="PHASE") while time.time() < TARGET_TS - PREFIRE_OFFSET: pass t_prefire = time.time() log(f"*** PRE-FIRE WINDOW (T-{PREFIRE_OFFSET*1000:.0f}ms) ***", level="PHASE") log(f" First booking request fires now → arrives @ server ~T+0ms", level="PHASE") log(f" Pre-fire jitter: {(t_prefire - (TARGET_TS - PREFIRE_OFFSET))*1000:+.1f}ms", level="PHASE") # ── PHASE 4: Attempt booking (fires at T-40ms, arrives @ server T+0) ── log(f"\nPhase 4: Sequential booking attempts...", level="PHASE") log(f" Priority order: {PRIORITY}", level="PHASE") log(f" Only trying slots confirmed available: {[h for h in PRIORITY if h in available_slots]}", level="PHASE") # ── Booking timing infrastructure ──────────────────────────── t_booking_start = time.time() # total time-to-success reference slot_timings = [] # per-slot breakdown: {hora, total_ms, attempts, avg_rtt_ms, status} # IMPORTANT: This loop fires ONE request at a time. # It EXITS immediately on success — "Cita insertada" means the cita was ALREADY # inserted into the database, so no further booking action is needed; we just # confirm and stop. # Each slot is tried ONCE, with retries ONLY for: # - "Fecha posterior" (server date not rolled): EACH slot gets its own independent # 3-phase backoff (43ms×1.5^n first 6, 1.15x gradual to 500ms, 2s×1.2^n extended # to 120s). WE ARE FIGHTING BOTS — every slot retries until certified taken. # - "EXCEPTION:" (conn drop): force-reconnect + retry on SAME slot # - "Hora no permitida": DEFINITIVE certification slot is taken → no retry # Each slot's retry window is independent — the server date may roll during # a later slot's retries even if earlier slots exhausted theirs. # Only give up on a slot when: certified taken ("Hora no permitida") or # time budget exhausted (can't certify further) or duplicate detected. # Duplicate detection ("ya existente"/"DNI"/"existe") at ANY point → STOP immediately. # This prevents duplicate bookings while tolerating clock/network issues. attempts = [] # in-memory log of all attempts booked_hora = None booked_result = None # Each slot tracks skew retry exhaustion independently — NO global skip flag. # The server date may roll during another slot's retry window, so every # slot must get its own full 120s three-phase backoff chance to hit midnight. skew_retries_exhausted = False # diagnostics only (per-slot, not global skip) duplicate_detected = False # STOP entire booking process if cita already exists for hora in PRIORITY: if hora not in available_slots: log(f" ↷ {hora}: SKIP (not in available list from Phase 3)") attempts.append({"hora": hora, "status": "skipped", "response": "not in available list"}) continue body = build_booking_body(hora) t0 = time.time() t_slot_start = time.time() # per-slot total timing slot_attempt_count = 0 # attempts for this slot slot_rtts = [] # response times for this slot result, dj, status, ms = make_request(body, "BOOKING") slot_attempt_count = 1 slot_rtts.append(ms) # raw RTT, rounding deferred to display t1 = bench("BOOKING_ATTEMPT", f"{hora} → {ms:.0f}ms — {result[:150]}", t0) attempts.append({ "hora": hora, "status": status, "response": result, "elapsed_ms": round(ms, 1), "timestamp": datetime.now().strftime('%H:%M:%S.%f')[:-3] }) if result == "Cita insertada": booked_hora = hora booked_result = result t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 t_success_total = (t_slot_end - t_booking_start) * 1000 t_prefire_to_success = (t_slot_end - t_prefire) * 1000 slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(sum(slot_rtts)/len(slot_rtts), 1), "status": "booked", "rtts": slot_rtts }) log(f"\n✅✅✅ CITA BOOKED! ✅✅✅", level="SUCCESS") log(f" Hora: {hora}", level="SUCCESS") log(f" Fecha: {FECHA}", level="SUCCESS") log(f" {NOMBRE} {APE1} {APE2} — NIE: {DOC}", level="SUCCESS") log(f" Cola: {COLA} (C/PORTUGAL 17 TARDE - PADRÓN)", level="SUCCESS") log(f" Motivo: {COMENTARIO}", level="SUCCESS") log(f" Server load: {_current_load()}", level="SUCCESS") log(f" Response time: {ms:.0f}ms", level="SUCCESS") log(f" Slot total: {slot_total_ms:.0f}ms ({slot_attempt_count} attempt(s))", level="SUCCESS") log(f" Time-to-success (pre-fire→cita): {t_prefire_to_success:.0f}ms", level="SUCCESS") log(f" Time-to-success (booking start→cita): {t_success_total:.0f}ms", level="SUCCESS") # CRITICAL: exit immediately — no more requests sent break elif result == "Hora no permitida": t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(sum(slot_rtts)/len(slot_rtts), 1), "status": "taken_certified", "rtts": slot_rtts }) load = _current_load() # _track_rtt already called in make_request — no double-track log(f" → Slot {hora}: certified taken in {slot_total_ms:.0f}ms (load: {load}). Moving to next.", level="WARN") elif result == "Fecha posterior al limite permitido": # "Fecha posterior" is NOT a certification — the server date simply # hasn't rolled yet. We must keep retrying until one of these: # 1. Booking succeeds → "Cita insertada" (slot available, not taken) # 2. Slot certified taken → "Hora no permitida" on retry # 3. Duplicate detected → "ya existente" / "DNI" / "existe" / "Usted ya tiene cita previa" # 4. Other definitive error → non-Fecha-posterior response # 5. Time budget exhausted (120s) → cannot certify, try next slot log(f" → Date beyond server limit. Retrying {hora} with 3-phase backoff...", level="WARN") t_slot_start = time.time() skew_attempt = 0 while skew_attempt < SKEW_MAX_RETRIES: elapsed = time.time() - t_slot_start if elapsed >= SKEW_MAX_BUDGET: t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 avg_rtt = sum(slot_rtts) / len(slot_rtts) if slot_rtts else 0 slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(avg_rtt, 1), "status": "budget_exhausted", "rtts": slot_rtts }) load = _current_load() log(f" → {hora}: {elapsed:.1f}s budget exhausted (load: {load}). {slot_attempt_count} attempts. Next slot gets fresh window.", level="WARN") skew_retries_exhausted = True # diagnostics only — does NOT skip future slots break # Three-phase pseudo-exponential backoff: # Phase 1 (attempts 1-6): 43ms × 1.5^n — aggressive, midnight-fast # Phase 2 (attempts 7-12): 330ms × 1.15^n, capped 500ms — less spammy # Phase 3 (attempt 13+): 2s × 1.2^n, capped 15s — extended, catches cancellations delay = _skew_delay(skew_attempt) delay = min(delay, SKEW_MAX_BUDGET - elapsed) # don't sleep past budget time.sleep(delay) skew_attempt += 1 t0b = time.time() result2, _, _, ms2 = make_request(body, f"RETRY-SKEW{skew_attempt}") slot_attempt_count += 1 slot_rtts.append(ms2) # raw RTT, rounding deferred to display t1 = bench("RETRY", f"{hora} → {ms2:.0f}ms — {result2[:150]}", t0b, category="SKEW") attempts.append({"hora": hora, "status": f"retry-skew{skew_attempt}", "response": result2, "elapsed_ms": round(ms2, 1)}) if result2 == "Cita insertada": booked_hora = hora booked_result = result2 t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 t_success_total = (t_slot_end - t_booking_start) * 1000 t_prefire_to_success = (t_slot_end - t_prefire) * 1000 avg_rtt = sum(slot_rtts) / len(slot_rtts) slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(avg_rtt, 1), "status": "booked_on_retry", "rtts": slot_rtts }) log(f"\n✅ CITA BOOKED (on skew retry {skew_attempt})! Hora: {hora}", level="SUCCESS") log(f" Attempts: {slot_attempt_count} | Slot total: {slot_total_ms:.0f}ms | Avg RTT: {avg_rtt:.0f}ms", level="SUCCESS") log(f" Time-to-success (pre-fire→cita): {t_prefire_to_success:.0f}ms | (booking start→cita): {t_success_total:.0f}ms", level="SUCCESS") break elif _is_duplicate(result2): # covers "ya existente", "DNI", "existe", "Usted ya tiene cita previa" log(f" → DUPLICATE on retry: {result2[:200]} — STOPPING", level="ERROR") duplicate_detected = True # signal outer loop to STOP entirely break elif result2 == "Hora no permitida": # ✅ CERTIFIED: slot is genuinely taken — safe to give up THIS slot t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 avg_rtt = sum(slot_rtts) / len(slot_rtts) slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(avg_rtt, 1), "status": "taken_certified_on_retry", "rtts": slot_rtts }) log(f" → Slot {hora}: certified taken on retry {skew_attempt} (load: {_current_load()}). Moving to next.", level="WARN") break elif result2 != "Fecha posterior al limite permitido": # Non-certifying error — log and move on t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 avg_rtt = sum(slot_rtts) / len(slot_rtts) slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(avg_rtt, 1), "status": f"error: {result2[:50]}", "rtts": slot_rtts }) log(f" → Retry returned: {result2[:100]} — moving on", level="WARN") break # else: still "Fecha posterior" → NOT certified → keep retrying if booked_hora or duplicate_detected: break # success OR duplicate certifies — do NOT try any more slots elif _is_duplicate(result): # covers "ya existente", "DNI", "existe", "Usted ya tiene cita previa" t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(sum(slot_rtts)/len(slot_rtts), 1), "status": "duplicate", "rtts": slot_rtts }) log(f" → DUPLICATE: {result[:200]} — STOPPING", level="ERROR") break elif result.startswith("EXCEPTION:"): log(f" → Network ERROR: {result[:150]}", level="WARN") # make_request already tried reconnecting once. Try force-reconnect now. try: ctx = ssl.create_default_context() conn = http.client.HTTPSConnection(HOST, PORT, context=ctx, timeout=20) conn.connect() conn.sock.setsockopt(socket.IPPROTO_TCP, socket.TCP_NODELAY, 1) log(" → Force-reconnected ✓ — retrying booking", level="WARN") t0r = time.time() result_retry, _, _, ms2 = make_request(body, "RETRY-CONN") slot_attempt_count += 1 slot_rtts.append(ms2) # raw RTT, rounding deferred to display bench("RETRY", f"{hora} → {ms2:.0f}ms — {result_retry[:150]}", t0r, category="RECOVERY") attempts.append({"hora": hora, "status": "retry-conn", "response": result_retry, "elapsed_ms": round(ms2, 1)}) if result_retry == "Cita insertada": booked_hora = hora booked_result = result_retry t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 t_success_total = (t_slot_end - t_booking_start) * 1000 t_prefire_to_success = (t_slot_end - t_prefire) * 1000 avg_rtt = sum(slot_rtts) / len(slot_rtts) slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(avg_rtt, 1), "status": "booked_after_reconnect", "rtts": slot_rtts }) log(f"\n✅ CITA BOOKED (on retry after conn error)! Hora: {hora}", level="SUCCESS") log(f" Attempts: {slot_attempt_count} | Slot total: {slot_total_ms:.0f}ms | Avg RTT: {avg_rtt:.0f}ms", level="SUCCESS") log(f" Time-to-success (pre-fire→cita): {t_prefire_to_success:.0f}ms | (booking start→cita): {t_success_total:.0f}ms", level="SUCCESS") break elif _is_duplicate(result_retry): # covers "ya existente", "DNI", "existe", "Usted ya tiene cita previa" log(f" → DUPLICATE after reconnect: {result_retry[:200]} — STOPPING", level="ERROR") duplicate_detected = True break elif result_retry.startswith("EXCEPTION:"): log(f" → Connection retry also failed — moving to next slot", level="WARN") elif result_retry == "Hora no permitida": log(f" → Slot {hora} taken after reconnect — moving to next.", level="WARN") elif result_retry == "Fecha posterior al limite permitido": log(f" → Retry also hit date limit — moving to next slot", level="WARN") else: log(f" → Retry result: {result_retry[:100]}", level="WARN") except Exception as e: log(f" → Force-reconnect failed: {e}", level="ERROR") else: # Catch-all for any other server response — stop to avoid accidental double-booking t_slot_end = time.time() slot_total_ms = (t_slot_end - t_slot_start) * 1000 slot_timings.append({ "hora": hora, "total_ms": round(slot_total_ms, 1), "attempts": slot_attempt_count, "avg_rtt_ms": round(sum(slot_rtts)/len(slot_rtts), 1), "status": f"unexpected: {result[:50]}", "rtts": slot_rtts }) log(f" → Unexpected server response: {result[:150]}", level="WARN") log(f" Stopping to avoid accidental duplication. Add to DUPLICATE_PATTERNS if this is a known duplicate signal.", level="WARN") break # Small delay between attempts (avoid overwhelming server) time.sleep(0.03) # ── PHASE 5: Post-booking verification ───────────────────── if booked_hora: log(f"\nPhase 5: Verifying booking (getHorasCitas — slot should be gone)...", level="PHASE") t0 = time.time() verify_result, verify_dj, _, verify_ms = make_request(build_check_body(), "VERIFY") t1 = bench("VERIFY", f"{verify_ms:.0f}ms", t0) verify_slots = [] if verify_dj: try: slots = json.loads(verify_dj.get('result', '[]')) verify_slots = [s['hora'] for s in slots] except: pass if booked_hora not in verify_slots: log(f" ✅ VERIFIED: Slot {booked_hora} is gone from available list — booking confirmed!", level="SUCCESS") log(f" Remaining slots on Oct 19: {verify_slots}") else: log(f" ⚠️ WARNING: Slot {booked_hora} still appears available — booking may not have fully committed", level="WARN") log(f" Slots still showing: {verify_slots}") # ── BENCHMARK SUMMARY ─────────────────────────────────────── log(f"\n{'='*60}", level="PHASE") log(f"BENCHMARK SUMMARY — {len(BENCH)} steps, {len(attempts)} booking attempts", level="PHASE") # Server load analysis log(f"\n ── SERVER LOAD ESTIMATION ──") log(f" RTT observations: {len(_rtt_history)} measurements") log(f" Current load: {_current_load()}") if _rtt_history: all_rtt_avg = round(sum(_rtt_history) / len(_rtt_history), 1) log(f" Session avg RTT: {all_rtt_avg}ms") if len(_rtt_history) > 1: log(f" Min RTT: {min(_rtt_history):.0f}ms | Max RTT: {max(_rtt_history):.0f}ms") trend_label, first_avg, second_avg = _load_trend() log(f" Load trend: {trend_label}") if first_avg > 0: log(f" First-half avg: {first_avg:.0f}ms ({len(_rtt_history)//2} samples)") log(f" Second-half avg: {second_avg:.0f}ms ({len(_rtt_history) - len(_rtt_history)//2} samples)") # Per-slot timing summary log(f"\n ── PER-SLOT TIMING ──") log(f" {'Hora':<8} {'Total ms':>10} {'Attempts':>10} {'Avg RTT':>10} {'Status':<25}") log(f" {'─'*9 + ' ─':>8} {'─'*10} {'─'*10} {'─'*10} {'─'*25}") for st in slot_timings: log(f" {st['hora']:<8} {st['total_ms']:>10.1f} {st['attempts']:>10} {st['avg_rtt_ms']:>10.1f} {st['status']:<25}") # Time-to-success summary if booked_hora: t_total = (time.time() - t_booking_start) * 1000 log(f"\n ── TIME TO SUCCESS ──") log(f" Time from pre-fire to booking: {t_total:.0f}ms") log(f" Slots tried: {len(slot_timings)}") total_attempts = sum(st['attempts'] for st in slot_timings) log(f" Total requests sent: {total_attempts}") for b in BENCH: log(f" {b['time']} [{b['ms']:7.1f}ms] [{b.get('category', 'REQUEST'):>12}] {b['step']}: {b['detail']}") # Persist benchmark log with open(log_file, 'w') as f: f.write(f"Booking log — {datetime.now().strftime('%Y-%m-%d %H:%M:%S')}\n") f.write(f"NIE: {DOC} Cola: {COLA} Fecha: {FECHA}\n") f.write(f"Tracking: None (clean motivo)\n\n") f.write("=== ATTEMPTS ===\n") for a in attempts: f.write(json.dumps(a, indent=2) + "\n") f.write("\n=== TIMING ===\n") for b in BENCH: f.write(f"{b['time']} [{b['ms']:7.1f}ms] [{b.get('category', 'REQUEST'):>12}] {b['step']}: {b['detail']}\n") f.write("\n=== PER-SLOT TIMING ===\n") for st in slot_timings: f.write(json.dumps(st, indent=2) + "\n") f.write("\n=== SERVER LOAD ===\n") f.write(f"RTT observations: {len(_rtt_history)}\n") f.write(f"Current load: {_current_load()}\n") f.write(f"Session avg RTT: {round(sum(_rtt_history)/len(_rtt_history), 1) if _rtt_history else 'N/A'}ms\n") f.write(f"Load trend: {_load_trend()[0]}\n") log(f"\nLog persisted to: {log_file}", level="PHASE") if booked_hora: log(f"\n🎉 SUCCESS: Cita for {NOMBRE} on {FECHA} at {booked_hora}", level="SUCCESS") log(f" To view/cancel: use NIF={DOC}, Service=SI (composite code: SIX2491454W)") log(f" Cancel API: anularCitaInsertadaCodigo with codigoCita from obtenerCitaInsertada") sys.exit(0) else: log(f"\n❌ FAILED: All {len(attempts)} attempts exhausted. Competing requests likely grabbed all 9 slots.", level="ERROR") log(f"New slots open daily for the next working day — try again tomorrow.", level="ERROR") sys.exit(1)