TDA4VM: MCU2_1 CPU load occasional 100%

Hi,

This looks similar to the below thread

(+) TDA4VM: perf_stats overflow issue - Processors forum - Processors - TI E2E support forums

Could you share the source code on how you are reproducing this, so that I could try the same at my end?

Regards,

Nikhil

Hi,

Below is the patch where we debug the code, you may need to write a demo use case with reference to patch.

Date: Tue, 12 Mar 2024 14:51:38 +0800
Subject: [PATCH] [DEBUG]:DEBUG MCU2_1 100%

Change-Id: I50d093216dab5a0b5308359d94aebfacff4dbb14
---

diff --git a/pdk_jacinto_08_04_00_21/packages/ti/kernel/freertos/config/j721e/r5f/FreeRTOSConfig.h b/pdk_jacinto_08_04_00_21/packages/ti/kernel/freertos/config/j721e/r5f/FreeRTOSConfig.h
index a232ab5..5b80b36 100755
--- a/pdk_jacinto_08_04_00_21/packages/ti/kernel/freertos/config/j721e/r5f/FreeRTOSConfig.h
+++ b/pdk_jacinto_08_04_00_21/packages/ti/kernel/freertos/config/j721e/r5f/FreeRTOSConfig.h
@@ -206,7 +206,7 @@
 
 #if (configLOAD_UPDATE_IN_IDLE==1)
 #undef  configUSE_IDLE_HOOK
-#define configUSE_IDLE_HOOK         (1)
+#define configUSE_IDLE_HOOK         (0)
 #endif
 
 #endif /* TI_FREERTOS_CONFIG_H */
diff --git a/pdk_jacinto_08_04_00_21/packages/ti/osal/LoadP.h b/pdk_jacinto_08_04_00_21/packages/ti/osal/LoadP.h
index 01653e9..037f1a3 100755
--- a/pdk_jacinto_08_04_00_21/packages/ti/osal/LoadP.h
+++ b/pdk_jacinto_08_04_00_21/packages/ti/osal/LoadP.h
@@ -125,7 +125,11 @@
  */
 extern void LoadP_update(void);
 
-
+extern uint64_t getTotalTime();
+extern uint64_t getIdlTskTime();
+extern uint64_t getResetTimes();
+extern uint64_t getGetTimes();
+extern void resetResetTimes();
 #ifdef __cplusplus
 }
 #endif
diff --git a/pdk_jacinto_08_04_00_21/packages/ti/osal/src/freertos/LoadP_freertos.c b/pdk_jacinto_08_04_00_21/packages/ti/osal/src/freertos/LoadP_freertos.c
index fc72b9f..e625c5a 100755
--- a/pdk_jacinto_08_04_00_21/packages/ti/osal/src/freertos/LoadP_freertos.c
+++ b/pdk_jacinto_08_04_00_21/packages/ti/osal/src/freertos/LoadP_freertos.c
@@ -102,6 +102,26 @@
 /*                          Function Definitions                              */
 /* ========================================================================== */
 
+static uint64_t idlTskTime = 0;
+static uint64_t totalTime = 0;
+static uint64_t resetTimes = 0;
+static uint64_t getTimes = 0;
+
+uint64_t getTotalTime(){
+    return totalTime;
+}
+uint64_t getIdlTskTime(){
+    return idlTskTime;
+}
+uint64_t getResetTimes(){
+    return resetTimes;
+}
+uint64_t getGetTimes(){
+    return getTimes;
+}
+void resetResetTimes(){
+    resetTimes = 0;
+}
 void LoadP_reset(void)
 {
     uint32_t            i;
@@ -122,7 +142,7 @@
         }
     }
     xTaskResumeAll();
-
+    resetTimes ++;
     return;
 }
 
@@ -166,11 +186,11 @@
     LoadP_update();
 
     vTaskSuspendAll();
-
-    cpuLoad = 100 - LoadP_calcPercentLoad(gLoadP_freertos.idlTskTime, gLoadP_freertos.totalTime);
-
+    idlTskTime = gLoadP_freertos.idlTskTime;
+    totalTime = gLoadP_freertos.totalTime;
+    cpuLoad = 100 - LoadP_calcPercentLoad(idlTskTime, totalTime);
+    getTimes ++;
     xTaskResumeAll();
-
     return cpuLoad;
 }
 
diff --git a/vision_apps/apps/hirain_demos/hi_diag/src/hi_diag_load.cpp b/vision_apps/apps/hirain_demos/hi_diag/src/hi_diag_load.cpp
index 3fc083f..f87010c 100755
--- a/vision_apps/apps/hirain_demos/hi_diag/src/hi_diag_load.cpp
+++ b/vision_apps/apps/hirain_demos/hi_diag/src/hi_diag_load.cpp
@@ -368,6 +368,16 @@
 }
 void hi_diag_cpu_load_1000ms(uint8_t flag)
 {
+    static uint64_t appPerfStatsCpuLoadGetTimes_MPU1_0 = 0;
+    static uint64_t appPerfStatsCpuLoadResetTimes_MPU1_0 = 0;
+    static uint64_t appPerfStatsCpuLoadGetTimes_MCU2_0 = 0;
+    static uint64_t appPerfStatsCpuLoadResetTimes_MCU2_0 = 0;
+    static uint64_t appPerfStatsCpuLoadGetTimes_MCU2_1 = 0;
+    static uint64_t appPerfStatsCpuLoadResetTimes_MCU2_1 = 0;
+    static uint64_t appPerfStatsCpuLoadGetTimes_C6x_1 = 0;
+    static uint64_t appPerfStatsCpuLoadResetTimes_C6x_1 = 0;
+    static uint64_t appPerfStatsCpuLoadGetTimes_C6x_2 = 0;
+    static uint64_t appPerfStatsCpuLoadResetTimes_C6x_2 = 0;
     static int32_t status = 0;
     static uint32_t cpu_id;
     static app_perf_stats_cpu_load_t cpu_load_str;
@@ -425,6 +435,8 @@
                     gmpu1_0_load_check_line = gmpu1_0_load;
                     VDB_LOG_ERROR("gmpu1_0_load = %d. \n", gmpu1_0_load);
                 }
+            appPerfStatsCpuLoadGetTimes_MPU1_0 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadGetTimes_MPU1_0 : %d", appPerfStatsCpuLoadGetTimes_MPU1_0);
         }
         if (cpu_id == APP_IPC_CPU_MCU2_0) {
             gmcu2_0_load = cpu_load_str.cpu_load / 100u;
@@ -432,6 +444,8 @@
                     gmcu2_0_load_check_line = gmcu2_0_load;
                     VDB_LOG_ERROR("gmcu2_0_load = %d. \n", gmcu2_0_load);
                 }
+            appPerfStatsCpuLoadGetTimes_MCU2_0 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadGetTimes_MCU2_0 : %d", appPerfStatsCpuLoadGetTimes_MCU2_0);
         }
         if (cpu_id == APP_IPC_CPU_MCU2_1) {
             gmcu2_1_load = cpu_load_str.cpu_load / 100u;
@@ -439,6 +453,8 @@
                     gmcu2_1_load_check_line = gmcu2_1_load;
                     VDB_LOG_ERROR("gmcu2_1_load = %d. \n", gmcu2_1_load);
                 }
+            appPerfStatsCpuLoadGetTimes_MCU2_1 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadGetTimes_MCU2_1 : %d", appPerfStatsCpuLoadGetTimes_MCU2_1);
         }
         // if (cpu_id == APP_IPC_CPU_C7x_1) {
         //     gc7x_cpu_load = cpu_load_str.cpu_load / 100u;
@@ -455,9 +471,32 @@
                     VDB_LOG_ERROR("gc66_cpu_load = %d. \n", gc66_cpu_load);
                 }
             }
+            if(cpu_id == APP_IPC_CPU_C6x_1){
+                appPerfStatsCpuLoadGetTimes_C6x_1 ++;
+                VDB_LOG_NOTE("appPerfStatsCpuLoadGetTimes_C6x_1 : %d", appPerfStatsCpuLoadGetTimes_C6x_1);
+            }else{
+                appPerfStatsCpuLoadGetTimes_C6x_2 ++;
+                VDB_LOG_NOTE("appPerfStatsCpuLoadGetTimes_C6x_2 : %d", appPerfStatsCpuLoadGetTimes_C6x_2);                
+            }
         }
 
         status = appPerfStatsCpuLoadReset(cpu_id);
+        if(cpu_id == APP_IPC_CPU_MPU1_0){
+            appPerfStatsCpuLoadResetTimes_MPU1_0 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadResetTimes_MPU1_0 : %d", appPerfStatsCpuLoadResetTimes_MPU1_0);
+        }else if(cpu_id == APP_IPC_CPU_MCU2_0){
+            appPerfStatsCpuLoadResetTimes_MCU2_0 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadResetTimes_MCU2_0 : %d", appPerfStatsCpuLoadResetTimes_MCU2_0);
+        }else if(cpu_id == APP_IPC_CPU_MCU2_1){
+            appPerfStatsCpuLoadResetTimes_MCU2_1 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadResetTimes_MCU2_1 : %d", appPerfStatsCpuLoadResetTimes_MCU2_1);
+        }else if(cpu_id == APP_IPC_CPU_C6x_1){
+            appPerfStatsCpuLoadResetTimes_C6x_1 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadResetTimes_C6x_1 : %d", appPerfStatsCpuLoadResetTimes_C6x_1);
+        }else if(cpu_id == APP_IPC_CPU_C6x_2){
+            appPerfStatsCpuLoadResetTimes_C6x_2 ++;
+            VDB_LOG_NOTE("appPerfStatsCpuLoadResetTimes_C6x_2 : %d", appPerfStatsCpuLoadResetTimes_C6x_2);
+        }
         if (status < 0) {
             VDB_LOG_ERROR("CPU %6s load reset failed !\n", appIpcGetCpuName(cpu_id));
         }
diff --git a/vision_apps/platform/j721e/rtos/mcu2_1/main.c b/vision_apps/platform/j721e/rtos/mcu2_1/main.c
index ee24c2b..84feea1 100755
--- a/vision_apps/platform/j721e/rtos/mcu2_1/main.c
+++ b/vision_apps/platform/j721e/rtos/mcu2_1/main.c
@@ -70,8 +70,6 @@
 #include <app_ipc_rsctable.h>
 #include <utils/des_fsync/include/hw_timer.h>
 
-static const uint16_t gTaskTime10s  = 1000U;
-
 static void appMain(void* arg0, void* arg1)
 {
     appUtilsTaskInit();
@@ -79,16 +77,12 @@
     appRun();
     //init des_fsync PWM timer
     hi_des_fsync_pwm_init();
-    uint16_t counter = 0;
+
     #if 1
     while(1)
     {
-        if (counter >= gTaskTime10s) {
-            appLogPrintf("[ads] mcu2_1 is working\n");
-            counter = 0;
-        }
-        counter++;
-        appLogWaitMsecs(10u);
+        appLogPrintf("[ads] mcu2_1 is working\n");
+        appLogWaitMsecs(10000u);
     }
     #else
     appDeInit();
diff --git a/vision_apps/utils/perf_stats/src/app_perf_stats_freertos.c b/vision_apps/utils/perf_stats/src/app_perf_stats_freertos.c
index 6a8f4ac..da5d5c0 100755
--- a/vision_apps/utils/perf_stats/src/app_perf_stats_freertos.c
+++ b/vision_apps/utils/perf_stats/src/app_perf_stats_freertos.c
@@ -366,6 +366,9 @@
                 #if defined(FREERTOS)
                 /* Multiplying by 100 to show decimal points when printing */
                 cpu_load->cpu_load = 100 * LoadP_getCPULoad();
+                appLogPrintf("current cpu load: %lu getTimes: %llu resetTimes: %llu idlTskTime: %llu, totalTime: %llu", cpu_load->cpu_load, getGetTimes(), getResetTimes(), getIdlTskTime(), getTotalTime());
+
+                // resetResetTimes();
                 #endif
 
                 cpu_load->hwi_load = 0U;

Let me try this at my end and get back to you early next week.

HI, Has there been any progress on this issue？

Sorry for the delay here. I will get back this week

HI, Has there been any progress on this issue？

Hi,

Sorry for the delay here.

I tested the same using the below application

/cfs-file/__key/communityserver-discussions-components-files/791/basic_5F00_test.c

and the below changes

diff --git a/platform/j721e/rtos/mcu2_1/main.c b/platform/j721e/rtos/mcu2_1/main.c
index 6e492f4..5e93af3 100755
--- a/platform/j721e/rtos/mcu2_1/main.c
+++ b/platform/j721e/rtos/mcu2_1/main.c
@@ -77,7 +77,8 @@ static void appMain(void* arg0, void* arg1)
     #if 1
     while(1)
     {
-        appLogWaitMsecs(100u);
+        printf("[ads] mcu2_1 is working\n");
+        appLogWaitMsecs(10000u);
     }
     #else
     appDeInit();
     
     
     

diff --git a/utils/perf_stats/src/app_perf_stats_freertos.c b/utils/perf_stats/src/app_perf_stats_freertos.c
index 2c63699..cd42bfb 100644
--- a/utils/perf_stats/src/app_perf_stats_freertos.c
+++ b/utils/perf_stats/src/app_perf_stats_freertos.c
@@ -365,6 +365,7 @@ int32_t appPerfStatsHandler(char *service_name, uint32_t cmd, void *prm, uint32_
                 #if defined(FREERTOS)
                 /* Multiplying by 100 to show decimal points when printing */
                 cpu_load->cpu_load = 100 * LoadP_getCPULoad();
+                printf("current cpu load: %u\n",cpu_load->cpu_load);
                 #endif
 
                 cpu_load->hwi_load = 0U;

I was getting a constant print of 100 i.e. around 1%

[MCU2_1]    512.694176 s: current cpu load: 100
task running
[MCU2_1]    513.694454 s: current cpu load: 100
task running
[MCU2_1]    514.694727 s: current cpu load: 100
task running
[MCU2_1]    515.695008 s: current cpu load: 100
[MCU2_1]    516.430638 s: [ads] mcu2_1 is working
task running
[MCU2_1]    516.695293 s: current cpu load: 100
task running
[MCU2_1]    517.695573 s: current cpu load: 100
task running
[MCU2_1]    518.695859 s: current cpu load: 100
task running
[MCU2_1]    519.696140 s: current cpu load: 100
task running
[MCU2_1]    520.696414 s: current cpu load: 100
task running
[MCU2_1]    521.696695 s: current cpu load: 100
task running
[MCU2_1]    522.696983 s: current cpu load: 100
task running
[MCU2_1]    523.697263 s: current cpu load: 100
task running
[MCU2_1]    524.697545 s: current cpu load: 100
task running
[MCU2_1]    525.697830 s: current cpu load: 100
[MCU2_1]    526.430639 s: [ads] mcu2_1 is working
task running
[MCU2_1]    526.698123 s: current cpu load: 100

I am not seeing 10000 here. Could you please confirm if I must read from all the cores to reproduce the issue or were you able to reproduce the same with just reading MCU2_1 ?

Regards,

Nikhil

We found this problem in about 12 hours of stress test logs, so it is better to try to observe it for a longer time.

HI, Has there been any progress on this issue？

Hi,

I have kept the same for long run. Still trying to reproduce the issue.

Meanwhile, could you please confirm if the above content sent by me is sufficient to reproduce this issue or do you have some modifications which would reproduce the same faster?

Regards,

Nikhil

I think it is sufficient to reproduce this issue.And this issue occurs once or three times in 12 hours.Has there been any progress on this issue？

HI, Has there been any progress on this issue？

Hi,

I am able to reproduce this issue at my end now. 

It seems that sometime the idltsk time is corrupted and sometimes the totaltime is corrupted. 

Now that I have reproduced this issue, Please allow me sometime to debug this and get back to you 

Regards,

Nikhil

Thank you, when is this issue expected to be resolved, and when you will be able to provide the code to resolve the issue?

Hi,

The fix should be available in the upcoming SDK 10.0 which would be around mid of July 2024 as per the current SW Roadmap.

Regards,

Nikhil

Is this bug critical? Will it impact the functionality? Can you address it with a patch?

Hi,

The issue is a predictable one, i.e. the rollover happens every 2^32 nanoseconds (i.e. around 1.5 hours). 

The unpredictable loading issue is resolved in SDK 9.1 

So, I do not think this should affect the functionality.

However, we are working on fixing this by SDK 10.0. If the fix is available before that, I can share it you via a patch

Regards,

Nikhil