citas-getter/book_final.py

#!/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)