sergio/takana

1#!/usr/bin/env python3
2"""atuq-en-imagen.py — arranca la IMAGEN DE DISCO con COSMIC y le pide al navegador que pinte.
3
4    scripts/cosmic/atuq-en-imagen.py                # lanza atuq y fotografía la pantalla
5    scripts/cosmic/atuq-en-imagen.py --only-cosmic  # control: NO lanza atuq (línea de base)
6
7── POR QUÉ ────────────────────────────────────────────────────────────────────────────────────
8El §6.10.ter del SDD 26 dejó esto medido y sin explicar: en la imagen arrancada `atuq` corre —sus
9extensiones sondean, WebRender inicializa— y la ventana NO APARECE, mientras que bajo `sway` headless
10el mismo artefacto pinta. `scripts/cosmic/atuq-en-cosmic.sh` ya sacó una variable de encima:
11**con cosmic-comp NESTEADO (backend winit, GL por software) el navegador pinta**, o sea que no es el
12compositor por sí mismo. Lo que queda es el arranque de verdad: kms/DRM sobre virtio-gpu, el PID1 de
13arje, el seat. Eso sólo se mide acá adentro.
14
15La corrida anterior fue A MANO por el serial y no dejó ni un log que se pueda releer. Este guion
16hace lo mismo pero REPETIBLE y con la evidencia guardada: maneja el serial, lanza el navegador con
17`MOZ_LOG` del widget de Wayland, pide capturas por QMP y saca los logs por el serial.
18
19── CÓMO HABLA CON LA VM ───────────────────────────────────────────────────────────────────────
20`console-getty` corre `cosmic-start`, que tras su ventana de observación (3 min) hace `exec /bin/sh`
21CON EL ENTORNO DE LA SESIÓN puesto (WAYLAND_DISPLAY, DBUS_SESSION_BUS_ADDRESS). O sea que el shell
22del serial es exactamente desde donde un usuario lanzaría una app — y por eso no hace falta
23reconstruir el entorno a mano, que es como se inventan diferencias que después se confunden con la
24causa.
25"""
26import argparse, json, os, shutil, socket, subprocess, sys, time
27
28# Sin esto la salida sale por tandas cuando se redirige a un fichero, y una corrida de 20 minutos se
29# lee como si estuviera colgada.
30sys.stdout.reconfigure(line_buffering=True)
31
32RAIZ = os.path.dirname(os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
33IMG = os.environ.get("IMG", "/mnt/cosecha/takana-cosmic-qemu.img")
34OVMF_CODE = os.environ.get("OVMF_CODE", "/usr/share/edk2/x64/OVMF_CODE.4m.fd")
35OVMF_VARS = os.environ.get("OVMF_VARS", "/usr/share/edk2/x64/OVMF_VARS.4m.fd")
36MEM = os.environ.get("MEM", "2560")
37SMP = os.environ.get("SMP", "2")
38
39# ⚠ `VGA=1` reproduce el arranque del §6.10.ter, y la diferencia NO es cosmética: sin `-vga none`,
40# QEMU agrega una VGA estándar ADEMÁS del virtio-gpu, OVMF pinta su GOP ahí y el kernel levanta
41# `simpledrm` encima ⇒ el guest ve DOS dispositivos DRM. En el serial se lee tal cual:
42#
43#     == cosmic :: kernel 6.16.12 · drm: card0 card1 renderD128    (corrida del §6.10.ter)
44#     == cosmic :: kernel 6.16.12 · drm: card0 renderD128          (con -vga none)
45#
46# Un compositor con dos tarjetas puede componer en la que el `screendump` NO muestra. Por eso el
47# default acá es UNA sola (-vga none) y la reproducción del caso original es una opción explícita:
48# son dos mediciones distintas y hay que poder pedir cada una por su nombre.
49# Las dos pantallas van con ID EXPLÍCITO (`vga0`, `gpu0`) y no por el `-vga std` implícito, porque
50# `screendump` de QMP fotografía UN dispositivo y hay que poder pedir cada uno por su nombre: con dos
51# salidas, el compositor puede poner la ventana en la que la captura por defecto NO muestra, y eso se
52# ve exactamente igual que «la ventana no aparece».
53DOS_PANTALLAS = os.environ.get("VGA") == "1"
54VGA_ARGS = (["-vga", "none", "-device", "VGA,id=vga0"] if DOS_PANTALLAS else ["-vga", "none"])
55PANTALLAS = ["gpu0", "vga0"] if DOS_PANTALLAS else ["gpu0"]
56
57
58class Serial:
59    """El serial de la VM. Todo lo que entra queda en el .log crudo, pase lo que pase."""
60
61    def __init__(self, ruta, log):
62        self.log = open(log, "ab", buffering=0)
63        for _ in range(120):
64            try:
65                self.s = socket.socket(socket.AF_UNIX); self.s.connect(ruta); break
66            except OSError:
67                time.sleep(0.5)
68        else:
69            raise SystemExit(f"no pude conectarme al serial {ruta}")
70        self.s.settimeout(1.0)
71        self.buf = b""
72
73    def leer(self, segundos):
74        fin = time.time() + segundos
75        while time.time() < fin:
76            try:
77                d = self.s.recv(65536)
78            except socket.timeout:
79                continue
80            if not d:
81                break
82            self.buf += d; self.log.write(d)
83        return self.buf
84
85    def esperar(self, marca, segundos, nombre=""):
86        """Lee hasta ver `marca`. Devuelve lo leído desde la llamada anterior."""
87        vistos = len(self.buf)
88        fin = time.time() + segundos
89        while time.time() < fin:
90            try:
91                d = self.s.recv(65536)
92            except socket.timeout:
93                continue
94            if d:
95                self.buf += d; self.log.write(d)
96            if marca.encode() in self.buf[vistos:]:
97                return self.buf[vistos:].decode("utf-8", "replace")
98        print(f"   ⚠ nunca llegó «{marca}» {nombre} en {segundos}s", flush=True)
99        return self.buf[vistos:].decode("utf-8", "replace")
100
101    def cmd(self, orden, segundos=30, fondo=False):
102        """Manda una orden y devuelve su salida (delimitada por una marca propia).
103
104        ⚠ DOS TRAMPAS MEDIDAS, las dos hacen que la orden NO CORRA y el guion siga como si nada:
105
106        · **el terminal hace ECO de lo que se le escribe**, así que una marca escrita literal en la
107          línea aparece en el serial ANTES de que el shell ejecute nada: el `esperar` la ve en el eco
108          y vuelve al instante, y las órdenes se pisan unas a otras. Por eso la marca se ARMA EN EL
109          GUEST partida en dos (`'FIN''-123'`): el eco muestra las comillas y sólo la salida trae la
110          marca entera.
111        · **`cmd & ; echo …` es un error de sintaxis** en ash: pegarle un `;` a un `&` no lanza nada
112          y el shell contesta «syntax error». Lo de fondo va en su propia línea (`fondo=True`).
113        """
114        n = int(time.time() * 1000) % 100000
115        marca = f"FIN-{n}"
116        if fondo:
117            self.s.sendall(f"{orden}\n".encode()); time.sleep(0.5)
118            self.s.sendall(f"echo 'FIN''-{n}'\n".encode())
119        else:
120            self.s.sendall(f"{orden}; echo 'FIN''-{n}'\n".encode())
121        return self.esperar(marca, segundos, nombre=f"de «{orden[:40]}»")
122
123
124def capturar(ruta_qmp, out, nombre):
125    """Fotografía CADA pantalla del guest y devuelve {pantalla: fichero}.
126
127    Con dos salidas hay que mirar las dos: la ventana puede estar viva y dibujando en la que no se
128    fotografía, y eso es indistinguible de «no pinta» si sólo se mira una.
129    """
130    ficheros = {p: os.path.join(out, f"{nombre}-{p}.ppm") for p in PANTALLAS}
131    qmp(ruta_qmp, [{"execute": "screendump", "arguments": {"filename": f, "device": p}}
132                   for p, f in ficheros.items()])
133    return ficheros
134
135
136def pintado(ppm):
137    """¿Cuántos píxeles de la pantalla son la página de prueba?
138
139    Se cuenta el magenta con TOLERANCIA, no por color exacto, y la razón está medida: a los ~+590 s
140    sin una sola entrada `cosmic-idle` ATENÚA la pantalla y los 703 766 px de `(255,0,255)` pasan a
141    703 779 px de `(117,0,117)` —la misma ventana al 46 % de brillo—. Un contador por color exacto
142    lee eso como «desapareció la ventana», que es justo el error que este guion existe para no
143    cometer.
144    """
145    try:
146        from PIL import Image
147    except Exception:
148        return None
149    im = Image.open(ppm).convert("RGB")
150    return sum(n for n, (r, g, b) in im.getcolors(1 << 24) if r > 90 and b > 90 and g < 40)
151
152
153def anotar_medicion(segundos, a, pantalla=None):
154    """Deja el tiempo de primera pintura en `docs/state/primera-pintura.json`.
155
156    Va al estado del repo y no a un log porque quien pregunta «¿esta imagen se puede usar?» es
157    `scripts/vigia-imagen.py`, que mira artefactos y no arranca ninguna VM: el número tiene que
158    llegarle por escrito o no le llega. Se guarda TODO lo que lo hace comparable —cómo se lanzó, con
159    qué vídeo, con cuánta RAM y cuántos cores— porque el tiempo depende de eso y de la carga de la
160    máquina anfitriona; un número sin sus condiciones invita a leerlo como si fuera del producto.
161    """
162    dato = {
163        "medido": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()),
164        "imagen": IMG,
165        "segundos_primera_pintura": segundos,          # None = no pintó dentro de la ventana
166        "pantalla": pantalla,                          # EN CUÁL de las salidas apareció (medido 2026-09-14:
167                                                       # con dos, la ventana cae en cualquiera de las dos)
168        "pantallas_fotografiadas": len(PANTALLAS),     # con 1 y dos salidas, un ✗ NO es concluyente
169        "presupuesto_s": a.budget,
170        "ventana_s": a.wait,
171        "cadencia_s": a.cadence,                       # la RESOLUCIÓN del número: ±cadencia
172        "lanzamiento": "perfil del usuario" if a.as_user else "perfil nuevo en tmpfs",
173        "video": "vga+virtio-gpu (dos DRM)" if DOS_PANTALLAS else "virtio-gpu solo (-vga none)",
174        "mem_mb": int(MEM), "vcpus": int(SMP), "acel": "tcg",
175        "guion": "scripts/cosmic/atuq-en-imagen.py",
176    }
177    # ⚠ SE ACUMULAN, NO SE PISAN. Medido el 2026-09-14: dos corridas IDÉNTICAS (mismo comando,
178    # misma imagen) dieron «+204 s» y «no pintó en 900 s». Un fichero de UNA medición convierte un
179    # fenómeno intermitente en el número que le tocó a la última corrida, que es la forma más cara
180    # de mentir con datos ciertos.
181    destino = os.path.join(RAIZ, "docs/state/primera-pintura.json")
182    try:
183        historia = {"corridas": []}
184        if os.path.exists(destino):
185            with open(destino) as f:
186                historia = json.load(f)
187        historia.setdefault("corridas", []).append(dato)
188        historia["corridas"] = historia["corridas"][-30:]
189        os.makedirs(os.path.dirname(destino), exist_ok=True)
190        with open(destino, "w") as f:
191            json.dump(historia, f, indent=2, ensure_ascii=False)
192            f.write("\n")
193        pintaron = [c for c in historia["corridas"] if c.get("segundos_primera_pintura") is not None]
194        print("   anotada en docs/state/primera-pintura.json — %d de %d corridas pintaron"
195              % (len(pintaron), len(historia["corridas"])))
196    except (OSError, ValueError) as e:
197        print(f"   ⚠ no pude anotar la medición: {e}")
198
199
200def qmp(ruta, ordenes):
201    s = socket.socket(socket.AF_UNIX); s.settimeout(30); s.connect(ruta)
202    f = s.makefile("rwb", buffering=0)
203    f.readline()                                   # greeting
204    f.write(b'{"execute":"qmp_capabilities"}\n'); f.readline()
205    salidas = []
206    for o in ordenes:
207        f.write(json.dumps(o).encode() + b"\n"); salidas.append(f.readline())
208    s.close()
209    return salidas
210
211
212def main():
213    ap = argparse.ArgumentParser()
214    ap.add_argument("--only-cosmic", action="store_true", help="control: no lanza el navegador")
215    ap.add_argument("--as-user", action="store_true",
216                    help="lanza `atuq` a secas —perfil por defecto, sin MOZ_ENABLE_WAYLAND— como se hizo a mano en el §6.10.ter")
217    ap.add_argument("--wait", type=int, default=600, help="segundos de observación como máximo")
218    ap.add_argument("--cadence", type=int, default=30, help="segundos entre capturas (la resolución de la medida)")
219    ap.add_argument("--budget", type=int, default=420,
220                    help="segundos que puede tardar la primera pintura antes de dar ✗")
221    ap.add_argument("--until-paint", action="store_true",
222                    help="cortar la observación en cuanto la página aparezca (más barato para medir el tiempo)")
223    ap.add_argument("--wayland-debug", action="store_true",
224                    help="lanza el navegador con WAYLAND_DEBUG=1: registra CADA mensaje del "
225                         "protocolo en los dos sentidos. Es la única forma de ver qué MANDA el "
226                         "compositor sin recompilarlo (sus macros de debug están compiladas fuera)")
227    ap.add_argument("--set-rust-log", metavar="VALOR",
228                    help="escribe RUST_LOG en /etc/cosmic-mode de la IMAGEN y apaga; "
229                         "cadena vacía = lo quita. El compositor lo lee en el arranque SIGUIENTE, "
230                         "que es la única forma de subirle el nivel de log sin recompilar")
231    ap.add_argument("--out", default=os.path.join(RAIZ, "work/atuq-imagen"))
232    a = ap.parse_args()
233
234    rc = [0]                 # lista para poder tocarlo desde dentro del try/finally
235    out = a.out; os.makedirs(out, exist_ok=True)
236    vars_fd = os.path.join(out, "OVMF_VARS.fd")
237    shutil.copy(OVMF_VARS, vars_fd)
238    ser_sock, qmp_sock = os.path.join(out, "serial.sock"), os.path.join(out, "qmp.sock")
239    for p in (ser_sock, qmp_sock):
240        if os.path.exists(p):
241            os.unlink(p)
242
243    qemu = [
244        "nice", "-n", "10", "qemu-system-x86_64",
245        "-machine", "q35", "-accel", "tcg", "-cpu", "max", "-m", MEM, "-smp", SMP,
246        *VGA_ARGS, "-device", "virtio-gpu-pci,id=gpu0", "-display", "none", "-nic", "none",
247        "-drive", f"if=pflash,format=raw,unit=0,file={OVMF_CODE},readonly=on",
248        "-drive", f"if=pflash,format=raw,unit=1,file={vars_fd}",
249        "-drive", f"file={IMG},format=raw,if=virtio",
250        "-serial", f"unix:{ser_sock},server,nowait",
251        "-qmp", f"unix:{qmp_sock},server,nowait",
252        "-no-reboot",
253    ]
254    print("== arrancando la imagen (TCG, sin KVM — paciencia)")
255
256    def primero_en_la_fila():
257        # El repo es COMPARTIDO y casi siempre hay una tanda de la granja compilando en esta misma
258        # máquina (4 cores, 7,6 G). Si la RAM se acaba, el que tiene que morir es ESTA VM y no el
259        # build de otro agente: `oom_score_adj` alto es la única forma de decirlo por adelantado.
260        with open("/proc/self/oom_score_adj", "w") as f:
261            f.write("900")
262
263    vm = subprocess.Popen(qemu, stdout=open(os.path.join(out, "qemu.log"), "wb"),
264                          stderr=subprocess.STDOUT, preexec_fn=primero_en_la_fila)
265    try:
266        ser = Serial(ser_sock, os.path.join(out, "serial.log"))
267        print("== esperando a COSMIC…", flush=True)
268        ser.esperar("compositor OK", 600, nombre="(arranque de cosmic-comp)")
269        print("   compositor arriba; esperando el shell del serial (ventana de observación)", flush=True)
270        # 420 s alcanzaban con el anfitrión ocioso y NO con carga ~13: la VM llegaba a «+15s» y el
271        # arnés se rendía antes de que `cosmic-start` soltara el shell. El margen es de espera, no de
272        # medida: subirlo no cambia ningún número, sólo deja de tirar corridas por carga ajena.
273        ser.esperar("fin de la ventana de observación", 780, nombre="(fin de observación)")
274        time.sleep(3)
275        ser.s.sendall(b"\n")
276        print(ser.cmd("echo ENTORNO: WD=$WAYLAND_DISPLAY XDG=$XDG_RUNTIME_DIR DBUS=$DBUS_SESSION_BUS_ADDRESS").strip())
277        print(ser.cmd("ls -l $XDG_RUNTIME_DIR; ls /usr/lib/dri").strip())
278
279        if a.set_rust_log is not None:
280            # `cosmic-start` hace `. /etc/cosmic-mode` ANTES de `export RUST_LOG="${RUST_LOG:-info}"`,
281            # así que el fichero es la perilla. Se escribe y se apaga: quien la usa es el arranque
282            # siguiente — el compositor de ESTA sesión ya arrancó y no se lo puede reconfigurar.
283            ser.cmd("grep -v '^RUST_LOG=' /etc/cosmic-mode > /tmp/cm 2>/dev/null; true")
284            if a.set_rust_log:
285                ser.cmd("printf '%%s\\n' \"RUST_LOG=%s\" >> /tmp/cm" % a.set_rust_log)
286            ser.cmd("cp /tmp/cm /etc/cosmic-mode && sync")
287            print("== /etc/cosmic-mode ahora dice:")
288            print(ser.cmd("cat /etc/cosmic-mode").strip())
289            return
290
291        capturar(qmp_sock, out, "antes")
292        print("== captura ANTES (%s)" % ", ".join(PANTALLAS), flush=True)
293
294        if a.only_cosmic:
295            print("== CONTROL: no se lanza el navegador")
296        else:
297            # Una página de un color imposible de confundir con el escritorio.
298            ser.cmd("mkdir -p /tmp/perfil /var/log/cosmic")
299            ser.cmd("printf '%s' '<!doctype html><body style=\"margin:0;background:#ff00ff\">"
300                    "<h1 style=\"font:40px monospace\">ATUQ PINTA</h1>' > /tmp/pagina.html")
301            ser.cmd("printf '%s\\n' 'user_pref(\"browser.dom.window.dump.enabled\", true);' > /tmp/perfil/user.js")
302            ser.cmd("printf '%s\\n' 'user_pref(\"browser.shell.checkDefaultBrowser\", false);' >> /tmp/perfil/user.js")
303            # ⚠ LOS DOS LANZAMIENTOS NO SON EL MISMO EXPERIMENTO. El de por defecto fija el
304            # entorno (perfil nuevo, `MOZ_ENABLE_WAYLAND`) para que la medición no dependa de lo que
305            # haya quedado en el estado del usuario; `--como-usuario` reproduce lo que se tecleó a
306            # mano en el §6.10.ter —`atuq` pelado, con SU perfil y sin variables— que es lo único que
307            # sigue distinto entre aquella corrida y ésta. El `MOZ_LOG` va en los dos: no cambia el
308            # comportamiento, sólo deja rastro.
309            wd = "WAYLAND_DEBUG=1 " if a.wayland_debug else ""
310            if a.as_user:
311                lanz = (wd + "MOZ_LOG='Widget:5,WidgetWayland:5,WaylandBackend:5,timestamp' "
312                        "MOZ_LOG_FILE=/var/log/cosmic/moz "
313                        "/usr/bin/atuq file:///tmp/pagina.html > /var/log/cosmic/atuq.log 2>&1 &")
314            else:
315                lanz = (wd + "MOZ_ENABLE_WAYLAND=1 GDK_BACKEND=wayland "
316                        "MOZ_LOG='Widget:5,WidgetWayland:5,WaylandBackend:5,timestamp' "
317                        "MOZ_LOG_FILE=/var/log/cosmic/moz "
318                        "/usr/bin/atuq --no-remote --profile /tmp/perfil file:///tmp/pagina.html "
319                        "> /var/log/cosmic/atuq.log 2>&1 &")
320            print(ser.cmd(lanz, fondo=True).strip())
321            print(f"== navegador lanzado; observando {a.wait}s", flush=True)
322            t0 = time.time(); n = 0
323            primera = None           # segundos hasta la PRIMERA captura con la página en pantalla
324            while time.time() - t0 < a.wait:
325                time.sleep(a.cadence); n += 1
326                tomas = capturar(qmp_sock, out, f"durante-{n}")
327                t = int(time.time() - t0)
328                medidas = {p: pintado(f) for p, f in tomas.items()}
329                px = max((v for v in medidas.values() if v is not None), default=None)
330                donde = next((p for p, v in medidas.items() if v and v > 100_000), None)
331                if primera is None and px and px > 100_000:
332                    primera = t
333                    print(f"   +{t}s  ██ PRIMERA PINTURA — {px} px de la página EN {donde}", flush=True)
334                    if a.until_paint:
335                        break
336                else:
337                    vivos = ser.cmd("for c in /proc/[0-9]*/comm; do cat $c 2>/dev/null; done | grep -c atuq")
338                    v = vivos.splitlines()[1].strip() if len(vivos.splitlines()) > 1 else "?"
339                    detalle = " ".join(f"{p}={medidas[p]}" for p in PANTALLAS)
340                    print(f"   +{t}s  px de la página: {detalle}   procesos atuq: {v}", flush=True)
341
342            capturar(qmp_sock, out, "despues")
343            print("== captura DESPUES", flush=True)
344
345            # EL NÚMERO. No «pinta / no pinta»: CUÁNTO TARDA. Medido el 2026-09-14 sobre esta misma
346            # imagen, la primera pintura cae entre +137 s y +204 s con el perfil por defecto y ~+134 s
347            # con uno nuevo en tmpfs — y con la máquina anfitriona cargada pasa de los +300 s. Por eso
348            # el presupuesto es HOLGADO y se dice el número siempre: un guardián que sólo contestara
349            # «no pintó» a los 5 min habría firmado el error del §6.10.ter.
350            if primera is None:
351                print(f"✗ el navegador NO pintó en {a.wait}s — mirá {out}/despues.png y el MOZ_LOG:")
352                print("  `mapped 1` + «marked as visible & has buffer» + WaylandBufferSHM ⇒ estaba pintando"
353                      " y la captura llegó antes; sin eso, es un fallo de verdad")
354                rc[0] = 1
355            else:
356                print(f"✓ primera pintura: +{primera}s   (presupuesto {a.budget}s)")
357                if primera > a.budget:
358                    print(f"✗ tardó {primera - a.budget}s MÁS que el presupuesto")
359                    rc[0] = 1
360
361            # El número se PUBLICA donde lo pueda leer el vigía de la imagen, que es estático y no
362            # arranca nada: sin esto el dato vive en el scrollback del que corrió la VM y se pierde,
363            # que es exactamente lo que pasó con la corrida a mano del §6.10.ter.
364            anotar_medicion(primera, a, donde if primera is not None else None)
365
366            # La evidencia que no se puede leer de una captura: qué hizo el widget de Wayland.
367            print("---- atuq.log (cola) ----")
368            print(ser.cmd("tail -25 /var/log/cosmic/atuq.log", 60))
369            print("---- MOZ_LOG: creación de la ventana ----")
370            print(ser.cmd("grep -a -m 40 -E 'nsWindow::Create|CreateNative|Map|configure|Show|frame callback|Buffer' "
371                          "/var/log/cosmic/moz.moz_log | head -40", 120))
372            print("---- MOZ_LOG: últimas líneas ----")
373            print(ser.cmd("tail -25 /var/log/cosmic/moz.moz_log", 60))
374            # El otro lado de la conversación. Gecko commitea a ciegas cuando nadie le devuelve
375            # frame callbacks (§6.10.nonies), y eso lo decide el COMPOSITOR: sin su log, «no pinta»
376            # sólo se puede mirar desde el cliente, que es la mitad que ya sabemos que miente.
377            if a.wayland_debug:
378                # Lo que INTERESA no es lo que pide el cliente sino lo que llega de vuelta: las
379                # líneas `[  ]` de entrada son eventos DEL COMPOSITOR. Sin `wl_callback.done` no
380                # hay frame callbacks, que es exactamente la hipótesis del §6.10.nonies.
381                # ⚠ EN `WAYLAND_DEBUG` LA FLECHA ES DEL CLIENTE. `-> obj.metodo()` es un PEDIDO que
382                # manda el navegador; los EVENTOS del compositor son las líneas SIN flecha. Filtrar
383                # por `->` es leer otra vez al cliente, que es justo la mitad que ya sabemos que
384                # miente. Y los nombres llevan `@id` en el medio, así que `wl_surface.commit` no
385                # engancha: hay que anclar en el método.
386                print("---- protocolo: EVENTOS del compositor (sin flecha) ----")
387                print(ser.cmd("grep -av ' -> ' /var/log/cosmic/atuq.log | "
388                              "grep -a -E 'xdg_surface|xdg_toplevel|wl_callback|wl_output|wl_surface' | "
389                              "tail -40", 180))
390                print("---- protocolo: cuentas (evento = sin flecha) ----")
391                print(ser.cmd("for k in xdg_toplevel# xdg_surface# wl_callback# wl_output#; do "
392                              "printf 'EVENTOS %s ' $k; grep -av ' -> ' /var/log/cosmic/atuq.log | "
393                              "grep -ac $k; done", 180))
394                print(ser.cmd("printf 'done() '; grep -av ' -> ' /var/log/cosmic/atuq.log | "
395                              "grep -ac 'done('; printf 'configure() '; grep -av ' -> ' "
396                              "/var/log/cosmic/atuq.log | grep -ac 'configure('", 180))
397            print("---- cosmic-comp: superficies, salidas y foco ----")
398            print(ser.cmd("grep -a -i -E 'output|workspace|focus|toplevel|surface|xdg|map' "
399                          "/var/log/cosmic/cosmic-session.log | tail -40", 120))
400            print("---- cosmic-comp: últimas líneas ----")
401            print(ser.cmd("tail -30 /var/log/cosmic/cosmic-session.log", 60))
402            print("---- tamaño de los logs ----")
403            print(ser.cmd("wc -l /var/log/cosmic/moz.moz_log /var/log/cosmic/atuq.log "
404                          "/var/log/cosmic/cosmic-session.log /var/log/cosmic/cosmic-start.log", 30))
405    finally:
406        try:
407            qmp(qmp_sock, [{"execute": "quit"}])
408        except Exception:
409            pass
410        time.sleep(2); vm.terminate()
411        try:
412            vm.wait(20)
413        except Exception:
414            vm.kill()
415
416    # Las capturas salen en PPM (lo único que sabe QMP); a PNG para poder mirarlas.
417    try:
418        from PIL import Image
419        for f in sorted(os.listdir(out)):
420            if f.endswith(".ppm"):
421                Image.open(os.path.join(out, f)).save(os.path.join(out, f[:-4] + ".png"))
422        print("== capturas convertidas a PNG en", out)
423    except Exception as e:
424        print("   ⚠ sin conversión a PNG:", e)
425    return rc[0]
426
427
428if __name__ == "__main__":
429    sys.exit(main())