sergio/takana
> Una distribución Linux construida con un laboratorio funcional y hermético en el > sótano, y una terminal mutable, clásica y anárquica en el piso de arriba — diseñada > desde el suelo para que una IA programadora entienda, modifique y co…
⎇ 2f90d8eb4015889eaac99453ceeecb106d576c70
scripts/cosmic/atuq-en-imagen.py
History
Who touched what
raw
arnés de la imagen: el contador de caídas viaja con la medición, y las envenenadas se apartan
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, re, 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 leer_contador_de_caidas(texto):
154 """Saca el valor de `toolkit.startup.recent_crashes` de un volcado de `prefs.js`.
155
156 Devuelve `None` si el pref NO ESTÁ, que no es lo mismo que un 0 puesto a mano: «no está» es el
157 estado de un perfil cuyo arranque terminó bien —y es también lo que deja Gecko DESPUÉS de
158 mostrar el diálogo de Modo de resolución de problemas, que es la razón por la que la corrida
159 siguiente «se arregla sola» y la anterior parece intermitente.
160
161 Filtra por `user_pref` a propósito: el serial hace eco de la propia orden `grep`, y esa línea
162 contiene el nombre del pref sin su valor.
163 """
164 for linea in texto.splitlines():
165 if "user_pref" in linea and "toolkit.startup.recent_crashes" in linea:
166 m = re.search(r"recent_crashes\"?\s*,\s*(-?\d+)", linea)
167 if m:
168 return int(m.group(1))
169 return None
170
171
172def anotar_medicion(segundos, a, pantalla=None, extra=None):
173 """Deja el tiempo de primera pintura en `docs/state/primera-pintura.json`.
174
175 Va al estado del repo y no a un log porque quien pregunta «¿esta imagen se puede usar?» es
176 `scripts/vigia-imagen.py`, que mira artefactos y no arranca ninguna VM: el número tiene que
177 llegarle por escrito o no le llega. Se guarda TODO lo que lo hace comparable —cómo se lanzó, con
178 qué vídeo, con cuánta RAM y cuántos cores— porque el tiempo depende de eso y de la carga de la
179 máquina anfitriona; un número sin sus condiciones invita a leerlo como si fuera del producto.
180 """
181 dato = {
182 "medido": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()),
183 "imagen": IMG,
184 "segundos_primera_pintura": segundos, # None = no pintó dentro de la ventana
185 "pantalla": pantalla, # EN CUÁL de las salidas apareció (medido 2026-09-14:
186 # con dos, la ventana cae en cualquiera de las dos)
187 "pantallas_fotografiadas": len(PANTALLAS), # con 1 y dos salidas, un ✗ NO es concluyente
188 "presupuesto_s": a.budget,
189 "ventana_s": a.wait,
190 "cadencia_s": a.cadence, # la RESOLUCIÓN del número: ±cadencia
191 "lanzamiento": "perfil del usuario" if a.as_user else "perfil nuevo en tmpfs",
192 "video": "vga+virtio-gpu (dos DRM)" if DOS_PANTALLAS else "virtio-gpu solo (-vga none)",
193 "mem_mb": int(MEM), "vcpus": int(SMP), "acel": "tcg",
194 "guion": "scripts/cosmic/atuq-en-imagen.py",
195 }
196 # ⚠ EL CONTADOR DE CAÍDAS DEL PERFIL VIAJA CON LA MEDICIÓN, y es lo que hace legible la serie:
197 # con `toolkit.startup.recent_crashes` por encima de 3 el sujeto de la corrida NO es el
198 # navegador sino el diálogo de Modo de resolución de problemas (§6.10.terdecies), así que un ✗
199 # de esas corridas no dice nada del producto. Sin este campo, una tasa cierta se lee como si
200 # fuera del navegador — que es exactamente lo que pasó con «3 de 13» y «2 de 10».
201 dato.update(extra or {})
202 # ⚠ SE ACUMULAN, NO SE PISAN. Medido el 2026-09-14: dos corridas IDÉNTICAS (mismo comando,
203 # misma imagen) dieron «+204 s» y «no pintó en 900 s». Un fichero de UNA medición convierte un
204 # fenómeno intermitente en el número que le tocó a la última corrida, que es la forma más cara
205 # de mentir con datos ciertos.
206 destino = os.path.join(RAIZ, "docs/state/primera-pintura.json")
207 try:
208 historia = {"corridas": []}
209 if os.path.exists(destino):
210 with open(destino) as f:
211 historia = json.load(f)
212 historia.setdefault("corridas", []).append(dato)
213 historia["corridas"] = historia["corridas"][-30:]
214 os.makedirs(os.path.dirname(destino), exist_ok=True)
215 with open(destino, "w") as f:
216 json.dump(historia, f, indent=2, ensure_ascii=False)
217 f.write("\n")
218 pintaron = [c for c in historia["corridas"] if c.get("segundos_primera_pintura") is not None]
219 print(" anotada en docs/state/primera-pintura.json — %d de %d corridas pintaron"
220 % (len(pintaron), len(historia["corridas"])))
221 except (OSError, ValueError) as e:
222 print(f" ⚠ no pude anotar la medición: {e}")
223
224
225def qmp(ruta, ordenes):
226 s = socket.socket(socket.AF_UNIX); s.settimeout(30); s.connect(ruta)
227 f = s.makefile("rwb", buffering=0)
228 f.readline() # greeting
229 f.write(b'{"execute":"qmp_capabilities"}\n'); f.readline()
230 salidas = []
231 for o in ordenes:
232 f.write(json.dumps(o).encode() + b"\n"); salidas.append(f.readline())
233 s.close()
234 return salidas
235
236
237def main():
238 ap = argparse.ArgumentParser()
239 ap.add_argument("--only-cosmic", action="store_true", help="control: no lanza el navegador")
240 ap.add_argument("--as-user", action="store_true",
241 help="lanza `atuq` a secas —perfil por defecto, sin MOZ_ENABLE_WAYLAND— como se hizo a mano en el §6.10.ter")
242 ap.add_argument("--wait", type=int, default=600, help="segundos de observación como máximo")
243 ap.add_argument("--cadence", type=int, default=30, help="segundos entre capturas (la resolución de la medida)")
244 ap.add_argument("--budget", type=int, default=420,
245 help="segundos que puede tardar la primera pintura antes de dar ✗")
246 ap.add_argument("--until-paint", action="store_true",
247 help="cortar la observación en cuanto la página aparezca (más barato para medir el tiempo)")
248 ap.add_argument("--wayland-debug", action="store_true",
249 help="lanza el navegador con WAYLAND_DEBUG=1: registra CADA mensaje del "
250 "protocolo en los dos sentidos. Es la única forma de ver qué MANDA el "
251 "compositor sin recompilarlo (sus macros de debug están compiladas fuera)")
252 ap.add_argument("--set-rust-log", metavar="VALOR",
253 help="escribe RUST_LOG en /etc/cosmic-mode de la IMAGEN y apaga; "
254 "cadena vacía = lo quita. El compositor lo lee en el arranque SIGUIENTE, "
255 "que es la única forma de subirle el nivel de log sin recompilar")
256 ap.add_argument("--crashes", type=int, metavar="N",
257 help="fija `toolkit.startup.recent_crashes` del perfil del usuario antes de "
258 "lanzar: 0 lo limpia, >3 reproduce el diálogo de Modo de resolución de "
259 "problemas. Sólo tiene efecto con --as-user")
260 ap.add_argument("--xulstore", metavar="ANCHOxALTO",
261 help="agrega una SEGUNDA fase en el mismo arranque con `xulstore.json` sembrado "
262 "(p. ej. 1152x720): la ventana arranca con un tamaño YA PERSISTIDO. Es el "
263 "control del 117x70 — si con semilla sale grande, lo que falla es que nadie "
264 "le da tamaño en el primer arranque")
265 ap.add_argument("--out", default=os.path.join(RAIZ, "work/atuq-imagen"))
266 a = ap.parse_args()
267
268 rc = [0] # lista para poder tocarlo desde dentro del try/finally
269 out = a.out; os.makedirs(out, exist_ok=True)
270 vars_fd = os.path.join(out, "OVMF_VARS.fd")
271 shutil.copy(OVMF_VARS, vars_fd)
272 ser_sock, qmp_sock = os.path.join(out, "serial.sock"), os.path.join(out, "qmp.sock")
273 for p in (ser_sock, qmp_sock):
274 if os.path.exists(p):
275 os.unlink(p)
276
277 qemu = [
278 "nice", "-n", "10", "qemu-system-x86_64",
279 "-machine", "q35", "-accel", "tcg", "-cpu", "max", "-m", MEM, "-smp", SMP,
280 *VGA_ARGS, "-device", "virtio-gpu-pci,id=gpu0", "-display", "none", "-nic", "none",
281 "-drive", f"if=pflash,format=raw,unit=0,file={OVMF_CODE},readonly=on",
282 "-drive", f"if=pflash,format=raw,unit=1,file={vars_fd}",
283 "-drive", f"file={IMG},format=raw,if=virtio",
284 "-serial", f"unix:{ser_sock},server,nowait",
285 "-qmp", f"unix:{qmp_sock},server,nowait",
286 "-no-reboot",
287 ]
288 print("== arrancando la imagen (TCG, sin KVM — paciencia)")
289
290 def primero_en_la_fila():
291 # El repo es COMPARTIDO y casi siempre hay una tanda de la granja compilando en esta misma
292 # máquina (4 cores, 7,6 G). Si la RAM se acaba, el que tiene que morir es ESTA VM y no el
293 # build de otro agente: `oom_score_adj` alto es la única forma de decirlo por adelantado.
294 with open("/proc/self/oom_score_adj", "w") as f:
295 f.write("900")
296
297 vm = subprocess.Popen(qemu, stdout=open(os.path.join(out, "qemu.log"), "wb"),
298 stderr=subprocess.STDOUT, preexec_fn=primero_en_la_fila)
299 # ⚠ QEMU TOMA UN LOCK DE ESCRITURA SOBRE LA IMAGEN, y sin esta comprobación el arnés espera
300 # 600 s una marca del serial que no va a llegar NUNCA: el socket queda creado, el `connect()`
301 # funciona y no falla nada — el error es UNA línea en `qemu.log` que nadie mira. Medido el
302 # 2026-09-15 al lanzar el control negativo con la corrida anterior todavía viva:
303 # Failed to get "write" lock. Is another process using the image [...]?
304 # Las corridas sobre la misma imagen van EN SERIE; esto lo dice en el primer segundo.
305 time.sleep(2)
306 if vm.poll() is not None:
307 raise SystemExit("✗ QEMU no arrancó:\n " +
308 open(os.path.join(out, "qemu.log")).read().strip())
309
310 try:
311 ser = Serial(ser_sock, os.path.join(out, "serial.log"))
312 print("== esperando a COSMIC…", flush=True)
313 ser.esperar("compositor OK", 600, nombre="(arranque de cosmic-comp)")
314 print(" compositor arriba; esperando el shell del serial (ventana de observación)", flush=True)
315 # 420 s alcanzaban con el anfitrión ocioso y NO con carga ~13: la VM llegaba a «+15s» y el
316 # arnés se rendía antes de que `cosmic-start` soltara el shell. El margen es de espera, no de
317 # medida: subirlo no cambia ningún número, sólo deja de tirar corridas por carga ajena.
318 ser.esperar("fin de la ventana de observación", 780, nombre="(fin de observación)")
319 time.sleep(3)
320 ser.s.sendall(b"\n")
321 print(ser.cmd("echo ENTORNO: WD=$WAYLAND_DISPLAY XDG=$XDG_RUNTIME_DIR DBUS=$DBUS_SESSION_BUS_ADDRESS").strip())
322 print(ser.cmd("ls -l $XDG_RUNTIME_DIR; ls /usr/lib/dri").strip())
323
324 if a.set_rust_log is not None:
325 # `cosmic-start` hace `. /etc/cosmic-mode` ANTES de `export RUST_LOG="${RUST_LOG:-info}"`,
326 # así que el fichero es la perilla. Se escribe y se apaga: quien la usa es el arranque
327 # siguiente — el compositor de ESTA sesión ya arrancó y no se lo puede reconfigurar.
328 ser.cmd("grep -v '^RUST_LOG=' /etc/cosmic-mode > /tmp/cm 2>/dev/null; true")
329 if a.set_rust_log:
330 ser.cmd("printf '%%s\\n' \"RUST_LOG=%s\" >> /tmp/cm" % a.set_rust_log)
331 ser.cmd("cp /tmp/cm /etc/cosmic-mode && sync")
332 print("== /etc/cosmic-mode ahora dice:")
333 print(ser.cmd("cat /etc/cosmic-mode").strip())
334 return
335
336 capturar(qmp_sock, out, "antes")
337 print("== captura ANTES (%s)" % ", ".join(PANTALLAS), flush=True)
338
339 if a.only_cosmic:
340 print("== CONTROL: no se lanza el navegador")
341 else:
342 # Una página de un color imposible de confundir con el escritorio.
343 ser.cmd("mkdir -p /var/log/cosmic")
344 # La página además DICE, por `dump()`, qué tamaño cree que tiene la ventana y qué
345 # pantalla ve el navegador. Con `screen=` y `outer=` en el log se sabe si el navegador
346 # ve la pantalla o no — y desde el §6.10.terdecies sabemos que SÍ la ve, así que lo que
347 # queda por contar es el otro lado: qué tamaño cree tener la VENTANA. Sin comillas
348 # simples: va dentro de un `printf '%s' '...'`.
349 ser.cmd("printf '%s' '<!doctype html><body style=\"margin:0;background:#ff00ff\">"
350 "<h1 style=\"font:40px monospace\">ATUQ PINTA</h1><script>"
351 "function diag(t){dump(\"ATUQ-DIAG \"+t+\" screen=\"+screen.width+\"x\"+screen.height"
352 "+\" avail=\"+screen.availWidth+\"x\"+screen.availHeight"
353 "+\" outer=\"+outerWidth+\"x\"+outerHeight"
354 "+\" inner=\"+innerWidth+\"x\"+innerHeight"
355 "+\" dpr=\"+devicePixelRatio+\"\\n\");}"
356 "addEventListener(\"load\",function(){diag(\"load\");"
357 "setTimeout(function(){diag(\"t10\");},10000);"
358 "setTimeout(function(){diag(\"t60\");},60000);});"
359 "</script>' > /tmp/pagina.html")
360
361 # ⚠ LO QUE DEJÓ LA CORRIDA ANTERIOR, ANTES DE PISARLO. El disco de esta VM es
362 # PERSISTENTE (`-drive` sin `snapshot=on`) ⇒ `/var/log/cosmic/` todavía tiene el
363 # arranque anterior, y el lanzamiento de esta corrida lo trunca. Ahí es donde salen los
364 # errores de JS del chrome, y NUNCA se habían mirado: se leía `tail -25`, que con
365 # `WAYLAND_DEBUG` son 25 líneas de protocolo y nada más. Copiarlo primero cuesta nada.
366 ser.cmd("rm -rf /var/log/cosmic-anterior; cp -a /var/log/cosmic /var/log/cosmic-anterior "
367 "2>/dev/null; true", 120)
368 print("---- corrida ANTERIOR: cómo terminó y qué se quejó ----")
369 print(ser.cmd("grep -a -h -E 'ATUQ-EXIT|JavaScript error|Uncaught|NS_ERROR|"
370 "###!!!|\\[Parent\\].*ERROR' /var/log/cosmic-anterior/atuq*.log "
371 "2>/dev/null | head -20", 120))
372 # DÓNDE VIVE EL PERFIL, SIN ADIVINARLO. El `find` anterior miraba sólo `/root` y esta
373 # imagen lo desmintió en silencio: dijo «no encontré el perfil» y la sonda salió muda.
374 # `$HOME` lo decide todo y el shell del serial lo hereda de `cosmic-start`, así que se
375 # IMPRIME; y el `find` va sobre la raíz entera con `-xdev` (que deja fuera /proc y /sys).
376 print("== HOME del shell de la sesión y perfiles que ya existen en el disco:")
377 print(ser.cmd("echo HOME=$HOME; find / -xdev -maxdepth 7 -name prefs.js 2>/dev/null | head -5", 180))
378
379 def perfil_de_la_fase(semilla):
380 """Deja el perfil listo para la fase y devuelve su directorio (o None).
381
382 Las dos formas de lanzar NO son el mismo experimento y por eso conviven: el modo por
383 defecto usa un perfil NUEVO en tmpfs —primer arranque de verdad, que es el caso que
384 sale 117×70— y `--as-user` reproduce lo que se tecleó a mano en el §6.10.ter, con el
385 perfil del usuario y sin variables de entorno.
386 """
387 if a.as_user:
388 hallado = ser.cmd("find / -xdev -maxdepth 7 -name prefs.js 2>/dev/null | head -3", 180)
389 perfil = next((l.strip() for l in hallado.splitlines()
390 if l.strip().endswith("prefs.js") and l.strip().startswith("/")), None)
391 if not perfil:
392 print(" ⚠ no encontré el perfil del usuario: la sonda ATUQ-DIAG va a salir muda")
393 return None
394 d = os.path.dirname(perfil)
395 print("== perfil del usuario:", d)
396 # ⚠⚠ EL CONTADOR DE CAÍDAS DEL PERFIL, SIEMPRE A LA VISTA. Con
397 # `toolkit.startup.recent_crashes` por encima de `max_resumed_crashes` (3 por
398 # defecto) el navegador NO abre el navegador: abre el diálogo de Modo de
399 # resolución de problemas. Y este arnés mata la VM con el navegador vivo, así
400 # que CADA corrida fallida puede sumar uno: el instrumento degrada el sujeto y
401 # la tasa medida deja de ser del producto. Sin este número impreso, una corrida
402 # no se puede interpretar.
403 volcado = ser.cmd("grep -E 'toolkit.startup.(recent_crashes|max_resumed)|"
404 "browser.sessionstore.max_resumed' %s/prefs.js" % d, 60)
405 print(volcado.strip())
406 estado["recent_crashes_antes"] = leer_contador_de_caidas(volcado)
407 else:
408 d = "/tmp/perfil"
409 ser.cmd("rm -rf /tmp/perfil && mkdir -p /tmp/perfil")
410 ujs = ['user_pref("browser.dom.window.dump.enabled", true);',
411 'user_pref("browser.shell.checkDefaultBrowser", false);']
412 if a.crashes is not None:
413 # El mismo mando en los DOS sentidos: 0 limpia el contador (¿pinta?) y un
414 # número alto lo reproduce a propósito (¿se rompe?). `user.js` gana sobre
415 # `prefs.js` en cada arranque, así que fija el valor de la corrida.
416 ujs.append('user_pref("toolkit.startup.recent_crashes", %d);' % a.crashes)
417 print("== recent_crashes FIJADO a %d para esta corrida" % a.crashes)
418 ser.cmd("rm -f %s/user.js" % d)
419 for linea in ujs:
420 ser.cmd("printf '%%s\\n' '%s' >> %s/user.js" % (linea, d))
421 if semilla:
422 # EL CONTROL. `browser-init.js` —el que trae el propio artefacto, leído del
423 # `omni.ja` sellado— fija el tamaño de arranque UNA sola vez:
424 #
425 # } else if (!document.documentElement.hasAttribute("width")) {
426 # let width = Math.min(screen.availWidth * 0.9, 1280);
427 # let height = Math.min(screen.availHeight * 0.9, 1040);
428 #
429 # y ese atributo, en un perfil ya usado, lo rellena el `xulstore.json`. Sembrarlo
430 # a mano separa las dos explicaciones posibles del 117×70 en UNA corrida: si con
431 # semilla la ventana sale grande, el fallo es «nadie le dio tamaño» (ese `if` no
432 # corrió); si sale igual de chica, el tamaño no es lo que falla.
433 w, h = semilla.lower().split("x")
434 doc = {"chrome://browser/content/browser.xhtml":
435 {"main-window": {"screenX": "0", "screenY": "0",
436 "width": w, "height": h, "sizemode": "normal"}}}
437 ser.cmd("printf '%%s' '%s' > %s/xulstore.json" % (json.dumps(doc), d))
438 elif not a.as_user:
439 # Sólo en el perfil DESECHABLE de tmpfs. ⚠ En `--as-user` el `xulstore.json` es
440 # el estado del usuario —el tamaño que la ventana RECUERDA— y borrarlo cambiaría
441 # el experimento sin decirlo: la corrida siguiente ya no sería «como lo abre el
442 # usuario» sino un primer arranque disfrazado.
443 ser.cmd("rm -f %s/xulstore.json" % d)
444 ser.cmd("sync")
445 print("== el perfil, ANTES de lanzar (user.js y el tamaño que RECUERDA):")
446 print(ser.cmd("cat %s/user.js; echo ---; cat %s/xulstore.json 2>/dev/null || "
447 "echo '(sin xulstore.json: la ventana no recuerda ningún tamaño)'"
448 % (d, d), 60).strip())
449 return d
450
451 def matar_al_navegador():
452 """Deja la sesión sin ningún `atuq` vivo antes de la fase siguiente.
453
454 Por PID leído de `/proc/*/comm`, no por `pkill -f atuq`: el patrón engancha la propia
455 línea de orden del shell del serial y ahí se mata la sesión entera (medido en el hub,
456 sale 144 y lo que sigue no corre).
457 """
458 ser.cmd("for p in /proc/[0-9]*; do grep -q atuq $p/comm 2>/dev/null && "
459 "kill ${p#/proc/}; done; true", 60)
460 time.sleep(8)
461 salida = ser.cmd("for c in /proc/[0-9]*/comm; do cat $c 2>/dev/null; done | grep -c atuq")
462 # El serial hace ECO de la orden, así que la respuesta es la ÚLTIMA línea que sea un
463 # número y no la primera que aparezca: leer la primera devuelve un trozo del eco.
464 cuenta = next((l.strip() for l in reversed(salida.splitlines()) if l.strip().isdigit()), "?")
465 print(" navegadores vivos tras el kill: " + cuenta)
466
467 # LAS FASES. Una sola es la medición de siempre; con `--xulstore` se agrega una SEGUNDA
468 # en el MISMO arranque, que es un A/B de verdad: mismo compositor, misma sesión, misma
469 # carga del anfitrión. Dos arranques distintos no lo serían — y cada arranque cuesta
470 # cinco minutos de TCG.
471 # El estado del perfil que hay que ADJUNTAR a la medición: el contador de caídas antes
472 # y después. Vive acá afuera porque lo escribe la preparación de la fase y lo lee la
473 # anotación, y porque con `--crashes` fijado hay que poder distinguir el valor que
474 # PUSIMOS del que el perfil traía.
475 estado = {"recent_crashes_fijado": a.crashes}
476
477 fases = [("base", None)]
478 if a.xulstore:
479 fases.append(("semilla-%s" % a.xulstore, a.xulstore))
480
481 for fase, semilla in fases:
482 print("\n===== FASE «%s» =====" % fase, flush=True)
483 if semilla:
484 matar_al_navegador()
485 perfil_d = perfil_de_la_fase(semilla)
486 log_atuq = "/var/log/cosmic/atuq-%s.log" % fase
487 log_moz = "/var/log/cosmic/moz-%s" % fase
488 capturar(qmp_sock, out, "%s-antes" % fase)
489 print("== captura ANTES de la fase (%s)" % ", ".join(PANTALLAS), flush=True)
490
491 wd = "WAYLAND_DEBUG=1 " if a.wayland_debug else ""
492 moz = ("MOZ_LOG='Widget:5,WidgetWayland:5,WaylandBackend:5,WidgetScreen:5,timestamp' "
493 "MOZ_LOG_FILE=%s " % log_moz)
494 if a.as_user:
495 orden = wd + moz + "/usr/bin/atuq file:///tmp/pagina.html"
496 else:
497 orden = (wd + "MOZ_ENABLE_WAYLAND=1 GDK_BACKEND=wayland " + moz +
498 "/usr/bin/atuq --no-remote --profile /tmp/perfil file:///tmp/pagina.html")
499 # ⚠ EL NAVEGADOR SE MURIÓ Y NADIE LO SUPO (medido 2026-09-15, 17:12): el shell
500 # imprimió «[1]+ Done» a los ~25 s y la corrida siguió 420 s fotografiando un
501 # escritorio sin navegador, para terminar diciendo «no pintó». Un proceso que sale
502 # deja un CÓDIGO, y ese código es la diferencia entre «se cayó» y «se fue solo»; va
503 # al log, en el subshell, para que quede escrito aunque el arnés muera después.
504 print(ser.cmd("( %s; echo ATUQ-EXIT=$? ) > %s 2>&1 &" % (orden, log_atuq), fondo=True).strip())
505 print(f"== navegador lanzado; observando {a.wait}s", flush=True)
506 t0 = time.time(); n = 0
507 primera = None # segundos hasta la PRIMERA captura con la página en pantalla
508 donde = None
509 while time.time() - t0 < a.wait:
510 time.sleep(a.cadence); n += 1
511 tomas = capturar(qmp_sock, out, f"{fase}-durante-{n}")
512 t = int(time.time() - t0)
513 medidas = {p: pintado(f) for p, f in tomas.items()}
514 px = max((v for v in medidas.values() if v is not None), default=None)
515 donde = next((p for p, v in medidas.items() if v and v > 100_000), None)
516 if primera is None and px and px > 100_000:
517 primera = t
518 print(f" +{t}s ██ PRIMERA PINTURA — {px} px de la página EN {donde}", flush=True)
519 if a.until_paint:
520 break
521 else:
522 vivos = ser.cmd("for c in /proc/[0-9]*/comm; do cat $c 2>/dev/null; done | grep -c atuq")
523 v = vivos.splitlines()[1].strip() if len(vivos.splitlines()) > 1 else "?"
524 detalle = " ".join(f"{p}={medidas[p]}" for p in PANTALLAS)
525 print(f" +{t}s px de la página: {detalle} procesos atuq: {v}", flush=True)
526
527 capturar(qmp_sock, out, "%s-despues" % fase)
528 print("== captura DESPUES de la fase", flush=True)
529
530 # EL NÚMERO. No «pinta / no pinta»: CUÁNTO TARDA. Medido el 2026-09-14 sobre esta
531 # misma imagen, la primera pintura cae entre +137 s y +204 s con el perfil por
532 # defecto y ~+134 s con uno nuevo en tmpfs — y con la máquina anfitriona cargada pasa
533 # de los +300 s. Por eso el presupuesto es HOLGADO y se dice el número siempre: un
534 # guardián que sólo contestara «no pintó» a los 5 min habría firmado el error del
535 # §6.10.ter.
536 if primera is None:
537 print(f"✗ el navegador NO pintó en {a.wait}s — mirá {out}/{fase}-despues.png y el MOZ_LOG:")
538 print(" `mapped 1` + «marked as visible & has buffer» + WaylandBufferSHM ⇒ estaba pintando"
539 " y la captura llegó antes; sin eso, es un fallo de verdad")
540 rc[0] = 1
541 else:
542 print(f"✓ primera pintura: +{primera}s (presupuesto {a.budget}s)")
543 if primera > a.budget:
544 print(f"✗ tardó {primera - a.budget}s MÁS que el presupuesto")
545 rc[0] = 1
546
547 if perfil_d and a.as_user:
548 # ⚠ EL ESTADO FINAL ES PARTE DE LA PRUEBA. Gecko BORRA el contador después de
549 # mostrar el diálogo, así que un perfil envenenado se ve limpio en cuanto se
550 # lo mira DESPUÉS: sin este segundo volcado, la corrida siguiente parece
551 # «arreglada sola» y la anterior parece intermitente. Se lee con el navegador
552 # todavía vivo, o sea que refleja el último volcado de prefs de Gecko.
553 volcado = ser.cmd("grep -E 'toolkit.startup.recent_crashes' %s/prefs.js || "
554 "echo '(el pref no está: arranque sin caídas pendientes)'"
555 % perfil_d, 60)
556 estado["recent_crashes_despues"] = leer_contador_de_caidas(volcado)
557 print("---- el contador de caídas, DESPUÉS ----")
558 print(volcado.strip())
559 # ⚠ SÓLO LA FASE BASE SE ANOTA. La serie de `primera-pintura.json` es una TASA del
560 # producto tal como se entrega; una fase con el tamaño de ventana sembrado a mano es
561 # otro experimento, y mezclarlos haría que el denominador dejara de significar nada.
562 if semilla is None:
563 anotar_medicion(primera, a, donde if primera is not None else None, estado)
564 else:
565 print(" (fase con semilla: NO se anota en la serie de la tasa)")
566
567 # La evidencia que no se puede leer de una captura: cómo terminó el proceso, qué se
568 # quejó el chrome, y qué hizo el widget de Wayland.
569 # QUÉ QUEDÓ PERSISTIDO. `browser.xhtml` lleva `persist="… width height sizemode"`,
570 # así que el tamaño con el que terminó la ventana se ESCRIBE en el perfil y lo hereda
571 # la corrida siguiente: si una corrida sale de 117×70 y lo guarda, el fallo se
572 # aprende. Sin este volcado, «intermitente» y «contagiado» se ven igual.
573 if perfil_d:
574 print("---- el perfil, DESPUÉS: qué tamaño quedó recordado ----")
575 print(ser.cmd("cat %s/xulstore.json 2>/dev/null || echo '(no escribió xulstore.json)'"
576 % perfil_d, 60))
577 print("---- cómo terminó, y de qué se quejó el chrome ----")
578 print(ser.cmd("grep -a -E 'ATUQ-EXIT|JavaScript error|Uncaught|NS_ERROR|###!!!' "
579 "%s | head -25" % log_atuq, 120))
580 print("---- atuq.log (cabeza) ----")
581 print(ser.cmd("head -20 %s" % log_atuq, 60))
582 print("---- atuq.log (cola) ----")
583 print(ser.cmd("tail -20 %s" % log_atuq, 60))
584 print("---- MOZ_LOG: creación de la ventana ----")
585 print(ser.cmd("grep -a -m 40 -E 'nsWindow::Create|CreateNative|Map|configure|Show|frame callback|Buffer' "
586 "%s.moz_log | head -40" % log_moz, 120))
587 # QUÉ PANTALLA VE GECKO — contestado el 2026-09-15 y por eso se queda: la sonda que
588 # ya contestó es la que avisa cuando la respuesta cambia. `New monitor 0 size
589 # [0,0 -> 1280 x 800]` ANTES de `Initial resize to 1 x 1` ⇒ la geometría de la salida
590 # NO es lo que falta.
591 print("---- MOZ_LOG: pantallas que ve Gecko y tamaños del nsWindow ----")
592 print(ser.cmd("grep -a -E 'WidgetScreen|Screen\\[|AddScreen|nsWindow::Resize|Initial resize|"
593 "SetSizeMode|OnConfigure|SizeAllocate|LockAspect' "
594 "%s.moz_log | head -50" % log_moz, 180))
595 # Y lo que dice el propio navegador, desde la página, por `dump()`: `screen=` es lo
596 # que el contenido ve de la pantalla y `outer=` el tamaño de la ventana. Dos fuentes
597 # independientes para el mismo número; si se contradicen, eso también es un dato.
598 print("---- la página: ATUQ-DIAG ----")
599 print(ser.cmd("grep -a ATUQ-DIAG %s | head -10" % log_atuq, 120))
600 print("---- MOZ_LOG: últimas líneas ----")
601 print(ser.cmd("tail -25 %s.moz_log" % log_moz, 60))
602 # El otro lado de la conversación. Gecko commitea a ciegas cuando nadie le devuelve
603 # frame callbacks (§6.10.nonies), y eso lo decide el COMPOSITOR: sin su log, «no
604 # pinta» sólo se puede mirar desde el cliente, que es la mitad que ya sabemos miente.
605 if a.wayland_debug:
606 # ⚠ EN `WAYLAND_DEBUG` LA FLECHA ES DEL CLIENTE. `-> obj.metodo()` es un PEDIDO
607 # que manda el navegador; los EVENTOS del compositor son las líneas SIN flecha.
608 # Filtrar por `->` es leer otra vez al cliente. Y los nombres llevan `@id` en el
609 # medio, así que `wl_surface.commit` no engancha: hay que anclar en el método.
610 # QUIÉN ELIGE EL TAMAÑO: `attach` no lo dice —el tamaño del buffer está en
611 # `create_buffer(…, W, H, stride, fmt)`— y lo que el cliente DECLARA querer está
612 # en `set_window_geometry`. Puestos en orden y en los DOS sentidos se ve quién
613 # propone (contestado en el §6.10.duodecies: lo propone el cliente).
614 print("---- protocolo: el tamaño, en orden (→ = pedido del cliente) ----")
615 # ⚠ El filtro EXCLUYE `mode(0,`: QEMU anuncia ~60 modos no-actuales y con ellos
616 # dentro el `head` cortaba ANTES del `set_window_geometry` — la lista que existe
617 # para ordenar dos cosas se quedaba sin una de las dos.
618 print(ser.cmd("grep -a -n -E 'create_buffer|set_window_geometry|configure|ack_configure|"
619 "get_toplevel|set_min_size|set_max_size|set_title|set_app_id|\\.attach|"
620 "wl_output|\\.mode\\(|\\.geometry\\(|\\.done\\(\\)' "
621 "%s | grep -av 'mode(0,' | head -80" % log_atuq, 240))
622 print("---- protocolo: EVENTOS del compositor (sin flecha) ----")
623 print(ser.cmd("grep -av ' -> ' %s | "
624 "grep -a -E 'xdg_surface|xdg_toplevel|wl_callback|wl_output|wl_surface' | "
625 "tail -40" % log_atuq, 180))
626 print("---- cosmic-comp: superficies, salidas y foco ----")
627 print(ser.cmd("grep -a -i -E 'output|workspace|focus|toplevel|surface|xdg|map' "
628 "/var/log/cosmic/cosmic-session.log | tail -40", 120))
629 print("---- tamaño de los logs ----")
630 print(ser.cmd("wc -l /var/log/cosmic/atuq-*.log /var/log/cosmic/moz-*.moz_log "
631 "/var/log/cosmic/cosmic-session.log /var/log/cosmic/cosmic-start.log", 30))
632 finally:
633 try:
634 qmp(qmp_sock, [{"execute": "quit"}])
635 except Exception:
636 pass
637 time.sleep(2); vm.terminate()
638 try:
639 vm.wait(20)
640 except Exception:
641 vm.kill()
642
643 # Las capturas salen en PPM (lo único que sabe QMP); a PNG para poder mirarlas.
644 try:
645 from PIL import Image
646 for f in sorted(os.listdir(out)):
647 if f.endswith(".ppm"):
648 Image.open(os.path.join(out, f)).save(os.path.join(out, f[:-4] + ".png"))
649 print("== capturas convertidas a PNG en", out)
650 except Exception as e:
651 print(" ⚠ sin conversión a PNG:", e)
652 return rc[0]
653
654
655if __name__ == "__main__":
656 sys.exit(main())