From 1c07ea3da583653e3e211d3029f1f94377109a92 Mon Sep 17 00:00:00 2001 From: Ingmar Splitt Date: Fri, 18 Oct 2024 19:23:43 +0200 Subject: [PATCH] fix util for pru0, add tsample pru1, fix message-test, fix sync, fix CS-Spacing --- software/firmware/include/commons.h | 2 +- software/firmware/lib/src/msg_sys.c | 18 +++-- software/firmware/pru0-shepherd-fw/main.c | 14 ++-- software/firmware/pru1-shepherd-fw/main.c | 77 +++++++++++-------- software/kernel-module/src/module_base.c | 46 +++++++---- software/kernel-module/src/pru_msg_sys.c | 7 +- software/kernel-module/src/pru_sync_control.c | 7 +- software/kernel-module/src/sysfs_interface.c | 1 + .../shepherd_sheep/h5_recorder_pru.py | 16 ++-- .../shepherd_sheep/shared_memory.py | 60 +++++++-------- 10 files changed, 145 insertions(+), 103 deletions(-) diff --git a/software/firmware/include/commons.h b/software/firmware/include/commons.h index 6e46a453..4bd08763 100644 --- a/software/firmware/include/commons.h +++ b/software/firmware/include/commons.h @@ -147,7 +147,7 @@ struct UtilTrace uint32_t pru0_tsample_ns_max[BUFFER_UTIL_SIZE]; uint32_t pru0_tsample_ns_sum[BUFFER_UTIL_SIZE]; uint32_t pru0_sample_count[BUFFER_UTIL_SIZE]; - uint32_t pru1_tsample_max[BUFFER_UTIL_SIZE]; + uint32_t pru1_tsample_ns_max[BUFFER_UTIL_SIZE]; /* safety */ uint32_t canary; } __attribute__((packed)); diff --git a/software/firmware/lib/src/msg_sys.c b/software/firmware/lib/src/msg_sys.c index 1cedf6bd..1f52eec9 100644 --- a/software/firmware/lib/src/msg_sys.c +++ b/software/firmware/lib/src/msg_sys.c @@ -31,15 +31,19 @@ void msgsys_init() { - MSG_INBOX.unread = 0u; + MSG_INBOX.unread = 0u; - MSG_OUTBOX.unread = 0u; - MSG_OUTBOX.id = MSG_TO_KERNEL; - MSG_OUTBOX.canary = CANARY_VALUE_U32; + MSG_OUTBOX.unread = 0u; + MSG_OUTBOX.type = 0u; + MSG_OUTBOX.value[0] = 0u; + MSG_OUTBOX.id = MSG_TO_KERNEL; + MSG_OUTBOX.canary = CANARY_VALUE_U32; - MSG_ERROR.unread = 0u; - MSG_ERROR.id = MSG_TO_KERNEL; - MSG_ERROR.canary = CANARY_VALUE_U32; + MSG_ERROR.unread = 0u; + MSG_ERROR.type = 0u; + MSG_ERROR.value[0] = 0u; + MSG_ERROR.id = MSG_TO_KERNEL; + MSG_ERROR.canary = CANARY_VALUE_U32; } // alternative message channel specially dedicated for errors diff --git a/software/firmware/pru0-shepherd-fw/main.c b/software/firmware/pru0-shepherd-fw/main.c index 4b4b162f..19434305 100644 --- a/software/firmware/pru0-shepherd-fw/main.c +++ b/software/firmware/pru0-shepherd-fw/main.c @@ -226,14 +226,15 @@ void event_loop() if (iep_tmr_cmp_sts & IEP_CMP0_MASK) // LogicAnalyzer: 204 ns { // TODO: move back to PRU1 - not needed here anymore? - /* Clear Timer Compare 0 and forward it to pru1 */ GPIO_TOGGLE(DEBUG_PIN0_MASK); - SHARED_MEM.cmp0_trigger_for_pru1 = 1u; - iep_clear_evt_cmp(IEP_CMP0); // CT_IEP.TMR_CMP_STS.bit0 + /* Clear Timer Compare 0 */ + iep_clear_evt_cmp(IEP_CMP0); /* update timestamp * NOTE: incrementing of next_sync_timestamp_ns is done by PRU1 * */ SHARED_MEM.last_sync_timestamp_ns = SHARED_MEM.next_sync_timestamp_ns; + /* orward interrupt to pru1 */ + SHARED_MEM.cmp0_trigger_for_pru1 = 1u; /* go dark if not running */ if (SHARED_MEM.shp_pru_state != STATE_RUNNING) GPIO_OFF(DEBUG_PIN0_MASK); } @@ -246,10 +247,9 @@ void event_loop() iep_clear_evt_cmp(IEP_CMP1); // CT_IEP.TMR_CMP_STS.bit1 /* update current time (if not already done) */ - if (~(iep_tmr_cmp_sts & IEP_CMP0_MASK)) - { - last_sample_timestamp_ns += SAMPLE_INTERVAL_NS; - } + if (iep_tmr_cmp_sts & IEP_CMP0_MASK) + last_sample_timestamp_ns = SHARED_MEM.last_sync_timestamp_ns; + else last_sample_timestamp_ns += SAMPLE_INTERVAL_NS; /* The actual sampling takes place here */ if (SHARED_MEM.shp_pru_state == STATE_RUNNING) diff --git a/software/firmware/pru1-shepherd-fw/main.c b/software/firmware/pru1-shepherd-fw/main.c index 33b6760a..4c9c8e1e 100644 --- a/software/firmware/pru1-shepherd-fw/main.c +++ b/software/firmware/pru1-shepherd-fw/main.c @@ -67,6 +67,7 @@ static inline bool_ft receive_sync_reply(struct ProtoMsg *const msg) // (sync-reset does test pipeline) return 0u; } + msgsys_send_status(MSG_ERR_INVLD_CMD, msg->type, 0u); return 1u; } return 0u; @@ -83,7 +84,6 @@ static inline bool_ft receive_sync_reply(struct ProtoMsg *const msg) static inline void check_gpio(const uint32_t last_sync_offset_ns) { static uint32_t prev_gpio_status = 0x00; - /* * Only continue if shepherd is running */ @@ -130,8 +130,7 @@ static inline void check_gpio(const uint32_t last_sync_offset_ns) } -/* TODO: update comments, they seem outdated - * The firmware for synchronization/sample timing is based on a simple +/* The firmware for synchronization/sample timing is based on a simple * event loop. There are three events: * 1) Interrupt from Linux kernel module * 2) Local IEP timer compare for sampling @@ -175,6 +174,8 @@ int32_t event_loop() uint32_t compensation_increment = 0u; uint32_t bresenham_counter = 0u; uint32_t bresenham_increment = 0u; + uint32_t timer_ns = 0u; + bool_ft host_int_early = 0u; /* Tracks our local state, allowing to execute actions at the right time */ struct ProtoMsg sync_repl; enum SyncState sync_state = IDLE; @@ -186,6 +187,7 @@ int32_t event_loop() /* pru1 util monitor */ uint32_t pru1_tsample_ns_max = 0u; uint32_t last_timer_ns = 0u; + bool_ft transmit_util = 0u; /* Configure timer */ iep_set_cmp_val(IEP_CMP0, SYNC_INTERVAL_NS); // 20 MTicks -> 100 ms @@ -229,7 +231,9 @@ int32_t event_loop() compensation_counter--; } - const uint32_t timer_ns = iep_get_cnt_val(); + timer_ns = iep_get_cnt_val(); + if (read_r31() & HOST_INT_TIMESTAMP_MASK) host_int_early = 1u; + DEBUG_GPIO_STATE_1; check_gpio(timer_ns); DEBUG_GPIO_STATE_0; @@ -238,7 +242,7 @@ int32_t event_loop() const uint32_t tsample_ns = timer_ns - last_timer_ns; if ((tsample_ns > pru1_tsample_ns_max) && (tsample_ns < (1u << 20u))) { - pru1_tsample_ns_max = timer_ns; + pru1_tsample_ns_max = tsample_ns; } last_timer_ns = timer_ns; @@ -247,19 +251,21 @@ int32_t event_loop() { if (!INTC_CHECK_EVENT(HOST_PRU_EVT_TIMESTAMP)) continue; - /* Take timestamp of IEP */ - const uint32_t iep_timestamp = iep_get_cnt_val(); // TODO: use loop-value + /* Take timestamp of IEP if event just came up now */ + if (!host_int_early) timer_ns = iep_get_cnt_val(); + host_int_early = 0u; + DEBUG_EVENT_STATE_3; /* Clear interrupt */ INTC_CLEAR_EVENT(HOST_PRU_EVT_TIMESTAMP); if (sync_state == IDLE) sync_state = REPLY_PENDING; - //else - //{ - // msgsys_send_status(MSG_ERR_SYNC_STATE_NOT_IDLE, sync_state, 0u); - // return 0; - //} - msgsys_send(MSG_SYNC_ROUTINE, iep_timestamp, 0u); + else + { + msgsys_send_status(MSG_ERR_SYNC_STATE_NOT_IDLE, sync_state, 0u); + return 0; + } + msgsys_send(MSG_SYNC_ROUTINE, timer_ns, 0u); DEBUG_EVENT_STATE_0; continue; // for more regular gpio-sampling } @@ -272,10 +278,11 @@ int32_t event_loop() SHARED_MEM.cmp0_trigger_for_pru1 = 0; /* update clock compensation of sample-trigger */ - iep_set_cmp_val(IEP_CMP1, 0); // TODO: is this correct? + //iep_set_cmp_val(IEP_CMP1, 0); // TODO: is this correct? + iep_enable_evt_cmp(IEP_CMP1); SHARED_MEM.next_sync_timestamp_ns += SYNC_INTERVAL_NS; - //iep_enable_evt_cmp(IEP_CMP1); + if (sync_repl.value[0] >= SAMPLE_INTERVAL_TICKS) { // PRU is ahead, slow down @@ -291,22 +298,8 @@ int32_t event_loop() bresenham_increment = sync_repl.value[1]; bresenham_counter = 0; - /* transmit pru0-util, current design puts this in fresh/next buffer */ - // TODO: this can be done on separate occasion (triggered by this event3) - { - const uint32_t idx = SHARED_MEM.buffer_util_idx; - // TODO: add timestamp - SHARED_MEM.buffer_util_ptr->pru0_tsample_ns_sum[idx] = pru0_tsample_ns_sum; - SHARED_MEM.buffer_util_ptr->pru0_tsample_ns_max[idx] = pru0_tsample_ns_max; - SHARED_MEM.buffer_util_ptr->pru0_sample_count[idx] = pru0_sample_count; - SHARED_MEM.buffer_util_ptr->pru1_tsample_max[idx] = pru1_tsample_ns_max; - SHARED_MEM.buffer_util_ptr->idx_pru = idx; - pru0_tsample_ns_sum = 0u; - pru0_tsample_ns_max = 0u; - pru0_sample_count = 0u; - if (idx < BUFFER_UTIL_SIZE - 1u) { SHARED_MEM.buffer_util_idx = idx + 1u; } - else { SHARED_MEM.buffer_util_idx = 0u; } - } + /* trigger logging of util - separate for lower impact */ + transmit_util = 1u; // TODO: add warning for when sync not idle? DEBUG_EVENT_STATE_0; @@ -325,7 +318,7 @@ int32_t event_loop() // Update sample-trigger of timer uint32_t new_trigger = iep_get_cmp_val(IEP_CMP1) + SAMPLE_INTERVAL_NS; - //if (new_trigger >= SYNC_INTERVAL_NS) new_trigger -= SYNC_INTERVAL_NS; + if (new_trigger > SYNC_INTERVAL_NS) new_trigger -= SYNC_INTERVAL_NS; iep_set_cmp_val(IEP_CMP1, new_trigger); /* reactivate compensation with fixed point magic */ @@ -365,6 +358,26 @@ int32_t event_loop() continue; } + /* transmit pru0-util, current design puts this in fresh/next buffer */ + if (transmit_util) + { + const uint32_t idx = SHARED_MEM.buffer_util_idx; + // TODO: add timestamp + SHARED_MEM.buffer_util_ptr->pru0_tsample_ns_sum[idx] = pru0_tsample_ns_sum; + SHARED_MEM.buffer_util_ptr->pru0_tsample_ns_max[idx] = pru0_tsample_ns_max; + SHARED_MEM.buffer_util_ptr->pru0_sample_count[idx] = pru0_sample_count; + SHARED_MEM.buffer_util_ptr->pru1_tsample_ns_max[idx] = pru1_tsample_ns_max; + SHARED_MEM.buffer_util_ptr->idx_pru = idx; + transmit_util = 0u; + pru0_tsample_ns_sum = 0u; + pru0_tsample_ns_max = 0u; + pru0_sample_count = 0u; + pru1_tsample_ns_max = 0u; + if (idx < BUFFER_UTIL_SIZE - 1u) { SHARED_MEM.buffer_util_idx = idx + 1u; } + else { SHARED_MEM.buffer_util_idx = 0u; } + continue; + } + /* pru0 util monitoring */ // TODO: move to PRU0? if (SHARED_MEM.pru0_ns_per_sample != IDX_OUT_OF_BOUND) diff --git a/software/kernel-module/src/module_base.c b/software/kernel-module/src/module_base.c index e5e317ce..51eb45d3 100644 --- a/software/kernel-module/src/module_base.c +++ b/software/kernel-module/src/module_base.c @@ -6,7 +6,10 @@ #include #include #include +#include // TODO: test +#include // todo: test #include +#include // todo: test #include #include @@ -77,14 +80,12 @@ static int prepare_shepherd_platform_data(struct platform_device *pdev) if (strncmp(tmp_rproc->name, "4a334000.pru", 12) == 0) { printk(KERN_INFO "shprd.k: Found PRU0 at phandle 0x%02X", child->phandle); - shp_pdata->rproc_prus[0] = tmp_rproc; } else if (strncmp(tmp_rproc->name, "4a338000.pru", 12) == 0) { printk(KERN_INFO "shprd.k: Found PRU1 at phandle 0x%02X", child->phandle); - shp_pdata->rproc_prus[1] = tmp_rproc; } } @@ -125,25 +126,44 @@ static int shepherd_drv_probe(struct platform_device *pdev) static int shepherd_drv_remove(struct platform_device *pdev) { - struct shepherd_platform_data *pdata; - - pdata = pdev->dev.platform_data; sysfs_interface_exit(); msg_sys_exit(); sync_exit(); mem_interface_exit(); - if (pdata != NULL) + if (shp_pdata != NULL) { - rproc_shutdown(pdata->rproc_prus[0]); - rproc_put(pdata->rproc_prus[0]); - rproc_shutdown(pdata->rproc_prus[1]); - rproc_put(pdata->rproc_prus[1]); - devm_kfree(&pdev->dev, pdev->dev.platform_data); + if (shp_pdata->rproc_prus[1]->state == RPROC_RUNNING) + { + rproc_shutdown(shp_pdata->rproc_prus[1]); + printk(KERN_INFO "shprd.k: PRU1 shut down"); + } + if (shp_pdata->rproc_prus[0]->state == RPROC_RUNNING) + { + rproc_shutdown(shp_pdata->rproc_prus[0]); + printk(KERN_INFO "shprd.k: PRU0 shut down"); + } + // pt->pruss = pruss_get(pt->pru); // struct pruss * + //pruss_release_mem_region(pt->pruss, &pt->mem); + pruss_put(pruss_get(shp_pdata->rproc_prus[0])); + pruss_put(pruss_get(shp_pdata->rproc_prus[1])); + printk(KERN_INFO "shprd.k: prusses returned"); + // there is rproc_free(), + pru_rproc_put(shp_pdata->rproc_prus[0]); + pru_rproc_put(shp_pdata->rproc_prus[1]); + rproc_put(shp_pdata->rproc_prus[0]); + //rproc_put(shp_pdata->rproc_prus[1]); + shp_pdata->rproc_prus[0] = NULL; + shp_pdata->rproc_prus[1] = NULL; + printk(KERN_INFO "shprd.k: PRU-handles returned"); + devm_kfree(&pdev->dev, shp_pdata); + printk(KERN_INFO "shprd.k: platform-data 1 freed"); + shp_pdata = NULL; pdev->dev.platform_data = NULL; - printk(KERN_INFO "shprd.k: PRUs shut down"); + printk(KERN_INFO "shprd.k: platform-data 2 nulled"); } - + // TODO: testing-ground - module will not fully exit with + // "modprobe: FATAL: Module remoteproc is in use." platform_set_drvdata(pdev, NULL); printk(KERN_INFO "shprd.k: module exited from kernel!!!"); return 0; diff --git a/software/kernel-module/src/pru_msg_sys.c b/software/kernel-module/src/pru_msg_sys.c index a012012a..f7bab135 100644 --- a/software/kernel-module/src/pru_msg_sys.c +++ b/software/kernel-module/src/pru_msg_sys.c @@ -200,7 +200,10 @@ static enum hrtimer_restart coordinator_callback(struct hrtimer *timer_for_resta switch (pru_msg.type) { // NOTE: all MSG_ERR also get handed to python - case MSG_ERR_INVLD_CMD: break; + case MSG_ERR_INVLD_CMD: + printk(KERN_ERR "shprd.pru%u: pru received invalid cmd, type = %u", + had_work & 1u, pru_msg.value[0]); + break; case MSG_ERR_MEM_CORRUPTION: printk(KERN_ERR "shprd.pru%u: msg.id from kernel is faulty -> mem " "corruption? (val=%u)", @@ -239,7 +242,7 @@ static enum hrtimer_restart coordinator_callback(struct hrtimer *timer_for_resta break; default: /* these are all handled in userspace and will be passed by sys-fs */ - printk(KERN_ERR "shprd.k: received invalid command / msg-type (0x%02X) " + printk(KERN_ERR "shprd.k: received invalid command / msg-type = 0x%02X" "from pru%u", pru_msg.type, had_work & 1u); } diff --git a/software/kernel-module/src/pru_sync_control.c b/software/kernel-module/src/pru_sync_control.c index 49ef6051..7e358411 100644 --- a/software/kernel-module/src/pru_sync_control.c +++ b/software/kernel-module/src/pru_sync_control.c @@ -198,7 +198,7 @@ enum hrtimer_restart trigger_loop_callback(struct hrtimer *timer_for_restart) { uint64_t ns_to_next_trigger; uint64_t ts_now_ns; - + // TODO: best would be to get rid of this additional loop - is there a sys-interrupt we can use? GPIO_P819_SET; /* Raise Interrupt on PRU, telling it to timestamp IEP */ @@ -326,18 +326,19 @@ int sync_PID_correction(struct ProtoMsg *const sync_reply, const struct ProtoMsg ((smooth_factor - 1) * sync_state.input_smooth - input_now) / smooth_factor; /* adjust PI-Tuning once stable */ + // TODO: slow down state-changes, also try holding ki - phase-changes stay in recent versions if ((sync_state.input_smooth < 1000000) && (sync_state.k_state == 0)) { sync_state.kp_inv_n10 *= 2; sync_state.ki_inv_n10 *= 2; - sync_state.k_state = 1; + sync_state.k_state++; printk(KERN_INFO "shprd.sync: error BELOW 1ms -> relax PI-tuning"); } else if ((sync_state.input_smooth < 200000) && (sync_state.k_state == 1)) { sync_state.kp_inv_n10 *= 2; sync_state.ki_inv_n10 *= 2; - sync_state.k_state = 2; + sync_state.k_state++; printk(KERN_INFO "shprd.sync: error BELOW 200us -> relax PI-tuning"); } else if ((sync_state.input_smooth > 2000000) && (sync_state.k_state > 0)) diff --git a/software/kernel-module/src/sysfs_interface.c b/software/kernel-module/src/sysfs_interface.c index 18550473..f5ab1728 100644 --- a/software/kernel-module/src/sysfs_interface.c +++ b/software/kernel-module/src/sysfs_interface.c @@ -953,4 +953,5 @@ void sysfs_interface_exit(void) kobject_put(kobj_sync_ref); kobject_put(kobj_mem_ref); kobject_put(kobj_ref); + printk(KERN_INFO "shprd.k: sysfs exited"); } diff --git a/software/python-package/shepherd_sheep/h5_recorder_pru.py b/software/python-package/shepherd_sheep/h5_recorder_pru.py index e9322f06..aa964748 100644 --- a/software/python-package/shepherd_sheep/h5_recorder_pru.py +++ b/software/python-package/shepherd_sheep/h5_recorder_pru.py @@ -26,12 +26,12 @@ def __init__( compression=compression, ) - self.data["values"].attrs["unit"] = "ticks, ticks" + self.data["values"].attrs["unit"] = "ns, ns, ns" self.data["values"].attrs["description"] = ( - "pru0_util_mean [ticks], " - "pru0_util_min [ticks]," - "pru0_util_max [ticks]," - f"with {commons.SAMPLE_INTERVAL_TICKS} ticks per sample-step" + "pru0_vsrc_tsample_mean [ns], " + "pru0_vsrc_tsample_max [ns]," + "pru1_gpio_tsample_max [ns]," + f"with {commons.SAMPLE_INTERVAL_NS} ns per sample-step" ) # reset increment AFTER creating all dsets are created self.increment = 1000 # 100 s @@ -62,9 +62,9 @@ def write(self, data: UtilTrace) -> None: self.data["values"].resize((data_length, 3)) self.data["time"].resize((data_length,)) self.data["time"][self.position : pos_end] = int(time.time() * 1e9) - self.data["values"][self.position : pos_end, 0] = data.ticks_mean - self.data["values"][self.position : pos_end, 1] = data.ticks_min - self.data["values"][self.position : pos_end, 2] = data.ticks_max + self.data["values"][self.position : pos_end, 0] = data.pru0_tsample_mean + self.data["values"][self.position : pos_end, 1] = data.pru0_tsample_max + self.data["values"][self.position : pos_end, 2] = data.pru1_tsample_max self.position = pos_end def thread_fn(self) -> None: diff --git a/software/python-package/shepherd_sheep/shared_memory.py b/software/python-package/shepherd_sheep/shared_memory.py index 8a724371..479abca1 100644 --- a/software/python-package/shepherd_sheep/shared_memory.py +++ b/software/python-package/shepherd_sheep/shared_memory.py @@ -83,21 +83,21 @@ class UtilTrace: def __init__( self, timestamps_ns: np.ndarray, - ticks_min: np.ndarray, - ticks_max: np.ndarray, - ticks_mean: np.ndarray, + pru0_tsample_mean: np.ndarray, + pru0_tsample_max: np.ndarray, + pru1_tsample_max: np.ndarray, ) -> None: self.timestamps_ns = timestamps_ns - self.ticks_min = ticks_min - self.ticks_max = ticks_max - self.ticks_mean = ticks_mean + self.pru0_tsample_mean = pru0_tsample_mean + self.pru0_tsample_max = pru0_tsample_max + self.pru1_tsample_max = pru1_tsample_max def __len__(self) -> int: return min( self.timestamps_ns.size, - self.ticks_mean.size, - self.ticks_min.size, - self.ticks_max.size, + self.pru0_tsample_mean.size, + self.pru0_tsample_max.size, + self.pru1_tsample_max.size, ) @@ -208,12 +208,16 @@ def __init__( self.util_trace_index = 0 self.util_trace_offset = self.gpio_trace_offset + self.gpio_trace_size self.util_timestamps_offset = self.util_trace_offset + 4 - self.util_ticks_min_offset = self.util_trace_offset + 4 + commons.BUFFER_UTIL_SIZE * 8 - self.util_ticks_max_offset = self.util_trace_offset + 4 + commons.BUFFER_UTIL_SIZE * (8 + 4) - self.util_ticks_sum_offset = ( - self.util_trace_offset + 4 + commons.BUFFER_UTIL_SIZE * (8 + 2 * 4) + self.util_pru0_tsample_max_offset = ( + self.util_trace_offset + 4 + commons.BUFFER_UTIL_SIZE * 8 + ) + self.util_pru0_tsample_sum_offset = ( + self.util_trace_offset + 4 + commons.BUFFER_UTIL_SIZE * (8 + 1 * 4) ) self.util_sample_count_offset = ( + self.util_trace_offset + 4 + commons.BUFFER_UTIL_SIZE * (8 + 2 * 4) + ) + self.util_pru1_tsample_max_offset = ( self.util_trace_offset + 4 + commons.BUFFER_UTIL_SIZE * (8 + 3 * 4) ) self.util_canary_offset = ( @@ -442,7 +446,7 @@ def read_buffer_iv(self, *, verbose: bool = False) -> IVTrace | None: ) else: data = None - log.debug("Discarded IV-Data / out of time-boundary.") + log.debug("Discarded IV-Data / out of time-boundary (t_pru = %d).", pru_timestamp) # TODO: segment in buffer should be reset to ZERO to better detect errors # advance index @@ -545,36 +549,35 @@ def read_buffer_util(self, *, verbose: bool = False) -> UtilTrace | None: count=self.util_segment_size, offset=self.util_timestamps_offset + self.util_trace_index * 8, ), - ticks_min=np.frombuffer( + pru0_tsample_max=np.frombuffer( self.mapped_mem, np.uint32, count=self.util_segment_size, - offset=self.util_ticks_min_offset + self.util_trace_index * 4, + offset=self.util_pru0_tsample_max_offset + self.util_trace_index * 4, ), - ticks_max=np.frombuffer( + pru1_tsample_max=np.frombuffer( self.mapped_mem, np.uint32, count=self.util_segment_size, - offset=self.util_ticks_max_offset + self.util_trace_index * 4, + offset=self.util_pru1_tsample_max_offset + self.util_trace_index * 4, ), - ticks_mean=np.frombuffer( + pru0_tsample_mean=np.frombuffer( self.mapped_mem, np.uint32, count=self.util_segment_size, - offset=self.util_ticks_sum_offset + self.util_trace_index * 4, + offset=self.util_pru0_tsample_sum_offset + self.util_trace_index * 4, ) / sample_count, ) # TODO: cleanup, every crit-instance should be reported - util_mean_val = data.ticks_mean.mean() * 100 / commons.SAMPLE_INTERVAL_TICKS - util_min_val = data.ticks_min.max() * 100 / commons.SAMPLE_INTERVAL_TICKS - util_max_val = data.ticks_max.max() * 100 / commons.SAMPLE_INTERVAL_TICKS + util_mean_val = data.pru0_tsample_mean.mean() * 100 / commons.SAMPLE_INTERVAL_NS + util_max_val = data.pru0_tsample_max.max() * 100 / commons.SAMPLE_INTERVAL_NS util_mean_crit = util_mean_val > 95.0 util_max_crit = util_max_val >= 100.0 if (self.pru_warn_counter > 0) and (util_mean_crit or util_max_crit): log.warning( - "Pru0 Loop-Util: mean = %.3f %%, max = %.3f %% " + "Pru0-Util: mean = %.3f %%, max = %.3f %% " "-> WARNING: probably broken real-time-condition", util_mean_val, util_max_val, @@ -582,18 +585,15 @@ def read_buffer_util(self, *, verbose: bool = False) -> UtilTrace | None: self.pru_warn_counter -= 1 if self.pru_warn_counter == 0: # silenced because this is causing overhead without a cape - log.warning( - "Pru0 Loop-Util-Warning is silenced now! Is emu running without a cape?" - ) + log.warning("Pru0-Util-Warning is silenced now! Is emu running without a cape?") elif verbose: log.info( - "Pru0 Loop-Util = [%.3f, %.3f, %.3f] %%; sample-count [%d, %d, %d] n; (min, mean, max)", - util_min_val, + "Pru0-Util = [%.3f, %.3f] %% (mean,max); sample-count [%d, %d] n (min,max); tGpioMax = %d ns", util_mean_val, util_max_val, sample_count.min(), - sample_count.mean(), sample_count.max(), + data.pru1_tsample_max.max(), ) # TODO: segment should be reset to ZERO to better detect errors