diff --git a/docs/26-atuq-envoltorio-gecko.md b/docs/26-atuq-envoltorio-gecko.md index b143bec3..f417a7e8 100644 --- a/docs/26-atuq-envoltorio-gecko.md +++ b/docs/26-atuq-envoltorio-gecko.md @@ -1917,6 +1917,83 @@ diez corridas no se separa**. nueva sobrescribió los crudos de la anterior (se salvaron 9 de 10 en `work/serie-dos-tarjetas/`). Arreglado después de la serie — no durante: bash lee el guion a medida que lo ejecuta. +#### 6.10.decies El log del compositor a `info` NO puede contestar — y por qué hizo falta una perilla (2026-09-14) + +La hipótesis del §6.10.nonies —«nadie le devuelve frame callbacks»— se contesta del lado de +`cosmic-comp`, así que el arnés ahora vuelca **`/var/log/cosmic/cosmic-session.log`**, que ya existía +desde el primer día y nunca se había mirado. Corrida fallida (91 % de azul de escritorio, sin +ventana), y el log entero: + + 92 líneas. Todas de 21:17:48 — los segundos del arranque. Ni una superficie, ni un toplevel, + ni una salida. Termina en: + ERROR cosmic_comp::xwayland: Failed to start Xwayland + err=Custom { kind: AddrInUse, error: "Could not find a free socket for the XServer." } + +Dos cosas, y conviene no confundirlas: + +1. **el ERROR de Xwayland es ruido aquí** — la distro es Wayland-only por decisión (§frente-gnome), y + `atuq` es cliente Wayland nativo: que no haya X no le quita ni un frame. Es una pista falsa + esperando a que alguien la agarre; +2. **a `RUST_LOG=info` el compositor no dice NADA de ventanas.** El log no es que muestre algo raro: + es que no habla del tema. Un log en silencio no es evidencia de nada — lo mismo imprime cuando + todo anda. + +⇒ para responder hace falta subirle el nivel, y eso **no se puede hacer desde fuera**: `cosmic-comp` +lo lanza `cosmic-start` desde el getty, en el arranque, sin ambiente heredable. La perilla existe y +estaba a la vista: `cosmic-start` hace `. /etc/cosmic-mode` **antes** de +`export RUST_LOG="${RUST_LOG:-info}"`, así que ese fichero manda. Y la imagen se arranca sin +`-snapshot`, o sea que **lo que se escribe adentro persiste**. De ahí +`atuq-en-imagen.py --set-rust-log VALOR`: entra por el serial, escribe `/etc/cosmic-mode` y apaga; lo +usa el arranque SIGUIENTE. Con la cadena vacía lo quita, que es como se deja la imagen después de +medir — subirle el log a una imagen compartida y olvidárselo es dejar una trampa para el próximo. + +#### 6.10.undecies **La ventana SÍ está: mide 117×70 px** — y la hipótesis de los frame callbacks era falsa (2026-09-14) + +Como el compositor no habla por su log (§6.10.decies), se le preguntó por el **protocolo**: +`atuq-en-imagen.py --wayland-debug` lanza el navegador con `WAYLAND_DEBUG=1`, que registra cada +mensaje en los dos sentidos. Corrida fallida (91 % de azul de escritorio), y esto es lo que MANDA +`cosmic-comp`: + + xdg_toplevel#58.configure_bounds(0, 0) ← al mapear: todavía no sabe el tamaño + xdg_toplevel#58.configure(0, 0, array[0]) + xdg_toplevel#58.configure_bounds(1280, 692) ← después sí + xdg_toplevel#58.configure(117, 70, array[16]) ← y la ventana queda de 117×70 + wl_surface#52.enter(wl_output#16) + wl_callback#76.done(…) × 43 + +Y el píxel lo confirma, restando el cuadro de ANTES del de DESPUÉS: aparece un cluster en +**(496,115), de unos 286×86 con sombra**, con el blanco `#fafafb` y el acento cian `#63d0df` de la +decoración de COSMIC. Una ventanita. + +⇒ **`atuq` no deja de pintar: pinta una ventana de 117×70 px.** Con eso caen dos cosas que este mismo +documento daba por buenas hace dos secciones: + +| lo que decía | lo que mide el protocolo | +|---|---| +| «nadie le devuelve frame callbacks» (§6.10.nonies) | **43 `wl_callback.done`**. Los devuelve | +| «deja de trabajar a los ~40 s» | deja de **escribir**: con la ventana de 117×70 no hay casi nada que redibujar | +| «7 de 10 no tienen ventana» (§6.10.nonies) | **la tienen**. Mi contador de magenta no la ve porque es 0,7 % de la pantalla | + +**La tasa 2 de 10, entonces, tampoco mide lo que decía.** No es «pintó / no pintó»: es «la ventana +salió grande / salió de 117×70». El fenómeno es real y sigue estando —una ventana así es inusable— +pero el nombre estaba mal, y con el nombre mal la causa que se busca es otra. + +**De dónde sale 117×70, y qué es hipótesis.** El primer `configure` llega con `bounds(0,0)`: en ese +instante el compositor todavía no le puede decir al cliente de qué tamaño es la pantalla, y el +protocolo dice «elegí vos». La medida NO prueba quién eligió 117×70 —para eso hay que ver qué +tamaño de buffer commitea el cliente ANTES de ese configure—, pero el orden es compatible con una +**carrera**: `atuq` dimensiona su ventana antes de tener la geometría de la salida y cae en un +mínimo. En las corridas que salen bien la ventana mide 1073×549 (§6.10.quater), que es lo que se ve +cuando la geometría llegó primero. **Eso es lo próximo a medir, y se mide con el mismo arnés.** + +⚠ **Método, tercera vez en el mismo frente:** el primer vuelco del protocolo filtró por `' -> '` +creyendo que era «lo que manda el compositor». En `WAYLAND_DEBUG` la flecha marca los **pedidos del +cliente**; los eventos son las líneas SIN flecha. O sea que volví a leer al navegador —la mitad que +ya sabíamos que miente— con un filtro nuevo. Y las cuentas dieron cinco ceros porque los nombres +llevan `#id` en el medio (`wl_surface#30.commit`), así que `wl_surface.commit` no engancha: **un +grep que devuelve 0 puede ser una ausencia o puede ser un patrón mal escrito, y las dos se ven +igual.** + ### 6.11 Y ahora la pregunta que faltaba: ¿REPRODUCE? (2026-09-07) El §6.10 preguntó «¿qué NO puede hacer?» y contestó leyendo cadenas. Media pregunta. La otra mitad diff --git a/scripts/cosmic/atuq-en-imagen.py b/scripts/cosmic/atuq-en-imagen.py index d715f248..082c0a6a 100755 --- a/scripts/cosmic/atuq-en-imagen.py +++ b/scripts/cosmic/atuq-en-imagen.py @@ -220,6 +220,14 @@ def main(): 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("--out", default=os.path.join(RAIZ, "work/atuq-imagen")) a = ap.parse_args() @@ -259,12 +267,27 @@ def main(): 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) - ser.esperar("fin de la ventana de observación", 420, nombre="(fin de observación)") + # 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) @@ -283,12 +306,13 @@ def main(): # mano en el §6.10.ter —`atuq` pelado, con SU perfil y sin variables— que es lo único que # sigue distinto entre aquella corrida y ésta. El `MOZ_LOG` va en los dos: no cambia el # comportamiento, sólo deja rastro. + wd = "WAYLAND_DEBUG=1 " if a.wayland_debug else "" if a.as_user: - lanz = ("MOZ_LOG='Widget:5,WidgetWayland:5,WaylandBackend:5,timestamp' " + lanz = (wd + "MOZ_LOG='Widget:5,WidgetWayland:5,WaylandBackend:5,timestamp' " "MOZ_LOG_FILE=/var/log/cosmic/moz " "/usr/bin/atuq file:///tmp/pagina.html > /var/log/cosmic/atuq.log 2>&1 &") else: - lanz = ("MOZ_ENABLE_WAYLAND=1 GDK_BACKEND=wayland " + lanz = (wd + "MOZ_ENABLE_WAYLAND=1 GDK_BACKEND=wayland " "MOZ_LOG='Widget:5,WidgetWayland:5,WaylandBackend:5,timestamp' " "MOZ_LOG_FILE=/var/log/cosmic/moz " "/usr/bin/atuq --no-remote --profile /tmp/perfil file:///tmp/pagina.html " @@ -347,8 +371,37 @@ def main(): "/var/log/cosmic/moz.moz_log | head -40", 120)) print("---- MOZ_LOG: últimas líneas ----") print(ser.cmd("tail -25 /var/log/cosmic/moz.moz_log", 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 que miente. + if a.wayland_debug: + # Lo que INTERESA no es lo que pide el cliente sino lo que llega de vuelta: las + # líneas `[ ]` de entrada son eventos DEL COMPOSITOR. Sin `wl_callback.done` no + # hay frame callbacks, que es exactamente la hipótesis del §6.10.nonies. + # ⚠ 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, que es justo la mitad que ya sabemos que + # miente. Y los nombres llevan `@id` en el medio, así que `wl_surface.commit` no + # engancha: hay que anclar en el método. + print("---- protocolo: EVENTOS del compositor (sin flecha) ----") + print(ser.cmd("grep -av ' -> ' /var/log/cosmic/atuq.log | " + "grep -a -E 'xdg_surface|xdg_toplevel|wl_callback|wl_output|wl_surface' | " + "tail -40", 180)) + print("---- protocolo: cuentas (evento = sin flecha) ----") + print(ser.cmd("for k in xdg_toplevel# xdg_surface# wl_callback# wl_output#; do " + "printf 'EVENTOS %s ' $k; grep -av ' -> ' /var/log/cosmic/atuq.log | " + "grep -ac $k; done", 180)) + print(ser.cmd("printf 'done() '; grep -av ' -> ' /var/log/cosmic/atuq.log | " + "grep -ac 'done('; printf 'configure() '; grep -av ' -> ' " + "/var/log/cosmic/atuq.log | grep -ac 'configure('", 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("---- cosmic-comp: últimas líneas ----") + print(ser.cmd("tail -30 /var/log/cosmic/cosmic-session.log", 60)) print("---- tamaño de los logs ----") - print(ser.cmd("wc -l /var/log/cosmic/moz.moz_log /var/log/cosmic/atuq.log", 30)) + print(ser.cmd("wc -l /var/log/cosmic/moz.moz_log /var/log/cosmic/atuq.log " + "/var/log/cosmic/cosmic-session.log /var/log/cosmic/cosmic-start.log", 30)) finally: try: qmp(qmp_sock, [{"execute": "quit"}])