Fix fixed user event handling

auxoncorp · Jul 12, 2024 · 8e88a6a · 8e88a6a
1 parent 60ba20d
commit 8e88a6a
Show file tree

Hide file tree

Showing 7 changed files with 105 additions and 20 deletions.
diff --git a/Cargo.toml b/Cargo.toml
@@ -1,6 +1,6 @@
 [package]
 name = "trace-recorder-parser"
-version = "0.16.0"
+version = "0.16.1"
 edition = "2021"
 authors = ["Jon Lamb <[email protected]>"]
 description = "A Rust library to parse Percepio's TraceRecorder data"

diff --git a/src/streaming/error.rs b/src/streaming/error.rs
@@ -36,6 +36,9 @@ pub enum Error {
     #[error("Found an event with object handle {0} that doesn't exist in the entry table")]
     ObjectLookup(ObjectHandle),
 
+    #[error("Found a fixed user event with format string handle {0} that doesn't exist in the entry table")]
+    FixedUserEventFmtStringLookup(ObjectHandle),
+
     #[error("Found an event ({0}) with an invalid zero value object handle")]
     InvalidObjectHandle(EventId),
 

diff --git a/src/streaming/event/mod.rs b/src/streaming/event/mod.rs
@@ -41,6 +41,8 @@ pub mod ts_config;
 pub mod unused_stack;
 pub mod user;
 
+pub(crate) const FIXED_USER_EVENT_ID: u16 = 0x98;
+
 #[derive(
     Copy,
     Clone,
@@ -381,6 +383,8 @@ pub enum EventType {
     // Note that user event code range is 0x90..=0x9F
     // Allow for 0-15 arguments (the arg count == word count, always 32 bits) is added to event code
     // num_args = EventCode - 0x90
+    //
+    // This also supports fixed user events (PSF_EVENT_USER_EVENT_FIXED, 0x98..=0x9F)
     #[display(fmt = "USER_EVENT")]
     UserEvent(UserEventArgRecordCount),
 

diff --git a/src/streaming/event/parser.rs b/src/streaming/event/parser.rs
@@ -779,7 +779,7 @@ impl EventParser {
                 Some((event_code, Event::UnusedStack(event)))
             }
 
-            EventType::UserEvent(arg_count) => {
+            EventType::UserEvent(raw_arg_count) => {
                 // Always expect at least a channel
                 if num_params.0 < 1 {
                     return Err(Error::InvalidEventParameterCount(
@@ -788,6 +788,19 @@ impl EventParser {
                         num_params,
                     ));
                 }
+
+                // Account for fixed user events when can occupy part of the user event ID space
+                let (is_fixed, arg_count) = if event_id.0 >= FIXED_USER_EVENT_ID
+                    && usize::from(raw_arg_count) >= usize::from(num_params)
+                {
+                    (
+                        true,
+                        UserEventArgRecordCount((event_id.0 - FIXED_USER_EVENT_ID) as u8),
+                    )
+                } else {
+                    (false, raw_arg_count)
+                };
+
                 if usize::from(arg_count) >= usize::from(num_params) {
                     return Err(Error::InvalidEventParameterCount(
                         event_code.event_id(),
@@ -803,21 +816,39 @@ impl EventParser {
                     .map(|sym| UserEventChannel::Custom(sym.clone().into()))
                     .unwrap_or(UserEventChannel::Default);
 
-                // arg_count includes the format string, we want the args, if any
-                let not_fmt_str_arg_count = if arg_count.0 != 0 {
-                    usize::from(arg_count) - 1
-                } else {
-                    0
-                };
-                let num_arg_bytes = not_fmt_str_arg_count * 4;
                 self.arg_buf.clear();
-                if num_arg_bytes != 0 {
-                    self.arg_buf.resize(num_arg_bytes, 0);
-                    r.read_exact(&mut self.arg_buf)?;
-                }
 
-                let num_fmt_str_bytes = (usize::from(num_params) - 1 - not_fmt_str_arg_count) * 4;
-                let format_string = self.read_string(&mut r, num_fmt_str_bytes)?;
+                let format_string = if is_fixed {
+                    let fmt_string_handle = object_handle(&mut r, event_id)?;
+                    let format_string = entry_table
+                        .symbol(fmt_string_handle)
+                        .map(|s| TrimmedString(s.to_string()))
+                        .ok_or(Error::FixedUserEventFmtStringLookup(fmt_string_handle))?;
+
+                    let num_arg_bytes = usize::from(arg_count.0) * 4;
+                    if num_arg_bytes != 0 {
+                        self.arg_buf.resize(num_arg_bytes, 0);
+                        r.read_exact(&mut self.arg_buf)?;
+                    }
+
+                    format_string
+                } else {
+                    // arg_count includes the format string, we want the args, if any
+                    let not_fmt_str_arg_count = if arg_count.0 != 0 {
+                        usize::from(arg_count) - 1
+                    } else {
+                        0
+                    };
+                    let num_arg_bytes = not_fmt_str_arg_count * 4;
+                    if num_arg_bytes != 0 {
+                        self.arg_buf.resize(num_arg_bytes, 0);
+                        r.read_exact(&mut self.arg_buf)?;
+                    }
+
+                    let num_fmt_str_bytes =
+                        (usize::from(num_params) - 1 - not_fmt_str_arg_count) * 4;
+                    self.read_string(&mut r, num_fmt_str_bytes)?
+                };
 
                 let (formatted_string, args) = match format_symbol_string(
                     entry_table,

diff --git a/test_resources/fixtures/streaming/v14/trace.psf b/test_resources/fixtures/streaming/v14/trace.psf
diff --git a/test_resources/src/streaming/v14/main.c b/test_resources/src/streaming/v14/main.c
@@ -280,6 +280,32 @@ int main(int argc, char **argv)
     prvTraceStoreEvent_HandleParam(PSF_EVENT_SEMAPHORE_TAKE_FROMISR, cs, 0);
 
     assert(xTracePrintF(ch, "int %d, unsigned %u", -2, 32) == TRC_SUCCESS);
+    // Exceed the PSF_EVENT_USER_EVENT_FIXED id
+    assert(xTracePrintF(ch, "%u %u %u %u %u %u %u %u %u", 1, 2, 3, 4, 5, 6, 7, 8, 9) == TRC_SUCCESS);
+
+    TraceStringHandle_t ch1;
+    assert(xTraceStringRegister("ch1", &ch1) == TRC_SUCCESS);
+
+    TraceStringHandle_t fmt0;
+    assert(xTraceStringRegister("no args", &fmt0) == TRC_SUCCESS);
+    assert(xTracePrintF0(ch1, fmt0) == TRC_SUCCESS);
+
+    TraceStringHandle_t fmt1;
+    assert(xTraceStringRegister("1 arg: %u", &fmt1) == TRC_SUCCESS);
+    assert(xTracePrintF1(ch1, fmt1, 0) == TRC_SUCCESS);
+
+    TraceStringHandle_t fmt2;
+    assert(xTraceStringRegister("2 args: %u %u", &fmt2) == TRC_SUCCESS);
+    assert(xTracePrintF2(ch1, fmt2, 1, 2) == TRC_SUCCESS);
+
+    TraceStringHandle_t fmt3;
+    assert(xTraceStringRegister("3 args: %u %u %u", &fmt3) == TRC_SUCCESS);
+    assert(xTracePrintF3(ch1, fmt3, 1, 2, 3) == TRC_SUCCESS);
+
+    TraceStringHandle_t fmt4;
+    assert(xTraceStringRegister("4 args: %u %u %u %u", &fmt4) == TRC_SUCCESS);
+    assert(xTracePrintF4(ch1, fmt4, 1, 2, 3, 4) == TRC_SUCCESS);
+
     vTaskDelay(pdMS_TO_TICKS(25));
 
     prvTraceStoreEvent_HandleParamParam(PSF_EVENT_QUEUE_RECEIVE_BLOCK, q, pdMS_TO_TICKS(100), 0);

diff --git a/tests/streaming.rs b/tests/streaming.rs
@@ -46,6 +46,7 @@ fn streaming_v10_smoke() {
         initial_event_count: 1,
         latest_timestamp: Timestamp::zero(),
         high_water_mark: 0,
+        extra_user_events: false,
     });
 }
 
@@ -59,6 +60,7 @@ fn streaming_v12_smoke() {
         initial_event_count: 6,
         latest_timestamp: Timestamp::zero(),
         high_water_mark: 0,
+        extra_user_events: false,
     });
 }
 
@@ -72,6 +74,7 @@ fn streaming_v13_smoke() {
         initial_event_count: 6,
         latest_timestamp: Timestamp::zero(),
         high_water_mark: 0,
+        extra_user_events: false,
     });
 }
 
@@ -85,6 +88,7 @@ fn streaming_v14_smoke() {
         initial_event_count: 6,
         latest_timestamp: Timestamp::zero(),
         high_water_mark: 0,
+        extra_user_events: true,
     });
 }
 
@@ -105,27 +109,29 @@ fn streaming_v14_garbage_with_trace_restart() {
         initial_event_count: 6,
         latest_timestamp: Timestamp::zero(),
         high_water_mark: 0,
+        extra_user_events: true,
     };
     let mut reader = data.as_slice();
 
     let mut rd0 = RecorderData::find(&mut reader).unwrap();
     check_recorder_data(&rd0, &cfg0);
 
-    for _ in 0..52 {
+    for _ in 0..66 {
         let _ = rd0.read_event(&mut reader).unwrap().unwrap();
     }
     let next_psf_word = match rd0.read_event(&mut reader) {
         Err(Error::TraceRestarted(endianness)) => endianness,
-        _ => panic!("Expected TraceRestarted error"),
+        res => panic!("Expected TraceRestarted error. {res:?}"),
     };
 
     let cfg1 = CommonTestConfig {
         trace_path: TRACE_V14,
         expected_trace_format_version: 14,
         expected_platform_cfg_version_minor: 2,
         initial_event_count: 6,
-        latest_timestamp: Timestamp::from(Ticks::new(51)),
+        latest_timestamp: Timestamp::from(Ticks::new(65)),
         high_water_mark: 4,
+        extra_user_events: true,
     };
     let rd1 = RecorderData::read_with_endianness(next_psf_word, &mut reader).unwrap();
     check_recorder_data(&rd1, &cfg1);
@@ -135,8 +141,8 @@ fn streaming_v14_garbage_with_trace_restart() {
         let mut trd = TestRecorderData {
             rd: rd1,
             f: reader,
-            event_cnt: 70,
-            timestamp_ticks: 52,
+            event_cnt: 91,
+            timestamp_ticks: 66,
         };
         trd.check_event(TraceStart);
     }
@@ -149,6 +155,7 @@ struct CommonTestConfig {
     initial_event_count: u16,
     latest_timestamp: Timestamp,
     high_water_mark: u32,
+    extra_user_events: bool,
 }
 
 fn check_recorder_data(rd: &RecorderData, cfg: &CommonTestConfig) {
@@ -276,6 +283,20 @@ fn common_tests(cfg: CommonTestConfig) {
         trd.check_event(SemaphoreTakeFromIsr);
         trd.check_event(SemaphoreTakeFromIsr);
         trd.check_event(UserEvent(3.into()));
+        if cfg.extra_user_events {
+            trd.check_event(UserEvent(10.into()));
+            trd.check_event(ObjectName);
+            trd.check_event(ObjectName);
+            trd.check_event(UserEvent(8.into()));
+            trd.check_event(ObjectName);
+            trd.check_event(UserEvent(9.into()));
+            trd.check_event(ObjectName);
+            trd.check_event(UserEvent(10.into()));
+            trd.check_event(ObjectName);
+            trd.check_event(UserEvent(11.into()));
+            trd.check_event(ObjectName);
+            trd.check_event(UserEvent(12.into()));
+        }
         trd.check_event(TaskDelay);
         trd.check_event(QueueReceiveBlock);
         trd.check_event(UnusedStack);