Skip to content

Commit 59c7c5f

Browse files
NathanFlurryclaude
andcommitted
feat(debug): X11 stream reassembler + robust unix poll; localize render root to an unknown ext opcode
- scripts/xreassemble.py: reassembles the FULL client/server X11 byte streams (handling the setup request/reply + BigRequests) and matches requests to replies by sequence, so the exact unanswered request is visible. SECURE_EXEC_XTRACE=<n> now sets the per-payload capture cap (default 256; large for full reassembly). - ActiveUnixSocket::poll: try_recv first, so a guest non-blocking drain (net.poll(fd,0)) never misses a delivered request via the recv_timeout(ZERO)-returns-Timeout-with-data-pending std gotcha. Strictly more correct (did not by itself unblock the render). DIAGNOSIS (tools #2/#3): lxpanel creates the panel toplevel + sets its DOCK/_NET_WM properties but the toplevel is NEVER mapped — GTK queued its MapWindow in the GLib loop, which is stuck in its first dispatch. lxpanel waits for a GetInputFocus reply (op 0x2b) that never arrives; the server received all bytes (delivery is byte-symmetric) yet sits idle in net_poll. Root lead: the first-draw batch sends requests with major opcode 0x89=137, but Xvfb's registered extensions use opcodes 128/130/132/134/138 — NO extension owns 137. An unknown-opcode request mis-handled by the server desyncs the request stream (server waits for bytes to finish a phantom request; client waits for its reply) = the deadlock. Next: confirm which client lib emits op 137 / fix Xvfb's unknown-opcode handling (platform layer). Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent ba98a76 commit 59c7c5f

2 files changed

Lines changed: 135 additions & 4 deletions

File tree

crates/sidecar/src/execution.rs

Lines changed: 22 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1824,6 +1824,18 @@ impl ActiveUnixSocket {
18241824
}
18251825

18261826
fn poll(&mut self, wait: Duration) -> Result<Option<JavascriptTcpSocketEvent>, SidecarError> {
1827+
// Always check for an already-queued event first. `recv_timeout(Duration::ZERO)` can return
1828+
// `Timeout` while a message is pending (it compares the deadline before draining), so a guest
1829+
// non-blocking drain (`net.poll(fd, 0)`) could MISS a delivered request and park — the cross-VM
1830+
// poll stall this fixes. For wait>0 this also returns ready data without sleeping.
1831+
match self.events.try_recv() {
1832+
Ok(event) => return Ok(Some(event)),
1833+
Err(mpsc::TryRecvError::Disconnected) => return Ok(None),
1834+
Err(mpsc::TryRecvError::Empty) => {}
1835+
}
1836+
if wait.is_zero() {
1837+
return Ok(None);
1838+
}
18271839
match self.events.recv_timeout(wait) {
18281840
Ok(event) => Ok(Some(event)),
18291841
Err(RecvTimeoutError::Timeout) => Ok(None),
@@ -12495,15 +12507,21 @@ fn spawn_tls_socket_reader(
1249512507
}
1249612508

1249712509
// Tool #2: X11-wire tap. When SECURE_EXEC_XTRACE is set, dump a unix socket's bytes as
12498-
// `[xtrace] <dir> <path> len=<n> <hex...>` (first 48 bytes — enough for the X11 opcode/sequence/length
12499-
// header). Decode offline with experiments/wasm-gui/scripts/xdecode.py. Zero cost when unset.
12510+
// `[xtrace] <dir> <path> len=<n> <hex...>`. Decode offline with experiments/wasm-gui/scripts/xdecode.py
12511+
// (per-chunk headers) or scripts/xreassemble.py (full request/reply stream). Zero cost when unset.
12512+
// SECURE_EXEC_XTRACE=<n> caps the hex per payload at n bytes (default 256, enough for the X11 header);
12513+
// set it large (e.g. 65536) to capture full requests for xreassemble.py.
1250012514
fn xtrace_dump(path: Option<&str>, dir: &str, bytes: &[u8]) {
12501-
if bytes.is_empty() || std::env::var("SECURE_EXEC_XTRACE").is_err() {
12515+
let Ok(setting) = std::env::var("SECURE_EXEC_XTRACE") else {
12516+
return;
12517+
};
12518+
if bytes.is_empty() {
1250212519
return;
1250312520
}
12521+
let cap: usize = setting.parse().ok().filter(|&n| n > 0).unwrap_or(256);
1250412522
let head: String = bytes
1250512523
.iter()
12506-
.take(256)
12524+
.take(cap)
1250712525
.map(|b| format!("{b:02x}"))
1250812526
.collect::<Vec<_>>()
1250912527
.join("");
Lines changed: 113 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,113 @@
1+
#!/usr/bin/env python3
2+
"""Reassemble the FULL X11 client<->server byte streams from an xtrace log and parse them
3+
request-by-request with correct sequence numbers, to find the exact request the server stops
4+
answering. Needs the sidecar xtrace cap large enough that no write is truncated.
5+
6+
Usage: xreassemble.py <logfile> [path-substring]
7+
"""
8+
import sys, re
9+
10+
REQ = {1:"CreateWindow",2:"ChangeWindowAttributes",3:"GetWindowAttributes",8:"MapWindow",
11+
10:"UnmapWindow",12:"ConfigureWindow",14:"GetGeometry",15:"QueryTree",16:"InternAtom",
12+
17:"GetAtomName",18:"ChangeProperty",19:"DeleteProperty",20:"GetProperty",23:"GetSelectionOwner",
13+
38:"QueryPointer",40:"TranslateCoords",43:"GetInputFocus",45:"OpenFont",47:"QueryFont",
14+
48:"QueryTextExtents",53:"CreatePixmap",54:"FreePixmap",55:"CreateGC",56:"ChangeGC",60:"FreeGC",
15+
62:"CopyArea",66:"PolySegment",70:"PolyFillRectangle",72:"PutImage",73:"GetImage",91:"QueryColors",
16+
94:"CreateGlyphCursor",98:"QueryExtension",119:"GetModifierMapping"}
17+
# requests that produce a reply (client will block in xcb_wait_for_reply on these)
18+
HAS_REPLY = {3,14,15,16,17,20,23,38,40,43,47,48,73,91,98,119,55}
19+
20+
def cat(log, direction, sub):
21+
b = bytearray()
22+
for line in log:
23+
m = re.search(r"\[xtrace\] (\S+) (\S+) len=(\d+) ([0-9a-f]*)", line)
24+
if not m or m.group(1) != direction: continue
25+
if sub and sub not in m.group(2): continue
26+
b += bytes.fromhex(m.group(4))
27+
return bytes(b)
28+
29+
def main():
30+
log = open(sys.argv[1], errors="replace").read().splitlines()
31+
sub = sys.argv[2] if len(sys.argv) > 2 else "X0"
32+
cs = cat(log, "C>S", sub); sc = cat(log, "S>C", sub)
33+
# --- skip the client setup request (byte order 'l'/'B') ---
34+
o = 0
35+
if cs[:1] in (b'l', b'B'):
36+
nlen = int.from_bytes(cs[6:8], 'little'); dlen = int.from_bytes(cs[8:10], 'little')
37+
o = 12 + ((nlen+3)//4)*4 + ((dlen+3)//4)*4
38+
# --- parse requests, assigning sequence numbers (server starts replies at seq 1) ---
39+
reqs = [] # (seq, opcode, name, has_reply)
40+
seq = 0
41+
while o + 4 <= len(cs):
42+
op = cs[o]; ln = int.from_bytes(cs[o+2:o+4], 'little')
43+
if ln == 0: # BigRequests: real length in the next u32
44+
if o + 8 > len(cs): break
45+
ln = int.from_bytes(cs[o+4:o+8], 'little')
46+
nbytes = ln * 4
47+
if nbytes < 4: break # desync guard
48+
seq = (seq + 1) & 0xffffffff
49+
reqs.append((seq, op, REQ.get(op, f"op{op}"), op in HAS_REPLY))
50+
o += nbytes
51+
# --- skip the server setup reply, then parse replies/events/errors ---
52+
p = 0
53+
if sc[:1] in (b'\x00', b'\x01', b'\x02'):
54+
rlen = int.from_bytes(sc[6:8], 'little'); p = 8 + rlen*4
55+
got_reply = set(); errors = []
56+
while p + 32 <= len(sc):
57+
t = sc[p]
58+
s = int.from_bytes(sc[p+2:p+4], 'little')
59+
if t == 1:
60+
extra = int.from_bytes(sc[p+4:p+8], 'little'); got_reply.add(s); p += 32 + extra*4
61+
elif t == 0:
62+
errors.append((s, sc[p+1])); p += 32
63+
else:
64+
p += 32
65+
# full request listing with the first resource id (window/drawable/etc.)
66+
if "--list" in sys.argv:
67+
o2 = o0 = 0
68+
# re-walk to grab the resource id (bytes 4-8) of each request
69+
oo = 12
70+
if cs[:1] in (b'l', b'B'):
71+
nlen = int.from_bytes(cs[6:8],'little'); dlen=int.from_bytes(cs[8:10],'little')
72+
oo = 12 + ((nlen+3)//4)*4 + ((dlen+3)//4)*4
73+
sq = 0
74+
print("# full request list (seq op name resource):")
75+
while oo + 4 <= len(cs):
76+
op = cs[oo]; ln = int.from_bytes(cs[oo+2:oo+4],'little')
77+
hdr = oo
78+
if ln == 0:
79+
ln = int.from_bytes(cs[oo+4:oo+8],'little')
80+
nb = ln*4
81+
if nb < 4:
82+
print(f" !! DESYNC at byte {oo}: op={op} ln={ln}"); break
83+
sq += 1
84+
res = int.from_bytes(cs[oo+4:oo+8],'little') if oo+8<=len(cs) else 0
85+
nm = REQ.get(op, f"op{op}")
86+
mark = " <<ERR" if sq in (71,72) else ""
87+
if op in (1,8,53,55,62,70,72,2,18,12) or sq>=120 or mark:
88+
print(f" seq={sq:<4} op={op:<3} {nm:<20} res={res:#010x}{mark}")
89+
oo += nb
90+
return
91+
# --- report: the first reply-expecting request with no reply = the stuck point ---
92+
last_reply = max(got_reply) if got_reply else 0
93+
print(f"# parsed {len(reqs)} requests, {len(got_reply)} replies (last reply seq={last_reply}), {len(errors)} errors")
94+
if errors: print("# ERRORS:", errors[:10])
95+
print("# reply-expecting requests and whether a reply arrived:")
96+
stuck = None
97+
for (sq, op, name, hr) in reqs:
98+
if not hr: continue
99+
ok = sq in got_reply
100+
flag = "" if ok else " <-- NO REPLY"
101+
if not ok and stuck is None and sq > last_reply: stuck = (sq, name)
102+
if sq >= last_reply - 6:
103+
print(f" seq={sq:<5} {name:<18} reply={'yes' if ok else 'NO'}{flag}")
104+
print(f"\n# => first reply-expecting request past the last reply with NO reply: {stuck}")
105+
# show the requests immediately around the stuck point (all, incl. no-reply ones)
106+
if stuck:
107+
print(f"# requests around seq {stuck[0]}:")
108+
for (sq, op, name, hr) in reqs:
109+
if abs(sq - stuck[0]) <= 4:
110+
print(f" seq={sq:<5} op={op:<3} {name}{' (expects reply)' if hr else ''}")
111+
112+
if __name__ == "__main__":
113+
main()

0 commit comments

Comments
 (0)