#!/usr/bin/env python3
"""atuq-en-imagen.py — arranca la IMAGEN DE DISCO con COSMIC y le pide al navegador que pinte.
scripts/cosmic/atuq-en-imagen.py # lanza atuq y fotografía la pantalla
scripts/cosmic/atuq-en-imagen.py --only-cosmic # control: NO lanza atuq (línea de base)
── POR QUÉ ────────────────────────────────────────────────────────────────────────────────────
El §6.10.ter del SDD 26 dejó esto medido y sin explicar: en la imagen arrancada `atuq` corre —sus
extensiones sondean, WebRender inicializa— y la ventana NO APARECE, mientras que bajo `sway` headless
el mismo artefacto pinta. `scripts/cosmic/atuq-en-cosmic.sh` ya sacó una variable de encima:
**con cosmic-comp NESTEADO (backend winit, GL por software) el navegador pinta**, o sea que no es el
compositor por sí mismo. Lo que queda es el arranque de verdad: kms/DRM sobre virtio-gpu, el PID1 de
arje, el seat. Eso sólo se mide acá adentro.
La corrida anterior fue A MANO por el serial y no dejó ni un log que se pueda releer. Este guion
hace lo mismo pero REPETIBLE y con la evidencia guardada: maneja el serial, lanza el navegador con
`MOZ_LOG` del widget de Wayland, pide capturas por QMP y saca los logs por el serial.
── CÓMO HABLA CON LA VM ───────────────────────────────────────────────────────────────────────
`console-getty` corre `cosmic-start`, que tras su ventana de observación (3 min) hace `exec /bin/sh`
CON EL ENTORNO DE LA SESIÓN puesto (WAYLAND_DISPLAY, DBUS_SESSION_BUS_ADDRESS). O sea que el shell
del serial es exactamente desde donde un usuario lanzaría una app — y por eso no hace falta
reconstruir el entorno a mano, que es como se inventan diferencias que después se confunden con la
causa.
"""
import argparse, json, os, re, shutil, socket, subprocess, sys, time
# Sin esto la salida sale por tandas cuando se redirige a un fichero, y una corrida de 20 minutos se
# lee como si estuviera colgada.
sys.stdout.reconfigure(line_buffering=True)
RAIZ = os.path.dirname(os.path.dirname(os.path.dirname(os.path.abspath(__file__))))
IMG = os.environ.get("IMG", "/mnt/cosecha/takana-cosmic-qemu.img")
OVMF_CODE = os.environ.get("OVMF_CODE", "/usr/share/edk2/x64/OVMF_CODE.4m.fd")
OVMF_VARS = os.environ.get("OVMF_VARS", "/usr/share/edk2/x64/OVMF_VARS.4m.fd")
MEM = os.environ.get("MEM", "2560")
SMP = os.environ.get("SMP", "2")
# ⚠ `VGA=1` reproduce el arranque del §6.10.ter, y la diferencia NO es cosmética: sin `-vga none`,
# QEMU agrega una VGA estándar ADEMÁS del virtio-gpu, OVMF pinta su GOP ahí y el kernel levanta
# `simpledrm` encima ⇒ el guest ve DOS dispositivos DRM. En el serial se lee tal cual:
#
# == cosmic :: kernel 6.16.12 · drm: card0 card1 renderD128 (corrida del §6.10.ter)
# == cosmic :: kernel 6.16.12 · drm: card0 renderD128 (con -vga none)
#
# Un compositor con dos tarjetas puede componer en la que el `screendump` NO muestra. Por eso el
# default acá es UNA sola (-vga none) y la reproducción del caso original es una opción explícita:
# son dos mediciones distintas y hay que poder pedir cada una por su nombre.
# Las dos pantallas van con ID EXPLÍCITO (`vga0`, `gpu0`) y no por el `-vga std` implícito, porque
# `screendump` de QMP fotografía UN dispositivo y hay que poder pedir cada uno por su nombre: con dos
# salidas, el compositor puede poner la ventana en la que la captura por defecto NO muestra, y eso se
# ve exactamente igual que «la ventana no aparece».
# Segundos desde el lanzamiento del navegador antes de los cuales NO se puede matar la VM sin
# envenenar el perfil: el sello del arranque (`last_success` + borrado de `recent_crashes`) aparece
# en disco entre +100 s y +137 s (medido 2026-09-15, `work/cuanto-1.txt`). 180 deja margen sobre la
# cota alta; es un piso del INSTRUMENTO y no una medida del producto.
# ⚠ EL PISO DEL SELLO, Y EL NÚMERO QUE LO JUSTIFICA — si esto se lee como elegido, el próximo que
# lo vea lo baja. Gecko da por bueno un arranque un rato DESPUÉS DEL LANZAMIENTO (no de la primera
# pintura) y ahí escribe `toolkit.startup.last_success` y limpia `recent_crashes`. Medido el
# 2026-09-15, leyendo el perfil en cada captura, y acotado por dos corridas independientes:
#
# el sello NO estaba a los +100 s (la corrida S1 vivió 100 s desde el lanzamiento y no selló)
# el sello YA estaba a los +137 s (la corrida `cuanto-1`: last_success pasó a su propia hora)
#
# ⇒ el hito cae entre +100 y +137 s, y el 180 es margen sobre la cota alta. Y la consecuencia es
# contraintuitiva: **cuanto más rápido pinta, MÁS fácil es envenenar el perfil**, porque
# `--until-paint` corta antes. Una serie sin este piso se rompe sola a la cuarta corrida.
PISO_SELLO = int(os.environ.get("PISO_SELLO", "180"))
DOS_PANTALLAS = os.environ.get("VGA") == "1"
VGA_ARGS = (["-vga", "none", "-device", "VGA,id=vga0"] if DOS_PANTALLAS else ["-vga", "none"])
PANTALLAS = ["gpu0", "vga0"] if DOS_PANTALLAS else ["gpu0"]
class Serial:
"""El serial de la VM. Todo lo que entra queda en el .log crudo, pase lo que pase."""
def __init__(self, ruta, log):
self.log = open(log, "ab", buffering=0)
for _ in range(120):
try:
self.s = socket.socket(socket.AF_UNIX); self.s.connect(ruta); break
except OSError:
time.sleep(0.5)
else:
raise SystemExit(f"no pude conectarme al serial {ruta}")
self.s.settimeout(1.0)
self.buf = b""
def leer(self, segundos):
fin = time.time() + segundos
while time.time() < fin:
try:
d = self.s.recv(65536)
except socket.timeout:
continue
if not d:
break
self.buf += d; self.log.write(d)
return self.buf
def esperar(self, marca, segundos, nombre=""):
"""Lee hasta ver `marca`. Devuelve lo leído desde la llamada anterior."""
vistos = len(self.buf)
fin = time.time() + segundos
while time.time() < fin:
try:
d = self.s.recv(65536)
except socket.timeout:
continue
if d:
self.buf += d; self.log.write(d)
if marca.encode() in self.buf[vistos:]:
return self.buf[vistos:].decode("utf-8", "replace")
print(f" ⚠ nunca llegó «{marca}» {nombre} en {segundos}s", flush=True)
return self.buf[vistos:].decode("utf-8", "replace")
def cmd(self, orden, segundos=30, fondo=False):
"""Manda una orden y devuelve su salida (delimitada por una marca propia).
⚠ DOS TRAMPAS MEDIDAS, las dos hacen que la orden NO CORRA y el guion siga como si nada:
· **el terminal hace ECO de lo que se le escribe**, así que una marca escrita literal en la
línea aparece en el serial ANTES de que el shell ejecute nada: el `esperar` la ve en el eco
y vuelve al instante, y las órdenes se pisan unas a otras. Por eso la marca se ARMA EN EL
GUEST partida en dos (`'FIN''-123'`): el eco muestra las comillas y sólo la salida trae la
marca entera.
· **`cmd & ; echo …` es un error de sintaxis** en ash: pegarle un `;` a un `&` no lanza nada
y el shell contesta «syntax error». Lo de fondo va en su propia línea (`fondo=True`).
"""
n = int(time.time() * 1000) % 100000
marca = f"FIN-{n}"
if fondo:
self.s.sendall(f"{orden}\n".encode()); time.sleep(0.5)
self.s.sendall(f"echo 'FIN''-{n}'\n".encode())
else:
self.s.sendall(f"{orden}; echo 'FIN''-{n}'\n".encode())
return self.esperar(marca, segundos, nombre=f"de «{orden[:40]}»")
def capturar(ruta_qmp, out, nombre):
"""Fotografía CADA pantalla del guest y devuelve {pantalla: fichero}.
Con dos salidas hay que mirar las dos: la ventana puede estar viva y dibujando en la que no se
fotografía, y eso es indistinguible de «no pinta» si sólo se mira una.
"""
ficheros = {p: os.path.join(out, f"{nombre}-{p}.ppm") for p in PANTALLAS}
qmp(ruta_qmp, [{"execute": "screendump", "arguments": {"filename": f, "device": p}}
for p, f in ficheros.items()])
return ficheros
def pintado(ppm):
"""¿Cuántos píxeles de la pantalla son la página de prueba?
Se cuenta el magenta con TOLERANCIA, no por color exacto, y la razón está medida: a los ~+590 s
sin una sola entrada `cosmic-idle` ATENÚA la pantalla y los 703 766 px de `(255,0,255)` pasan a
703 779 px de `(117,0,117)` —la misma ventana al 46 % de brillo—. Un contador por color exacto
lee eso como «desapareció la ventana», que es justo el error que este guion existe para no
cometer.
"""
try:
from PIL import Image
except Exception:
return None
im = Image.open(ppm).convert("RGB")
return sum(n for n, (r, g, b) in im.getcolors(1 << 24) if r > 90 and b > 90 and g < 40)
def leer_contador_de_caidas(texto):
"""Saca el valor de `toolkit.startup.recent_crashes` de un volcado de `prefs.js`.
Devuelve `None` si el pref NO ESTÁ, que no es lo mismo que un 0 puesto a mano: «no está» es el
estado de un perfil cuyo arranque terminó bien —y es también lo que deja Gecko DESPUÉS de
mostrar el diálogo de Modo de resolución de problemas, que es la razón por la que la corrida
siguiente «se arregla sola» y la anterior parece intermitente.
Filtra por `user_pref` a propósito: el serial hace eco de la propia orden `grep`, y esa línea
contiene el nombre del pref sin su valor.
"""
for linea in texto.splitlines():
if "user_pref" in linea and "toolkit.startup.recent_crashes" in linea:
m = re.search(r"recent_crashes\"?\s*,\s*(-?\d+)", linea)
if m:
return int(m.group(1))
return None
def leer_sello_de_exito(texto):
"""Saca `toolkit.startup.last_success` de un volcado de `prefs.js`.
Es la OTRA MITAD del cálculo del contador de caídas: el contador sube mientras este sello no se
mueve, así que un contador que no cambió sólo deja de ser ambiguo —«no subió» contra «subió y se
limpió»— si se lee junto con el sello. Medido el 2026-09-15: pasó un día entero sin moverse.
"""
for linea in texto.splitlines():
if "user_pref" in linea and "toolkit.startup.last_success" in linea:
m = re.search(r"last_success\"?\s*,\s*(\d+)", linea)
if m:
return int(m.group(1))
return None
def anotar_medicion(segundos, a, pantalla=None, extra=None):
"""Deja el tiempo de primera pintura en `docs/state/primera-pintura.json`.
Va al estado del repo y no a un log porque quien pregunta «¿esta imagen se puede usar?» es
`scripts/vigia-imagen.py`, que mira artefactos y no arranca ninguna VM: el número tiene que
llegarle por escrito o no le llega. Se guarda TODO lo que lo hace comparable —cómo se lanzó, con
qué vídeo, con cuánta RAM y cuántos cores— porque el tiempo depende de eso y de la carga de la
máquina anfitriona; un número sin sus condiciones invita a leerlo como si fuera del producto.
"""
dato = {
"medido": time.strftime("%Y-%m-%dT%H:%M:%SZ", time.gmtime()),
"imagen": IMG,
"segundos_primera_pintura": segundos, # None = no pintó dentro de la ventana
"pantalla": pantalla, # EN CUÁL de las salidas apareció (medido 2026-09-14:
# con dos, la ventana cae en cualquiera de las dos)
"pantallas_fotografiadas": len(PANTALLAS), # con 1 y dos salidas, un ✗ NO es concluyente
"presupuesto_s": a.budget,
"ventana_s": a.wait,
"cadencia_s": a.cadence, # la RESOLUCIÓN del número: ±cadencia
"lanzamiento": "perfil del usuario" if a.as_user else "perfil nuevo en tmpfs",
"video": "vga+virtio-gpu (dos DRM)" if DOS_PANTALLAS else "virtio-gpu solo (-vga none)",
"mem_mb": int(MEM), "vcpus": int(SMP), "acel": "tcg",
"guion": "scripts/cosmic/atuq-en-imagen.py",
}
# ⚠ EL CONTADOR DE CAÍDAS DEL PERFIL VIAJA CON LA MEDICIÓN, y es lo que hace legible la serie:
# con `toolkit.startup.recent_crashes` por encima de 3 el sujeto de la corrida NO es el
# navegador sino el diálogo de Modo de resolución de problemas (§6.10.terdecies), así que un ✗
# de esas corridas no dice nada del producto. Sin este campo, una tasa cierta se lee como si
# fuera del navegador — que es exactamente lo que pasó con «3 de 13» y «2 de 10».
dato.update(extra or {})
# ⚠ SE ACUMULAN, NO SE PISAN. Medido el 2026-09-14: dos corridas IDÉNTICAS (mismo comando,
# misma imagen) dieron «+204 s» y «no pintó en 900 s». Un fichero de UNA medición convierte un
# fenómeno intermitente en el número que le tocó a la última corrida, que es la forma más cara
# de mentir con datos ciertos.
destino = os.path.join(RAIZ, "docs/state/primera-pintura.json")
try:
historia = {"corridas": []}
if os.path.exists(destino):
with open(destino) as f:
historia = json.load(f)
historia.setdefault("corridas", []).append(dato)
historia["corridas"] = historia["corridas"][-30:]
os.makedirs(os.path.dirname(destino), exist_ok=True)
with open(destino, "w") as f:
json.dump(historia, f, indent=2, ensure_ascii=False)
f.write("\n")
pintaron = [c for c in historia["corridas"] if c.get("segundos_primera_pintura") is not None]
print(" anotada en docs/state/primera-pintura.json — %d de %d corridas pintaron"
% (len(pintaron), len(historia["corridas"])))
except (OSError, ValueError) as e:
print(f" ⚠ no pude anotar la medición: {e}")
def qmp(ruta, ordenes):
s = socket.socket(socket.AF_UNIX); s.settimeout(30); s.connect(ruta)
f = s.makefile("rwb", buffering=0)
f.readline() # greeting
f.write(b'{"execute":"qmp_capabilities"}\n'); f.readline()
salidas = []
for o in ordenes:
f.write(json.dumps(o).encode() + b"\n"); salidas.append(f.readline())
s.close()
return salidas
def main():
ap = argparse.ArgumentParser()
ap.add_argument("--only-cosmic", action="store_true", help="control: no lanza el navegador")
ap.add_argument("--as-user", action="store_true",
help="lanza `atuq` a secas —perfil por defecto, sin MOZ_ENABLE_WAYLAND— como se hizo a mano en el §6.10.ter")
ap.add_argument("--wait", type=int, default=600, help="segundos de observación como máximo")
ap.add_argument("--cadence", type=int, default=30, help="segundos entre capturas (la resolución de la medida)")
ap.add_argument("--budget", type=int, default=420,
help="segundos que puede tardar la primera pintura antes de dar ✗")
ap.add_argument("--until-paint", action="store_true",
help="cortar la observación en cuanto la página aparezca (más barato para medir el tiempo)")
ap.add_argument("--wayland-debug", action="store_true",
help="lanza el navegador con WAYLAND_DEBUG=1: registra CADA mensaje del "
"protocolo en los dos sentidos. Es la única forma de ver qué MANDA el "
"compositor sin recompilarlo (sus macros de debug están compiladas fuera)")
ap.add_argument("--set-rust-log", metavar="VALOR",
help="escribe RUST_LOG en /etc/cosmic-mode de la IMAGEN y apaga; "
"cadena vacía = lo quita. El compositor lo lee en el arranque SIGUIENTE, "
"que es la única forma de subirle el nivel de log sin recompilar")
ap.add_argument("--crashes", type=int, metavar="N",
help="fija `toolkit.startup.recent_crashes` del perfil del usuario antes de "
"lanzar: 0 lo limpia, 4 o más reproduce el diálogo de Modo de resolución "
"de problemas (medido: con 3 guardado todavía pinta, porque el arranque "
"suma ANTES de comparar). Sólo tiene efecto con --as-user. ⚠ 0 es el valor "
"por DEFECTO y un pref igual al default no se persiste: si lo que querés "
"medir es quién limpia el contador, NO lo pinnees")
ap.add_argument("--xulstore", metavar="ANCHOxALTO",
help="agrega una SEGUNDA fase en el mismo arranque con `xulstore.json` sembrado "
"(p. ej. 1152x720): la ventana arranca con un tamaño YA PERSISTIDO. Es el "
"control del 117x70 — si con semilla sale grande, lo que falla es que nadie "
"le da tamaño en el primer arranque")
ap.add_argument("--watch-prefs", action="store_true",
help="en CADA captura lee también `recent_crashes` y `last_success` del perfil y "
"los imprime con el segundo. Es lo que mide CUÁNTO tarda un arranque en "
"darse por bueno: el valor de `last_success` es la hora de ARRANQUE, no la "
"de escritura, así que el momento en que cambia sólo se sabe mirándolo "
"seguido. Ignora `--until-paint`: lo interesante pasa DESPUÉS de pintar")
ap.add_argument("--repeat", type=int, metavar="N",
help="corre N fases IDÉNTICAS en el mismo arranque. Con `--wait` corto (60 s, o "
"sea antes de que pinte) mide el contador de caídas: cada fase lee "
"`recent_crashes` ANTES de lanzar, así que la serie 0,1,2… dice cuánto suma "
"un arranque interrumpido — y si no sube, el envenenamiento vino de otro lado")
ap.add_argument("--out", default=os.path.join(RAIZ, "work/atuq-imagen"))
a = ap.parse_args()
rc = [0] # lista para poder tocarlo desde dentro del try/finally
out = a.out; os.makedirs(out, exist_ok=True)
vars_fd = os.path.join(out, "OVMF_VARS.fd")
shutil.copy(OVMF_VARS, vars_fd)
ser_sock, qmp_sock = os.path.join(out, "serial.sock"), os.path.join(out, "qmp.sock")
for p in (ser_sock, qmp_sock):
if os.path.exists(p):
os.unlink(p)
qemu = [
"nice", "-n", "10", "qemu-system-x86_64",
"-machine", "q35", "-accel", "tcg", "-cpu", "max", "-m", MEM, "-smp", SMP,
*VGA_ARGS, "-device", "virtio-gpu-pci,id=gpu0", "-display", "none", "-nic", "none",
"-drive", f"if=pflash,format=raw,unit=0,file={OVMF_CODE},readonly=on",
"-drive", f"if=pflash,format=raw,unit=1,file={vars_fd}",
"-drive", f"file={IMG},format=raw,if=virtio",
"-serial", f"unix:{ser_sock},server,nowait",
"-qmp", f"unix:{qmp_sock},server,nowait",
"-no-reboot",
]
print("== arrancando la imagen (TCG, sin KVM — paciencia)")
def primero_en_la_fila():
# El repo es COMPARTIDO y casi siempre hay una tanda de la granja compilando en esta misma
# máquina (4 cores, 7,6 G). Si la RAM se acaba, el que tiene que morir es ESTA VM y no el
# build de otro agente: `oom_score_adj` alto es la única forma de decirlo por adelantado.
with open("/proc/self/oom_score_adj", "w") as f:
f.write("900")
vm = subprocess.Popen(qemu, stdout=open(os.path.join(out, "qemu.log"), "wb"),
stderr=subprocess.STDOUT, preexec_fn=primero_en_la_fila)
# ⚠ QEMU TOMA UN LOCK DE ESCRITURA SOBRE LA IMAGEN, y sin esta comprobación el arnés espera
# 600 s una marca del serial que no va a llegar NUNCA: el socket queda creado, el `connect()`
# funciona y no falla nada — el error es UNA línea en `qemu.log` que nadie mira. Medido el
# 2026-09-15 al lanzar el control negativo con la corrida anterior todavía viva:
# Failed to get "write" lock. Is another process using the image [...]?
# Las corridas sobre la misma imagen van EN SERIE; esto lo dice en el primer segundo.
time.sleep(2)
if vm.poll() is not None:
raise SystemExit("✗ QEMU no arrancó:\n " +
open(os.path.join(out, "qemu.log")).read().strip())
try:
ser = Serial(ser_sock, os.path.join(out, "serial.log"))
print("== esperando a COSMIC…", flush=True)
ser.esperar("compositor OK", 600, nombre="(arranque de cosmic-comp)")
print(" compositor arriba; esperando el shell del serial (ventana de observación)", flush=True)
# 420 s alcanzaban con el anfitrión ocioso y NO con carga ~13: la VM llegaba a «+15s» y el
# arnés se rendía antes de que `cosmic-start` soltara el shell. El margen es de espera, no de
# medida: subirlo no cambia ningún número, sólo deja de tirar corridas por carga ajena.
ser.esperar("fin de la ventana de observación", 780, nombre="(fin de observación)")
time.sleep(3)
ser.s.sendall(b"\n")
print(ser.cmd("echo ENTORNO: WD=$WAYLAND_DISPLAY XDG=$XDG_RUNTIME_DIR DBUS=$DBUS_SESSION_BUS_ADDRESS").strip())
print(ser.cmd("ls -l $XDG_RUNTIME_DIR; ls /usr/lib/dri").strip())
if a.set_rust_log is not None:
# `cosmic-start` hace `. /etc/cosmic-mode` ANTES de `export RUST_LOG="${RUST_LOG:-info}"`,
# así que el fichero es la perilla. Se escribe y se apaga: quien la usa es el arranque
# siguiente — el compositor de ESTA sesión ya arrancó y no se lo puede reconfigurar.
ser.cmd("grep -v '^RUST_LOG=' /etc/cosmic-mode > /tmp/cm 2>/dev/null; true")
if a.set_rust_log:
ser.cmd("printf '%%s\\n' \"RUST_LOG=%s\" >> /tmp/cm" % a.set_rust_log)
ser.cmd("cp /tmp/cm /etc/cosmic-mode && sync")
print("== /etc/cosmic-mode ahora dice:")
print(ser.cmd("cat /etc/cosmic-mode").strip())
return
capturar(qmp_sock, out, "antes")
print("== captura ANTES (%s)" % ", ".join(PANTALLAS), flush=True)
if a.only_cosmic:
print("== CONTROL: no se lanza el navegador")
else:
# Una página de un color imposible de confundir con el escritorio.
ser.cmd("mkdir -p /var/log/cosmic")
# La página además DICE, por `dump()`, qué tamaño cree que tiene la ventana y qué
# pantalla ve el navegador. Con `screen=` y `outer=` en el log se sabe si el navegador
# ve la pantalla o no — y desde el §6.10.terdecies sabemos que SÍ la ve, así que lo que
# queda por contar es el otro lado: qué tamaño cree tener la VENTANA. Sin comillas
# simples: va dentro de un `printf '%s' '...'`.
ser.cmd("printf '%s' '"
"ATUQ PINTA
' > /tmp/pagina.html")
# ⚠ LO QUE DEJÓ LA CORRIDA ANTERIOR, ANTES DE PISARLO. El disco de esta VM es
# PERSISTENTE (`-drive` sin `snapshot=on`) ⇒ `/var/log/cosmic/` todavía tiene el
# arranque anterior, y el lanzamiento de esta corrida lo trunca. Ahí es donde salen los
# errores de JS del chrome, y NUNCA se habían mirado: se leía `tail -25`, que con
# `WAYLAND_DEBUG` son 25 líneas de protocolo y nada más. Copiarlo primero cuesta nada.
ser.cmd("rm -rf /var/log/cosmic-anterior; cp -a /var/log/cosmic /var/log/cosmic-anterior "
"2>/dev/null; true", 120)
print("---- corrida ANTERIOR: cómo terminó y qué se quejó ----")
print(ser.cmd("grep -a -h -E 'ATUQ-EXIT|JavaScript error|Uncaught|NS_ERROR|"
"###!!!|\\[Parent\\].*ERROR' /var/log/cosmic-anterior/atuq*.log "
"2>/dev/null | head -20", 120))
# DÓNDE VIVE EL PERFIL, SIN ADIVINARLO. El `find` anterior miraba sólo `/root` y esta
# imagen lo desmintió en silencio: dijo «no encontré el perfil» y la sonda salió muda.
# `$HOME` lo decide todo y el shell del serial lo hereda de `cosmic-start`, así que se
# IMPRIME; y el `find` va sobre la raíz entera con `-xdev` (que deja fuera /proc y /sys).
print("== HOME del shell de la sesión y perfiles que ya existen en el disco:")
print(ser.cmd("echo HOME=$HOME; find / -xdev -maxdepth 7 -name prefs.js 2>/dev/null | head -5", 180))
def perfil_de_la_fase(semilla):
"""Deja el perfil listo para la fase y devuelve su directorio (o None).
Las dos formas de lanzar NO son el mismo experimento y por eso conviven: el modo por
defecto usa un perfil NUEVO en tmpfs —primer arranque de verdad, que es el caso que
sale 117×70— y `--as-user` reproduce lo que se tecleó a mano en el §6.10.ter, con el
perfil del usuario y sin variables de entorno.
"""
if a.as_user:
hallado = ser.cmd("find / -xdev -maxdepth 7 -name prefs.js 2>/dev/null | head -3", 180)
perfil = next((l.strip() for l in hallado.splitlines()
if l.strip().endswith("prefs.js") and l.strip().startswith("/")), None)
if not perfil:
print(" ⚠ no encontré el perfil del usuario: la sonda ATUQ-DIAG va a salir muda")
return None
d = os.path.dirname(perfil)
print("== perfil del usuario:", d)
# ⚠⚠ EL CONTADOR DE CAÍDAS DEL PERFIL, SIEMPRE A LA VISTA. Con
# `toolkit.startup.recent_crashes` por encima de `max_resumed_crashes` (3 por
# defecto) el navegador NO abre el navegador: abre el diálogo de Modo de
# resolución de problemas. Y este arnés mata la VM con el navegador vivo, así
# que CADA corrida fallida puede sumar uno: el instrumento degrada el sujeto y
# la tasa medida deja de ser del producto. Sin este número impreso, una corrida
# no se puede interpretar.
# ⚠ `last_success` VA EN EL MISMO VOLCADO. Es la otra mitad del cálculo: sin
# él, un `recent_crashes` que no se movió es ambiguo entre «no subió» y «subió y
# lo limpió el gancho de cierre», que son conclusiones opuestas sobre la misma
# cifra.
volcado = ser.cmd("grep -E 'toolkit.startup.(recent_crashes|max_resumed|"
"last_success)|browser.sessionstore.max_resumed' %s/prefs.js" % d, 60)
print(volcado.strip())
estado["recent_crashes_antes"] = leer_contador_de_caidas(volcado)
estado["last_success_antes"] = leer_sello_de_exito(volcado)
# ⚠ EL AVISO QUE FALTABA. Medido el 2026-09-15: el arranque que encuentra el
# anterior sin terminar SUMA UNO y compara DESPUÉS, así que con 3 guardado esta
# corrida abre el diálogo de Modo de resolución de problemas y no el navegador —
# y como el arnés mata la VM antes del gancho de cierre, CADA corrida suma.
# Una serie se rompe sola a la cuarta; por eso se dice acá y no en el post-mortem.
previo = estado["recent_crashes_antes"]
if previo is not None and previo >= 3 and a.crashes is None:
print(" ⚠⚠ contador en %d: ESTA corrida va a abrir el DIÁLOGO, no el "
"navegador. Para medir la pintura, pasá --crashes 0" % previo)
else:
d = "/tmp/perfil"
ser.cmd("rm -rf /tmp/perfil && mkdir -p /tmp/perfil")
ujs = ['user_pref("browser.dom.window.dump.enabled", true);',
'user_pref("browser.shell.checkDefaultBrowser", false);']
if a.crashes is not None:
# El mismo mando en los DOS sentidos: 0 limpia el contador (¿pinta?) y un
# número alto lo reproduce a propósito (¿se rompe?). `user.js` gana sobre
# `prefs.js` en cada arranque, así que fija el valor de la corrida.
ujs.append('user_pref("toolkit.startup.recent_crashes", %d);' % a.crashes)
print("== recent_crashes FIJADO a %d para esta corrida" % a.crashes)
ser.cmd("rm -f %s/user.js" % d)
for linea in ujs:
ser.cmd("printf '%%s\\n' '%s' >> %s/user.js" % (linea, d))
if semilla:
# EL CONTROL. `browser-init.js` —el que trae el propio artefacto, leído del
# `omni.ja` sellado— fija el tamaño de arranque UNA sola vez:
#
# } else if (!document.documentElement.hasAttribute("width")) {
# let width = Math.min(screen.availWidth * 0.9, 1280);
# let height = Math.min(screen.availHeight * 0.9, 1040);
#
# y ese atributo, en un perfil ya usado, lo rellena el `xulstore.json`. Sembrarlo
# a mano separa las dos explicaciones posibles del 117×70 en UNA corrida: si con
# semilla la ventana sale grande, el fallo es «nadie le dio tamaño» (ese `if` no
# corrió); si sale igual de chica, el tamaño no es lo que falla.
w, h = semilla.lower().split("x")
doc = {"chrome://browser/content/browser.xhtml":
{"main-window": {"screenX": "0", "screenY": "0",
"width": w, "height": h, "sizemode": "normal"}}}
ser.cmd("printf '%%s' '%s' > %s/xulstore.json" % (json.dumps(doc), d))
elif not a.as_user:
# Sólo en el perfil DESECHABLE de tmpfs. ⚠ En `--as-user` el `xulstore.json` es
# el estado del usuario —el tamaño que la ventana RECUERDA— y borrarlo cambiaría
# el experimento sin decirlo: la corrida siguiente ya no sería «como lo abre el
# usuario» sino un primer arranque disfrazado.
ser.cmd("rm -f %s/xulstore.json" % d)
ser.cmd("sync")
print("== el perfil, ANTES de lanzar (user.js y el tamaño que RECUERDA):")
print(ser.cmd("cat %s/user.js; echo ---; cat %s/xulstore.json 2>/dev/null || "
"echo '(sin xulstore.json: la ventana no recuerda ningún tamaño)'"
% (d, d), 60).strip())
return d
def matar_al_navegador():
"""Deja la sesión sin ningún `atuq` vivo antes de la fase siguiente.
Por PID leído de `/proc/*/comm`, no por `pkill -f atuq`: el patrón engancha la propia
línea de orden del shell del serial y ahí se mata la sesión entera (medido en el hub,
sale 144 y lo que sigue no corre).
"""
# ⚠ `-9` A PROPÓSITO. Un `kill` a secas le da a Gecko su apagado ordenado, y un
# apagado ordenado es EXACTAMENTE la variable bajo prueba: lo que hace este arnés al
# terminar es matar la VM entera, que no avisa. Con `-KILL` la fase siguiente
# encuentra el mismo estado que encontraría tras una corrida matada de verdad.
ser.cmd("for p in /proc/[0-9]*; do grep -q atuq $p/comm 2>/dev/null && "
"kill -9 ${p#/proc/}; done; true", 60)
time.sleep(8)
salida = ser.cmd("for c in /proc/[0-9]*/comm; do cat $c 2>/dev/null; done | grep -c atuq")
# El serial hace ECO de la orden, así que la respuesta es la ÚLTIMA línea que sea un
# número y no la primera que aparezca: leer la primera devuelve un trozo del eco.
cuenta = next((l.strip() for l in reversed(salida.splitlines()) if l.strip().isdigit()), "?")
print(" navegadores vivos tras el kill: " + cuenta)
# LAS FASES. Una sola es la medición de siempre; con `--xulstore` se agrega una SEGUNDA
# en el MISMO arranque, que es un A/B de verdad: mismo compositor, misma sesión, misma
# carga del anfitrión. Dos arranques distintos no lo serían — y cada arranque cuesta
# cinco minutos de TCG.
# El estado del perfil que hay que ADJUNTAR a la medición: el contador de caídas antes
# y después. Vive acá afuera porque lo escribe la preparación de la fase y lo lee la
# anotación, y porque con `--crashes` fijado hay que poder distinguir el valor que
# PUSIMOS del que el perfil traía.
estado = {"recent_crashes_fijado": a.crashes}
fases = [("base", None)]
if a.xulstore:
fases.append(("semilla-%s" % a.xulstore, a.xulstore))
if a.repeat:
# N fases iguales: lo que varía entre ellas no es la configuración sino el ESTADO que
# deja la anterior en el perfil, que es justo lo que se quiere medir.
fases = [("k%d" % i, None) for i in range(1, a.repeat + 1)]
for fase, semilla in fases:
print("\n===== FASE «%s» =====" % fase, flush=True)
if fase != fases[0][0]:
matar_al_navegador()
perfil_d = perfil_de_la_fase(semilla)
log_atuq = "/var/log/cosmic/atuq-%s.log" % fase
log_moz = "/var/log/cosmic/moz-%s" % fase
capturar(qmp_sock, out, "%s-antes" % fase)
print("== captura ANTES de la fase (%s)" % ", ".join(PANTALLAS), flush=True)
wd = "WAYLAND_DEBUG=1 " if a.wayland_debug else ""
moz = ("MOZ_LOG='Widget:5,WidgetWayland:5,WaylandBackend:5,WidgetScreen:5,timestamp' "
"MOZ_LOG_FILE=%s " % log_moz)
if a.as_user:
orden = wd + moz + "/usr/bin/atuq file:///tmp/pagina.html"
else:
orden = (wd + "MOZ_ENABLE_WAYLAND=1 GDK_BACKEND=wayland " + moz +
"/usr/bin/atuq --no-remote --profile /tmp/perfil file:///tmp/pagina.html")
# ⚠ EL NAVEGADOR SE MURIÓ Y NADIE LO SUPO (medido 2026-09-15, 17:12): el shell
# imprimió «[1]+ Done» a los ~25 s y la corrida siguió 420 s fotografiando un
# escritorio sin navegador, para terminar diciendo «no pintó». Un proceso que sale
# deja un CÓDIGO, y ese código es la diferencia entre «se cayó» y «se fue solo»; va
# al log, en el subshell, para que quede escrito aunque el arnés muera después.
print(ser.cmd("( %s; echo ATUQ-EXIT=$? ) > %s 2>&1 &" % (orden, log_atuq), fondo=True).strip())
print(f"== navegador lanzado; observando {a.wait}s", flush=True)
t0 = time.time(); n = 0
primera = None # segundos hasta la PRIMERA captura con la página en pantalla
donde = None
while time.time() - t0 < a.wait:
time.sleep(a.cadence); n += 1
tomas = capturar(qmp_sock, out, f"{fase}-durante-{n}")
t = int(time.time() - t0)
medidas = {p: pintado(f) for p, f in tomas.items()}
px = max((v for v in medidas.values() if v is not None), default=None)
donde = next((p for p, v in medidas.items() if v and v > 100_000), None)
vigilancia = ""
if a.watch_prefs and perfil_d:
# Una sola lectura, corta, por captura. `tr` junta las dos líneas para que
# entren en el renglón del avance: lo que importa es CUÁNDO cambian.
vigilancia = " prefs: " + " ".join(
l.strip() for l in ser.cmd(
"grep -hE 'toolkit.startup.(recent_crashes|last_success)' "
"%s/prefs.js | tr -d '\"' | tr '\\n' ' '" % perfil_d, 60).splitlines()
if "toolkit.startup" in l and "grep" not in l)
if primera is None and px and px > 100_000:
primera = t
print(f" +{t}s ██ PRIMERA PINTURA — {px} px de la página EN {donde}{vigilancia}", flush=True)
# ⚠ NO SE CORTA ANTES DEL SELLO, Y ESTO ES MEDIDO (2026-09-15). Gecko
# marca el arranque como bueno —escribe `toolkit.startup.last_success` y
# BORRA `recent_crashes`— y eso llega al disco entre los +100 s y los +137 s
# desde el lanzamiento (`work/cuanto-1.txt`, leyendo el perfil en cada
# captura). El reloj es el del ARRANQUE, no el de la pintura: `cierre-1`
# pintó a +120 s y selló, y la S1 de la serie pintó a +97 s, se cortó con
# `--until-paint` y dejó el contador en 1. Cortar en la pintura mata la VM
# antes del sello, y CADA corrida así suma uno: cuatro y el perfil abre el
# diálogo en vez del navegador. El piso es la diferencia entre medir el
# producto y medir el daño que hace el instrumento.
if a.until_paint and not a.watch_prefs and t >= PISO_SELLO:
break
if a.until_paint and t < PISO_SELLO:
print(f" (sigo hasta +{PISO_SELLO}s: antes de eso el arranque no está "
f"sellado y matar la VM envenena el perfil)", flush=True)
else:
vivos = ser.cmd("for c in /proc/[0-9]*/comm; do cat $c 2>/dev/null; done | grep -c atuq")
v = vivos.splitlines()[1].strip() if len(vivos.splitlines()) > 1 else "?"
detalle = " ".join(f"{p}={medidas[p]}" for p in PANTALLAS)
print(f" +{t}s px de la página: {detalle} procesos atuq: {v}{vigilancia}", flush=True)
capturar(qmp_sock, out, "%s-despues" % fase)
print("== captura DESPUES de la fase", flush=True)
# EL NÚMERO. No «pinta / no pinta»: CUÁNTO TARDA. Medido el 2026-09-14 sobre esta
# misma imagen, la primera pintura cae entre +137 s y +204 s con el perfil por
# defecto y ~+134 s con uno nuevo en tmpfs — y con la máquina anfitriona cargada pasa
# de los +300 s. Por eso el presupuesto es HOLGADO y se dice el número siempre: un
# guardián que sólo contestara «no pintó» a los 5 min habría firmado el error del
# §6.10.ter.
if primera is None:
print(f"✗ el navegador NO pintó en {a.wait}s — mirá {out}/{fase}-despues.png y el MOZ_LOG:")
print(" `mapped 1` + «marked as visible & has buffer» + WaylandBufferSHM ⇒ estaba pintando"
" y la captura llegó antes; sin eso, es un fallo de verdad")
rc[0] = 1
else:
print(f"✓ primera pintura: +{primera}s (presupuesto {a.budget}s)")
if primera > a.budget:
print(f"✗ tardó {primera - a.budget}s MÁS que el presupuesto")
rc[0] = 1
if perfil_d and a.as_user:
# ⚠ EL ESTADO FINAL ES PARTE DE LA PRUEBA: el número cambia DENTRO de la
# corrida —lo escribe el ARRANQUE al encontrar el anterior sin terminar, no el
# kill— así que sin el «después» no se puede encadenar una corrida con la
# siguiente, que es lo que convierte esto en una serie legible (medido:
# 2 → 3 → 4 en tres fases de un mismo arranque). Se lee con el navegador
# todavía vivo, o sea que refleja el último volcado de prefs de Gecko.
# ⚠ `last_success` VA EN LOS DOS VOLCADOS. Es la otra mitad del cálculo, y
# sin él en el «después» una limpieza no dice si el arranque además SELLÓ el
# éxito: son dos preguntas que se contestan con el mismo grep y una salía muda.
volcado = ser.cmd("grep -E 'toolkit.startup.(recent_crashes|last_success)' %s/prefs.js || "
"echo '(el pref no está: arranque sin caídas pendientes)'"
% perfil_d, 60)
estado["recent_crashes_despues"] = leer_contador_de_caidas(volcado)
estado["last_success_despues"] = leer_sello_de_exito(volcado)
# ⚠ EL PISO SE COMPRUEBA, NO SE CONFÍA. `PISO_SELLO` son 180 s medidos EN ESTA
# máquina (TCG sin KVM, con la carga que tenga el anfitrión): con el anfitrión
# cargado el mismo arranque puede no llegar al gancho, y entonces esta corrida
# SUMA al contador y envenena la siguiente — en silencio, que es como pasó la
# primera vez. Con el sello leído antes y después, eso se puede DECIR.
if estado["last_success_despues"] is not None and \
estado["last_success_despues"] == estado.get("last_success_antes"):
print(" ⚠⚠ el sello NO se movió (%s): este arranque no terminó ⇒ la corrida "
"SUMA al contador de caídas. Si usaste --until-paint, subí PISO_SELLO"
% estado["last_success_despues"])
elif estado["last_success_despues"] is not None:
print(" ✓ el arranque SELLÓ el éxito (last_success %s → %s): esta corrida "
"no envenena la siguiente"
% (estado.get("last_success_antes"), estado["last_success_despues"]))
print("---- el contador de caídas, DESPUÉS ----")
print(volcado.strip())
# ⚠ SÓLO LA FASE BASE SE ANOTA. La serie de `primera-pintura.json` es una TASA del
# producto tal como se entrega; una fase con el tamaño de ventana sembrado a mano es
# otro experimento, y mezclarlos haría que el denominador dejara de significar nada.
if semilla is None:
anotar_medicion(primera, a, donde if primera is not None else None, estado)
else:
print(" (fase con semilla: NO se anota en la serie de la tasa)")
# La evidencia que no se puede leer de una captura: cómo terminó el proceso, qué se
# quejó el chrome, y qué hizo el widget de Wayland.
# QUÉ QUEDÓ PERSISTIDO. `browser.xhtml` lleva `persist="… width height sizemode"`,
# así que el tamaño con el que terminó la ventana se ESCRIBE en el perfil y lo hereda
# la corrida siguiente: si una corrida sale de 117×70 y lo guarda, el fallo se
# aprende. Sin este volcado, «intermitente» y «contagiado» se ven igual.
if perfil_d:
print("---- el perfil, DESPUÉS: qué tamaño quedó recordado ----")
print(ser.cmd("cat %s/xulstore.json 2>/dev/null || echo '(no escribió xulstore.json)'"
% perfil_d, 60))
print("---- cómo terminó, y de qué se quejó el chrome ----")
print(ser.cmd("grep -a -E 'ATUQ-EXIT|JavaScript error|Uncaught|NS_ERROR|###!!!' "
"%s | head -25" % log_atuq, 120))
print("---- atuq.log (cabeza) ----")
print(ser.cmd("head -20 %s" % log_atuq, 60))
print("---- atuq.log (cola) ----")
print(ser.cmd("tail -20 %s" % log_atuq, 60))
print("---- MOZ_LOG: creación de la ventana ----")
print(ser.cmd("grep -a -m 40 -E 'nsWindow::Create|CreateNative|Map|configure|Show|frame callback|Buffer' "
"%s.moz_log | head -40" % log_moz, 120))
# QUÉ PANTALLA VE GECKO — contestado el 2026-09-15 y por eso se queda: la sonda que
# ya contestó es la que avisa cuando la respuesta cambia. `New monitor 0 size
# [0,0 -> 1280 x 800]` ANTES de `Initial resize to 1 x 1` ⇒ la geometría de la salida
# NO es lo que falta.
print("---- MOZ_LOG: pantallas que ve Gecko y tamaños del nsWindow ----")
print(ser.cmd("grep -a -E 'WidgetScreen|Screen\\[|AddScreen|nsWindow::Resize|Initial resize|"
"SetSizeMode|OnConfigure|SizeAllocate|LockAspect' "
"%s.moz_log | head -50" % log_moz, 180))
# Y lo que dice el propio navegador, desde la página, por `dump()`: `screen=` es lo
# que el contenido ve de la pantalla y `outer=` el tamaño de la ventana. Dos fuentes
# independientes para el mismo número; si se contradicen, eso también es un dato.
print("---- la página: ATUQ-DIAG ----")
print(ser.cmd("grep -a ATUQ-DIAG %s | head -10" % log_atuq, 120))
print("---- MOZ_LOG: últimas líneas ----")
print(ser.cmd("tail -25 %s.moz_log" % log_moz, 60))
# El otro lado de la conversación. Gecko commitea a ciegas cuando nadie le devuelve
# frame callbacks (§6.10.nonies), y eso lo decide el COMPOSITOR: sin su log, «no
# pinta» sólo se puede mirar desde el cliente, que es la mitad que ya sabemos miente.
if a.wayland_debug:
# ⚠ EN `WAYLAND_DEBUG` LA FLECHA ES DEL CLIENTE. `-> obj.metodo()` es un PEDIDO
# que manda el navegador; los EVENTOS del compositor son las líneas SIN flecha.
# Filtrar por `->` es leer otra vez al cliente. Y los nombres llevan `@id` en el
# medio, así que `wl_surface.commit` no engancha: hay que anclar en el método.
# QUIÉN ELIGE EL TAMAÑO: `attach` no lo dice —el tamaño del buffer está en
# `create_buffer(…, W, H, stride, fmt)`— y lo que el cliente DECLARA querer está
# en `set_window_geometry`. Puestos en orden y en los DOS sentidos se ve quién
# propone (contestado en el §6.10.duodecies: lo propone el cliente).
print("---- protocolo: el tamaño, en orden (→ = pedido del cliente) ----")
# ⚠ El filtro EXCLUYE `mode(0,`: QEMU anuncia ~60 modos no-actuales y con ellos
# dentro el `head` cortaba ANTES del `set_window_geometry` — la lista que existe
# para ordenar dos cosas se quedaba sin una de las dos.
print(ser.cmd("grep -a -n -E 'create_buffer|set_window_geometry|configure|ack_configure|"
"get_toplevel|set_min_size|set_max_size|set_title|set_app_id|\\.attach|"
"wl_output|\\.mode\\(|\\.geometry\\(|\\.done\\(\\)' "
"%s | grep -av 'mode(0,' | head -80" % log_atuq, 240))
print("---- protocolo: EVENTOS del compositor (sin flecha) ----")
print(ser.cmd("grep -av ' -> ' %s | "
"grep -a -E 'xdg_surface|xdg_toplevel|wl_callback|wl_output|wl_surface' | "
"tail -40" % log_atuq, 180))
print("---- cosmic-comp: superficies, salidas y foco ----")
print(ser.cmd("grep -a -i -E 'output|workspace|focus|toplevel|surface|xdg|map' "
"/var/log/cosmic/cosmic-session.log | tail -40", 120))
print("---- tamaño de los logs ----")
print(ser.cmd("wc -l /var/log/cosmic/atuq-*.log /var/log/cosmic/moz-*.moz_log "
"/var/log/cosmic/cosmic-session.log /var/log/cosmic/cosmic-start.log", 30))
finally:
try:
qmp(qmp_sock, [{"execute": "quit"}])
except Exception:
pass
time.sleep(2); vm.terminate()
try:
vm.wait(20)
except Exception:
vm.kill()
# Las capturas salen en PPM (lo único que sabe QMP); a PNG para poder mirarlas.
try:
from PIL import Image
for f in sorted(os.listdir(out)):
if f.endswith(".ppm"):
Image.open(os.path.join(out, f)).save(os.path.join(out, f[:-4] + ".png"))
print("== capturas convertidas a PNG en", out)
except Exception as e:
print(" ⚠ sin conversión a PNG:", e)
return rc[0]
if __name__ == "__main__":
sys.exit(main())