dvb_ci_runtime/
trace.rs

1//! Human-readable decoding of CI link frames, for diagnosing live-CAM
2//! exchanges (e.g. issue #337).
3//!
4//! [`decode_frame`] turns one raw link frame into a one-line annotation —
5//! TPDU tag → SPDU tag → APDU tag — so a [`RecordingCaDevice`] capture reads
6//! like the byte traces in bug reports without hand-decoding. [`decode_log`]
7//! formats a whole captured exchange.
8//!
9//! [`RecordingCaDevice`]: crate::device::RecordingCaDevice
10
11use crate::device::LinkEvent;
12use dvb_ci::resource::ResourceId;
13use dvb_ci::spdu::tags as spdu_tags;
14use dvb_ci::tag::ApduTag;
15use dvb_ci::tpdu::{SbValue, tags as tpdu_tags};
16
17/// Name of a TPDU tag (Table A.16), or `"T_?"` for an unknown one.
18fn tpdu_name(tag: u8) -> &'static str {
19    match tag {
20        tpdu_tags::SB => "T_SB",
21        tpdu_tags::RCV => "T_RCV",
22        tpdu_tags::CREATE_T_C => "Create_T_C",
23        tpdu_tags::C_T_C_REPLY => "C_T_C_Reply",
24        tpdu_tags::DELETE_T_C => "Delete_T_C",
25        tpdu_tags::D_T_C_REPLY => "D_T_C_Reply",
26        tpdu_tags::REQUEST_T_C => "Request_T_C",
27        tpdu_tags::NEW_T_C => "New_T_C",
28        tpdu_tags::T_C_ERROR => "T_C_Error",
29        tpdu_tags::DATA_LAST => "T_Data_Last",
30        tpdu_tags::DATA_MORE => "T_Data_More",
31        _ => "T_?",
32    }
33}
34
35/// Name of a session SPDU tag (§7), or `"spdu(?)"` for an unknown one.
36fn spdu_name(tag: u8) -> &'static str {
37    match tag {
38        spdu_tags::SESSION_NUMBER => "session_number",
39        spdu_tags::OPEN_SESSION_REQUEST => "open_session_request",
40        spdu_tags::OPEN_SESSION_RESPONSE => "open_session_response",
41        spdu_tags::CREATE_SESSION => "create_session",
42        spdu_tags::CREATE_SESSION_RESPONSE => "create_session_response",
43        spdu_tags::CLOSE_SESSION_REQUEST => "close_session_request",
44        spdu_tags::CLOSE_SESSION_RESPONSE => "close_session_response",
45        _ => "spdu(?)",
46    }
47}
48
49/// Decode the APDU at the start of `apdu` (3-byte tag) into `name (9F80xx)`.
50fn apdu_label(apdu: &[u8]) -> String {
51    match apdu.first_chunk::<3>() {
52        Some(&[a, b, c]) => {
53            let tag = ApduTag::from_bytes(a, b, c);
54            format!("{} ({:02X}{:02X}{:02X})", tag.name(), a, b, c)
55        }
56        None => "apdu(short)".to_string(),
57    }
58}
59
60/// Decode the SPDU payload of a data TPDU into a label, recursing into the APDU
61/// when the SPDU is a `session_number` wrapper.
62fn spdu_label(spdu: &[u8]) -> String {
63    match spdu.first().copied() {
64        Some(spdu_tags::SESSION_NUMBER) if spdu.len() >= 4 => {
65            let nb = u16::from_be_bytes([spdu[2], spdu[3]]);
66            let rest = &spdu[4..];
67            if rest.is_empty() {
68                format!("session {nb}")
69            } else {
70                format!("session {nb} · {}", apdu_label(rest))
71            }
72        }
73        // Session-management SPDUs: surface the resource_id (+ status/nb) so a
74        // live trace shows *which* resource each create/open targets.
75        Some(spdu_tags::OPEN_SESSION_REQUEST) if spdu.len() >= 6 => {
76            let r = ResourceId(u32::from_be_bytes([spdu[2], spdu[3], spdu[4], spdu[5]]));
77            format!("open_session_request {}", r.name())
78        }
79        Some(spdu_tags::CREATE_SESSION) if spdu.len() >= 8 => {
80            let r = ResourceId(u32::from_be_bytes([spdu[2], spdu[3], spdu[4], spdu[5]]));
81            let nb = u16::from_be_bytes([spdu[6], spdu[7]]);
82            format!("create_session {} (nb {nb})", r.name())
83        }
84        Some(t @ (spdu_tags::CREATE_SESSION_RESPONSE | spdu_tags::OPEN_SESSION_RESPONSE))
85            if spdu.len() >= 9 =>
86        {
87            let status = spdu[2];
88            let r = ResourceId(u32::from_be_bytes([spdu[3], spdu[4], spdu[5], spdu[6]]));
89            let nb = u16::from_be_bytes([spdu[7], spdu[8]]);
90            format!("{} {} status={status:#04x} nb={nb}", spdu_name(t), r.name())
91        }
92        Some(t) => spdu_name(t).to_string(),
93        None => "empty".to_string(),
94    }
95}
96
97/// Decode one raw link frame into a one-line annotation.
98///
99/// Handles the leading TPDU, the SPDU it carries (for `T_Data_*`), and the APDU
100/// inside a `session_number` SPDU. Appended `T_SB` data-available bits are noted.
101#[must_use]
102pub fn decode_frame(frame: &[u8]) -> String {
103    let Some(&tag) = frame.first() else {
104        return "empty frame".to_string();
105    };
106    match tag {
107        tpdu_tags::SB => match frame.get(3) {
108            Some(&sb) => format!(
109                "T_SB tcid={} DA={}",
110                frame.get(2).copied().unwrap_or(0),
111                u8::from(SbValue(sb).data_available())
112            ),
113            None => "T_SB (short)".to_string(),
114        },
115        tpdu_tags::CREATE_T_C
116        | tpdu_tags::C_T_C_REPLY
117        | tpdu_tags::DELETE_T_C
118        | tpdu_tags::D_T_C_REPLY
119        | tpdu_tags::REQUEST_T_C
120        | tpdu_tags::NEW_T_C
121        | tpdu_tags::RCV
122        | tpdu_tags::T_C_ERROR => {
123            format!(
124                "{} tcid={}",
125                tpdu_name(tag),
126                frame.get(2).copied().unwrap_or(0)
127            )
128        }
129        tpdu_tags::DATA_LAST | tpdu_tags::DATA_MORE => {
130            // tag · length_field · t_c_id · data(=SPDU) · [appended T_SB].
131            // length_field uses the Table-1 codec (long-form for >127 bytes), so
132            // decode it rather than assuming a single byte.
133            let Ok((len, hdr)) = dvb_ci::length::decode(&frame[1..]) else {
134                return format!("{} (bad length_field)", tpdu_name(tag));
135            };
136            let start = 1 + hdr; // t_c_id offset
137            let tcid = frame.get(start).copied().unwrap_or(0);
138            // `length` counts t_c_id + data; the SPDU is the data after t_c_id.
139            let data_end = (start + len).min(frame.len());
140            let spdu = frame.get(start + 1..data_end).unwrap_or(&[]);
141            if spdu.is_empty() {
142                format!("{} tcid={} (poll)", tpdu_name(tag), tcid)
143            } else {
144                format!("{} tcid={} · {}", tpdu_name(tag), tcid, spdu_label(spdu))
145            }
146        }
147        _ => format!("{} {:02X?}", tpdu_name(tag), &frame[..frame.len().min(8)]),
148    }
149}
150
151/// Format a whole captured exchange as a multi-line annotated trace.
152#[must_use]
153pub fn decode_log(log: &[LinkEvent]) -> String {
154    let mut out = String::new();
155    for ev in log {
156        let line = match ev {
157            LinkEvent::Tx(f) => format!("W {}", decode_frame(f)),
158            LinkEvent::Rx(f) => format!("R {}", decode_frame(f)),
159            LinkEvent::Reset => "  reset()".to_string(),
160            LinkEvent::SlotInfo(si) => format!(
161                "  slot_info() -> present={} ready={}",
162                si.module_present, si.module_ready
163            ),
164        };
165        out.push_str(&line);
166        out.push('\n');
167    }
168    out
169}
170
171#[cfg(test)]
172mod tests {
173    use super::*;
174
175    #[test]
176    fn names_every_connection_management_tpdu() {
177        // Table A.16: Delete/Request/New T_C used to fall through to "T_?".
178        assert_eq!(decode_frame(&[0x84, 0x01, 0x01]), "Delete_T_C tcid=1");
179        assert_eq!(decode_frame(&[0x85, 0x01, 0x01]), "D_T_C_Reply tcid=1");
180        assert_eq!(decode_frame(&[0x86, 0x01, 0x01]), "Request_T_C tcid=1");
181    }
182
183    #[test]
184    fn decodes_the_337_handshake_frames() {
185        // Bytes lifted from issue #337's trace.
186        assert_eq!(decode_frame(&[0x82, 0x01, 0x01]), "Create_T_C tcid=1");
187        assert_eq!(decode_frame(&[0x81, 0x01, 0x01]), "T_RCV tcid=1");
188        assert_eq!(decode_frame(&[0x80, 0x02, 0x01, 0x00]), "T_SB tcid=1 DA=0");
189
190        // open_session_request (module): a0 07 01 | 91 04 00 01 00 41 | SB
191        let osr = [
192            0xA0, 0x07, 0x01, 0x91, 0x04, 0x00, 0x01, 0x00, 0x41, 0x80, 0x02, 0x01, 0x00,
193        ];
194        assert_eq!(
195            decode_frame(&osr),
196            "T_Data_Last tcid=1 · open_session_request resource_manager"
197        );
198
199        // profile_enq (host): a0 09 01 | 90 02 00 01 | 9f 80 10 00
200        let enq = [
201            0xA0, 0x09, 0x01, 0x90, 0x02, 0x00, 0x01, 0x9F, 0x80, 0x10, 0x00,
202        ];
203        assert_eq!(
204            decode_frame(&enq),
205            "T_Data_Last tcid=1 · session 1 · profile_enq (9F8010)"
206        );
207    }
208
209    #[test]
210    fn decodes_long_form_length_profile_reply() {
211        // The module's profile_reply, captured raw on hardware (#337): the
212        // length_field is long-form `82 00 09`. A short-form decoder mis-reads
213        // tcid as 0x00 and garbles the SPDU.
214        let f = [
215            0xA0, 0x82, 0x00, 0x09, 0x01, 0x90, 0x02, 0x00, 0x01, 0x9F, 0x80, 0x11, 0x00, 0x80,
216            0x02, 0x01, 0x00,
217        ];
218        assert_eq!(
219            decode_frame(&f),
220            "T_Data_Last tcid=1 · session 1 · profile (9F8011)"
221        );
222    }
223
224    #[test]
225    fn decodes_log_directions() {
226        let log = [
227            LinkEvent::Reset,
228            LinkEvent::Tx(vec![0x82, 0x01, 0x01]),
229            LinkEvent::Rx(vec![0x80, 0x02, 0x01, 0x00]),
230        ];
231        let s = decode_log(&log);
232        assert!(s.contains("  reset()"));
233        assert!(s.contains("W Create_T_C tcid=1"));
234        assert!(s.contains("R T_SB tcid=1 DA=0"));
235    }
236}
dvb_ci_runtime/trace.rs

dvb_ci_runtime/
trace.rs
