fix(marmot-interop): diagnose B->Amethyst kind:445 drops in Test 02
When `wn_b messages send` fires but Amethyst never displays the reply,
the harness used to swallow the send output and only ask the operator a
blind yes/no — giving no signal about which side of the pipe failed.
Amethyst subscribes to kind:445 on the MLS GroupContext `relays`
extension (falling back to `Account.homeRelays`), so the two
actionable failure modes are:
- wn published to a relay Amethyst isn't subscribed to (group-relay
mismatch between the MLS extension and Amethyst's subscription)
- Amethyst received the event but `GroupEventHandler.add` dropped it
(no `h` tag, `isMember=false`, decrypt error)
Teach the harness to dump both sides automatically on the reply step:
- Capture wn's `messages send` stdout/stderr into the run log.
- `dump_outbound_diagnostics` prints wn's local view of the group
messages (did the send persist to wn's own DB?), the MLS
GroupContext relay list (what Amethyst should be subscribed to),
and live relay connection status.
- On operator-reported fail, prompt for an Amethyst-side logcat
grep targeted at the exact log points — MarmotGroupEventsEoseManager
filter updates, GroupEventHandler.add arrivals, and the membership
drop branch — naming the current group id so the operator can grep
for the right hex prefix.
This commit is contained in:
Claude
@@ -471,6 +471,70 @@ Then paste /tmp/amethyst-marmot.log contents here so the failure report has
|
||||
both the Amethyst-side publish log and the wn-side subscription log ($note)."
|
||||
}
|
||||
|
||||
# Dump everything we know about an outbound kind:445 from a wn daemon, so
|
||||
# when the operator reports "Amethyst didn't see it" we can tell them which
|
||||
# side of the wire to investigate:
|
||||
#
|
||||
# - `messages list` output (did the daemon persist the message locally,
|
||||
# i.e. is this a relay-reach issue, a membership issue, or a pure
|
||||
# Amethyst-receive issue?)
|
||||
# - `groups show` metadata (which MLS-extension relays is wn using for
|
||||
# this group — these are the SAME relays Amethyst subscribes to, so if
|
||||
# the lists don't match that's the bug)
|
||||
# - live relay connection status
|
||||
#
|
||||
# Output is tee'd to stderr (live) and $LOG_FILE (forward).
|
||||
dump_outbound_diagnostics() {
|
||||
local who="$1" gid="$2" needle="${3:-}" tag="${4:-post-send}"
|
||||
local wnfn
|
||||
if [[ "$who" == "B" ]]; then wnfn=wn_b
|
||||
else wnfn=wn_c; fi
|
||||
|
||||
printf '\n%s%s---- [%s] %s outbound diagnostics (group %.8s…) ----%s\n' \
|
||||
"$C_BOLD" "$C_CYAN" "$tag" "$who" "$gid" "$C_RESET" >&2
|
||||
printf '\n==== [%s] %s outbound diagnostics (group %s) ====\n' "$tag" "$who" "$gid" >>"$LOG_FILE"
|
||||
|
||||
step "$who local view of latest messages in group"
|
||||
local list_raw
|
||||
list_raw=$("$wnfn" --json messages list "$gid" --limit 5 2>/dev/null || true)
|
||||
printf ' %s\n' "${list_raw:-<no output>}" >>"$LOG_FILE"
|
||||
printf '%s' "$list_raw" \
|
||||
| jq -r '(.result // .) | .[]? | " \(.id // .event_id // "?") \((.content // .text // "") | tostring | .[0:80])"' 2>/dev/null \
|
||||
| tee -a "$LOG_FILE" >&2 || true
|
||||
if [[ -n "$needle" ]]; then
|
||||
if printf '%s' "$list_raw" | jq -e --arg n "$needle" \
|
||||
'(.result // .) | .[]? | select((.content // .text // "") | contains($n))' \
|
||||
>/dev/null 2>&1; then
|
||||
info "$who local store contains \"$needle\" — send reached wn's own DB (kind:445 went out)"
|
||||
else
|
||||
warn "$who local store does NOT contain \"$needle\" — `messages send` never persisted; check stderr.log"
|
||||
fi
|
||||
fi
|
||||
|
||||
step "$who MLS group metadata (relays here are what Amethyst subscribes on)"
|
||||
local meta_raw
|
||||
meta_raw=$("$wnfn" --json groups show "$gid" 2>/dev/null || true)
|
||||
printf ' %s\n' "${meta_raw:-<no output>}" >>"$LOG_FILE"
|
||||
local meta_relays
|
||||
meta_relays=$(printf '%s' "$meta_raw" \
|
||||
| jq -r '(.result // .) | (.relays // .group.relays // [])[]? | (. | tostring)' 2>/dev/null \
|
||||
| paste -sd',' -)
|
||||
info " group relays (MLS extension): ${meta_relays:-<none — Amethyst will fall back to homeRelays>}"
|
||||
local meta_name meta_epoch
|
||||
meta_name=$(printf '%s' "$meta_raw" | jq -r '(.result // .) | (.name // .group.name // "?")' 2>/dev/null)
|
||||
meta_epoch=$(printf '%s' "$meta_raw" | jq -r '(.result // .) | (.epoch // .group.epoch // "?")' 2>/dev/null)
|
||||
info " group name: $meta_name epoch: $meta_epoch"
|
||||
|
||||
step "$who relay connection status right now"
|
||||
"$wnfn" --json relays list 2>/dev/null \
|
||||
| jq -r '(.result // .)[]? | " \(.url // .relay.url // "?") [\(.type // "?")] [\(.status // .connection_status // "?")]"' 2>/dev/null \
|
||||
| tee -a "$LOG_FILE" >&2 || true
|
||||
|
||||
printf '%s%s---- end outbound diagnostics ----%s\n\n' \
|
||||
"$C_BOLD" "$C_CYAN" "$C_RESET" >&2
|
||||
printf '==== end [%s] %s outbound diagnostics ====\n\n' "$tag" "$who" >>"$LOG_FILE"
|
||||
}
|
||||
|
||||
# ------- group cleanup -------------------------------------------------------
|
||||
cleanup_group() {
|
||||
local gid="$1" who="${2:-B}"
|
||||
|
||||
@@ -473,11 +473,41 @@ that's the bug."
|
||||
fi
|
||||
|
||||
step "B sends reply"
|
||||
wn_b messages send "$gid" "hello from wn" >/dev/null 2>&1 || warn "send returned nonzero"
|
||||
local send_out
|
||||
if ! send_out=$(wn_b messages send "$gid" "hello from wn" 2>&1); then
|
||||
warn "wn messages send returned nonzero: $send_out"
|
||||
fi
|
||||
printf 'wn messages send (test_02 reply) raw: %s\n' "$send_out" >>"$LOG_FILE"
|
||||
# Give the relay a couple seconds to fan the commit/message back out to
|
||||
# Amethyst's subscription before we ask the operator to eyeball the UI.
|
||||
sleep 4
|
||||
|
||||
# Dump the B side up front — if B's own store doesn't contain the reply
|
||||
# or the MLS extension relays don't match what Amethyst subscribes to,
|
||||
# the operator can confirm "fail" with a specific reason instead of a
|
||||
# blind eyeball check.
|
||||
dump_outbound_diagnostics B "$gid" "hello from wn" "test_02 B->A reply"
|
||||
|
||||
if confirm "Does Amethyst now show 'hello from wn' in the same group?"; then
|
||||
record_result "02 Amethyst->B create+invite" pass
|
||||
else
|
||||
# The B-side dump above told us whether the send reached B's own DB and
|
||||
# which relays wn tagged on the kind:445. Now pull the Amethyst side so
|
||||
# the failure report has both halves of the pipe: which relays the
|
||||
# kind:445 subscription actually targets, whether the event arrived,
|
||||
# and (if it did) whether GroupEventHandler dropped it.
|
||||
prompt_human "Capture Amethyst's side of the B->A kind:445 path. On the adb host:
|
||||
|
||||
adb logcat -d -v time | grep -E \
|
||||
'MarmotDbg|GroupEventHandler|MarmotGroupEventsEoseManager|kind:445' \\
|
||||
| tail -n 200 > /tmp/amethyst-marmot.log
|
||||
|
||||
Then paste /tmp/amethyst-marmot.log here. Key lines to look for:
|
||||
- 'MarmotGroupEventsEoseManager.updateFilter: group=${gid:0:8}…' + the relay
|
||||
list — must match the 'group relays (MLS extension)' in the B-side dump.
|
||||
- 'GroupEventHandler.add: kind:445 id=… groupId=${gid:0:8}…' (event arrived).
|
||||
- 'GroupEventHandler.add: not a member of group=${gid:0:8}…' (dropped).
|
||||
- 'GroupEventHandler.add: processGroupEvent returned ApplicationMessage…' (decrypted)."
|
||||
record_result "02 Amethyst->B create+invite" fail "Amethyst did not display reply"
|
||||
fi
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user