atuq: la ventana SI esta — mide 117x70 px (lo dice el protocolo)

Como cosmic-comp no emite DEBUG (macros compiladas fuera), se le pregunto
por el protocolo con WAYLAND_DEBUG=1. Manda configure_bounds(0,0) al
mapear, despues bounds(1280,692) y configure(117,70): la ventana queda de
117x70. El pixel lo confirma — restando el cuadro de antes aparece un
cluster de 286x86 con la decoracion de COSMIC en (496,115).

Cae la hipotesis del §6.10.nonies: hay 43 wl_callback.done, o sea que SI
hay frame callbacks. Y la tasa 2 de 10 no medía «pinto/no pinto» sino
«ventana grande / ventana de 117x70».

Arnes: --wayland-debug y --set-rust-log (perilla por /etc/cosmic-mode, que
cosmic-start lee antes de RUST_LOG); margen de espera 420->780s porque con
carga ~13 la VM no llegaba al shell.

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"}])