[M5] mxaccess-asb: MX_ASB_TRACE_REPLY trace + F30/F31 followups
Adds env-gated diagnostic trace `MX_ASB_TRACE_REPLY` that, on every incoming SizedEnvelope, prints the raw reply bytes + decoded body tokens (capped at 64) before any consumer-level decode runs. Used to isolate the next blocker after F28's wire-format fixes landed: with canonical XML signing, registry-driven DH params, dynamic-dict id management, ConnectionValidator wire-format-per-action, chunked ASBIData decode, and 0x0A `ShortDictionaryXmlnsAttribute` all in place, AuthenticateMe is accepted by the server and a real RegisterItemsResponse comes back — but it decodes to an opaque token stream of `<b:Static(43)>false</b:Static(43)>` etc. because every field name is dict-encoded against the response's own binary header pre-pop and we never resolve those ids on the read side. Two new follow-ups capture the remaining work: - **F30**: resolve dict-id element/attribute names on the read side. Mirror the F28 write-side fix: read-side dynamic dict accumulates session strings via `intern`, and `decode_tokens` (or a post-pass) needs to substitute `NbfxName::Static(id)` with the resolved `NbfxName::Inline(name)` so downstream `find_element_named` / `collect_asbidata_payloads` match. - **F31**: server response indicates `successField=false` with an empty Status array on Register. Hypotheses (in order): (a) silent HMAC mismatch despite F23 deterministic parity; (b) request-side wire-byte delta the server tolerates but interprets as 0 items; (c) tag does not resolve in the live Galaxy state. Resolution needs F30 first to read the actual Status array + error codes. Workspace: 710 unit tests pass. Clippy clean. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
@@ -134,6 +134,20 @@ move to `## Resolved` with a date + commit hash.
|
||||
|
||||
F25 (`mxaccess-asb` IASBIDataV2 client) and F26 (`mxaccess::Session` over `AsbTransport`) remain open. With F19-F24 landed, the M5 framing/encoder layer (streams A+B+C+D and the codec stream) is complete; F25 composes them into the `IASBIDataV2` wire client. F22's static dictionary subset is intentionally curated; expand entries as wire captures show new IDs. F27 (constant-time DH) is filed as a separate follow-up below.
|
||||
|
||||
### F30 — Resolve dict-id element/attribute names on the read side
|
||||
**Severity:** P1 — blocks decoding any non-trivial WCF response.
|
||||
**Source:** Live Register response decode (`MX_ASB_TRACE_REPLY` dump in `client.rs:172-190`).
|
||||
**Why deferred:** When the server returns a response with the `RegisterItemsResponse` wrapper + `Result` fields, every element name (and most attribute names) is dict-encoded — `<b:Static(43)>false</b:Static(43)>` is `successField=false` on the wire. Our `decode_tokens` produces `NbfxName::Static(id)` tokens without resolving them; downstream consumers (`collect_asbidata_payloads`, `find_element_named`, `decode_register_items_response`) only match against `NbfxName::Inline(local)` and miss every dict-named element. The fault detection works because the SOAP fault Action header contains `/fault` (a literal string), but real success-response decoding is blind.
|
||||
|
||||
**Resolves when:** `decode_tokens` (or a post-pass over the token stream) substitutes `NbfxName::Static(id)` with `NbfxName::Inline(name)` whenever the dict id resolves to a known string. The dynamic dict (`read_dictionary`) accumulates session strings via `intern`; the read-path needs the parallel session counter to map wire ids to slots — wire ids are odd and session-cumulative across messages, mirroring the F28 fix on the write side. **Resolves**: F25 live data path (Read/Write/Subscribe responses are all dict-encoded too).
|
||||
|
||||
### F31 — Wire-byte server response says `successField = false` for AuthenticateMe-then-Register
|
||||
**Severity:** P1 — visible failure mode.
|
||||
**Source:** `relay-rust-decode.log` + `MX_ASB_TRACE_REPLY` dump.
|
||||
**Why deferred:** With every wire-format fix from F28 landed (canonical XML signing, registry-driven DH params, dynamic-dict id management, ConnectionValidator wire-format-per-action, chunked ASBIData decode, `0x0A ShortDictionaryXmlnsAttribute` decode), `AuthenticateMe` is accepted by the server and a real `RegisterItemsResponse` returns. The response body decodes structurally but the visible `<b:Static(43)>false</b:Static(43)>` element matches the `successField` slot in the response binary header pre-pop, so Register returned success=false with empty Status array. Hypothesis (highest-likelihood first): (a) `AuthenticateMe` reaches the server but its HMAC is silently invalid → server treats subsequent requests as unauthenticated → register returns "no items processed"; (b) wire-byte difference between our Register and .NET's that the server still accepts but interprets as a 0-item registration; (c) tag `TestChildObject.TestInt` doesn't resolve in the live Galaxy state during this run.
|
||||
|
||||
**Resolves when:** F30 lands (so we can read the actual Status array + error codes from the response), AND we confirm against a side-by-side .NET probe wire diff which interpretation applies. If (a), AuthenticateMe HMAC needs further investigation despite the deterministic-HMAC fixture parity (commit `ce27b63`) — a session-state mismatch between client+server view of next-message-number could explain it. If (b), expect a structural delta in the request bytes the server tolerates but interprets differently. If (c), pick a different known-resolvable tag.
|
||||
|
||||
### F28 — Canonical XML serialiser for `ConnectedRequest` signing (matches `XmlSerializer.Serialize` byte-for-byte)
|
||||
**Severity:** P0 — blocks every signed ASB operation (AuthenticateMe, RegisterItems, all data-plane RPCs).
|
||||
**Source:** F25 live-bring-up; `AsbSystemAuthenticator.cs:79` + `AsbSerialization.cs:12-48`.
|
||||
|
||||
@@ -170,7 +170,18 @@ impl<T: AsyncRead + AsyncWrite + Unpin + Send> AsbClient<T> {
|
||||
let record = read_record(&mut self.stream).await?;
|
||||
match record {
|
||||
NmfRecord::SizedEnvelope(reply_bytes) => {
|
||||
let trace_reply = std::env::var("MX_ASB_TRACE_REPLY").ok().is_some();
|
||||
if trace_reply {
|
||||
eprintln!("asb.reply.bytes_len={}", reply_bytes.len());
|
||||
eprintln!("asb.reply.bytes_hex={}", hex_dump(&reply_bytes));
|
||||
}
|
||||
let decoded = decode_envelope(&reply_bytes, &mut self.read_dictionary)?;
|
||||
if trace_reply {
|
||||
eprintln!("asb.reply.body_tokens.len={}", decoded.body_tokens.len());
|
||||
for (i, tok) in decoded.body_tokens.iter().enumerate().take(64) {
|
||||
eprintln!("asb.reply.body[{i}]={tok:?}");
|
||||
}
|
||||
}
|
||||
if let Some(fault) = detect_soap_fault(&decoded) {
|
||||
return Err(fault);
|
||||
}
|
||||
@@ -737,6 +748,14 @@ fn detect_soap_fault(decoded: &crate::DecodedEnvelope) -> Option<ClientError> {
|
||||
})
|
||||
}
|
||||
|
||||
/// Hex dump for diagnostic traces. First 256 bytes only to keep
|
||||
/// MX_ASB_TRACE_REPLY output bounded.
|
||||
fn hex_dump(bytes: &[u8]) -> String {
|
||||
let cap = bytes.len().min(256);
|
||||
let slice = bytes.get(..cap).unwrap_or(&[]);
|
||||
slice.iter().map(|b| format!("{b:02x}")).collect()
|
||||
}
|
||||
|
||||
// ---- error type ----------------------------------------------------------
|
||||
|
||||
#[derive(Debug, thiserror::Error)]
|
||||
|
||||
Reference in New Issue
Block a user