Mirrors_Framework/nuttx
1
0
Fork 0
mirror of https://github.com/apache/nuttx.git synced 2026-05-12 01:42:49 +08:00
Code Issues Actions Packages Projects Releases Wiki Activity

sched/spinlock: Add configuration to record busywait.

Browse Source 
Add configuration "CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT", which can record the busy waiting time to get spinlock or enter critical section.

Signed-off-by: wangzhi16 <wangzhi16@xiaomi.com>
This commit is contained in:
wangzhi16
2024-11-11 09:44:28 +08:00
committed by Donny(董九柱)
parent bb562cf8bf
commit 3116c19efc
7 changed files with 263 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files
fs/procfs/fs_procfscritmon.c
+73
View File
@@ -190,6 +190,11 @@ static ssize_t critmon_read_cpu(FAR struct critmon_file_s *attr,
size_t linesize;
size_t copysize;
size_t totalsize;
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
struct timespec alltime;
clock_t elapsed;
uint32_t rate;
#endif
UNUSED(maxtime);
UNUSED(linesize);
@@ -279,6 +284,74 @@ static ssize_t critmon_read_cpu(FAR struct critmon_file_s *attr,
}
#endif
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
/* Convert and generate output for max busywait time when trying spinlock */
if (g_busywait_max[cpu] > 0)
{
perf_convert(g_busywait_max[cpu], &maxtime);
}
else
{
maxtime.tv_sec = 0;
maxtime.tv_nsec = 0;
}
/* Reset the maximum */
g_busywait_max[cpu] = 0;
/* Generate output for max busywait time to enter csection(get spinlock) */
linesize = procfs_snprintf(attr->line, CRITMON_LINELEN, ",%lu.%09lu",
(unsigned long)maxtime.tv_sec,
(unsigned long)maxtime.tv_nsec);
copysize = procfs_memcpy(attr->line, linesize, buffer, buflen, offset);
totalsize += copysize;
buffer += copysize;
buflen -= copysize;
if (buflen <= 0)
{
return totalsize;
}
/* Convert and generate output for all busywait time when trying spinlock */
if (g_busywait_total[cpu] > 0)
{
perf_convert(g_busywait_total[cpu], &alltime);
}
else
{
alltime.tv_sec = 0;
alltime.tv_nsec = 0;
}
elapsed = clock() * CONFIG_USEC_PER_TICK;
rate = (uint64_t)(alltime.tv_sec * 1000000 + alltime.tv_nsec / 1000) *
1000000 / elapsed;
/* Generate output for all busywait time to enter csection(get spinlock) */
linesize = procfs_snprintf(attr->line, CRITMON_LINELEN, ",%lu.%09lu %2"
PRId32 ".%04" PRId32 "%%",
(unsigned long)alltime.tv_sec,
(unsigned long)alltime.tv_nsec,
rate / 10000, rate % 10000);
copysize = procfs_memcpy(attr->line, linesize, buffer, buflen, offset);
totalsize += copysize;
buffer += copysize;
buflen -= copysize;
if (buflen <= 0)
{
return totalsize;
}
#endif
linesize = procfs_snprintf(attr->line, CRITMON_LINELEN, "\n");
copysize = procfs_memcpy(attr->line, linesize, buffer, buflen, offset);
fs/procfs/fs_procfsproc.c
+63
View File
@@ -844,6 +844,69 @@ static ssize_t proc_critmon(FAR struct proc_file_s *procfile,
}
#endif /* CONFIG_SCHED_CRITMONITOR_MAXTIME_CSECTION >= 0 */
/* Convert and generate output for max busywait time && all busywait time */
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
if (tcb->busywait_max > 0)
{
perf_convert(tcb->busywait_max, &maxtime);
}
else
{
maxtime.tv_sec = 0;
maxtime.tv_nsec = 0;
}
/* Reset the maximum */
tcb->busywait_max = 0;
/* Generate output for max busywait time */
linesize = procfs_snprintf(procfile->line, STATUS_LINELEN, "%lu.%09lu %p,",
(unsigned long)maxtime.tv_sec,
(unsigned long)maxtime.tv_nsec,
tcb->busywait_max_caller);
copysize = procfs_memcpy(procfile->line, linesize, buffer, remaining,
&offset);
totalsize += copysize;
buffer += copysize;
remaining -= copysize;
if (totalsize >= buflen)
{
return totalsize;
}
if (tcb->busywait_total > 0)
{
perf_convert(tcb->busywait_total, &maxtime);
}
else
{
maxtime.tv_sec = 0;
maxtime.tv_nsec = 0;
}
/* Generate output for all busywait time */
linesize = procfs_snprintf(procfile->line, STATUS_LINELEN, "%lu.%09lu,",
(unsigned long)maxtime.tv_sec,
(unsigned long)maxtime.tv_nsec);
copysize = procfs_memcpy(procfile->line, linesize, buffer, remaining,
&offset);
totalsize += copysize;
buffer += copysize;
remaining -= copysize;
if (totalsize >= buflen)
{
return totalsize;
}
#endif /* CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0 */
/* Convert and generate output for maximum time thread running */
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_THREAD >= 0
if (tcb->run_max > 0)
include/nuttx/irq.h
+4
View File
@@ -150,6 +150,10 @@
# define CONFIG_SCHED_CRITMONITOR_MAXTIME_CSECTION -1
#endif
#ifndef CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT
# define CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT -1
#endif
#ifndef CONFIG_SCHED_CRITMONITOR_MAXTIME_IRQ
# define CONFIG_SCHED_CRITMONITOR_MAXTIME_IRQ -1
#endif
include/nuttx/sched.h
+13
View File
@@ -701,6 +701,14 @@ struct tcb_s
void *crit_max_caller; /* Caller of max critical section */
#endif
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
clock_t busywait_start; /* Time when thread busywait */
clock_t busywait_max; /* Max time of busywait */
clock_t busywait_total; /* Total time of busywait */
void *busywait_caller; /* Caller of busywait */
void *busywait_max_caller; /* Caller of max busywait */
#endif
/* State save areas *******************************************************/
/* The form and content of these fields are platform-specific. */
@@ -821,6 +829,11 @@ EXTERN clock_t g_preemp_max[CONFIG_SMP_NCPUS];
EXTERN clock_t g_crit_max[CONFIG_SMP_NCPUS];
#endif /* CONFIG_SCHED_CRITMONITOR_MAXTIME_CSECTION >= 0 */
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
EXTERN clock_t g_busywait_max[CONFIG_SMP_NCPUS];
EXTERN clock_t g_busywait_total[CONFIG_SMP_NCPUS];
#endif /* CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0 */
/* g_running_tasks[] holds a references to the running task for each CPU.
* It is valid only when up_interrupt_context() returns true.
*/
include/nuttx/spinlock.h
+22
View File
@@ -66,6 +66,12 @@ void sched_note_spinlock_unlock(FAR volatile spinlock_t *spinlock);
# define sched_note_spinlock_unlock(spinlock)
#endif
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
void nxsched_critmon_busywait(bool state, FAR void *caller);
#else
# define nxsched_critmon_busywait(state, caller)
#endif
/****************************************************************************
* Public Data Types
****************************************************************************/
@@ -223,10 +229,18 @@ static inline_function void spin_lock(FAR volatile spinlock_t *lock)
sched_note_spinlock_lock(lock);
/* If CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0, count busy-waiting. */
nxsched_critmon_busywait(true, return_address(0));
/* Lock without trace note */
spin_lock_notrace(lock);
/* Get the lock, end counting busy-waiting */
nxsched_critmon_busywait(false, return_address(0));
/* Notify that we have the spinlock */
sched_note_spinlock_locked(lock);
@@ -988,6 +1002,8 @@ void rspin_restorelock(FAR rspinlock_t *lock, uint16_t count)
static inline_function void read_lock(FAR volatile rwlock_t *lock)
{
nxsched_critmon_busywait(true, return_address(0));
while (true)
{
int old = atomic_read(lock);
@@ -1004,6 +1020,8 @@ static inline_function void read_lock(FAR volatile rwlock_t *lock)
}
UP_DMB();
nxsched_critmon_busywait(false, return_address(0));
}
/****************************************************************************
@@ -1106,6 +1124,8 @@ static inline_function void read_unlock(FAR volatile rwlock_t *lock)
static inline_function void write_lock(FAR volatile rwlock_t *lock)
{
nxsched_critmon_busywait(true, return_address(0));
while (true)
{
int zero = RW_SP_UNLOCKED;
@@ -1119,6 +1139,8 @@ static inline_function void write_lock(FAR volatile rwlock_t *lock)
}
UP_DMB();
nxsched_critmon_busywait(false, return_address(0));
}
/****************************************************************************
sched/Kconfig
+10
View File
@@ -955,6 +955,15 @@ config SCHED_CRITMONITOR_MAXTIME_CSECTION
SCHED_CRITMONITOR_MAXTIME_CSECTION, or system will give a warning.
For debugging system latency, 0 means disabled.
config SCHED_CRITMONITOR_MAXTIME_BUSYWAIT
int "Critical section or spinlock max busy waiting time"
default -1
---help---
Busy waiting time to enter critical section or
get spinlock should be smaller than
SCHED_CRITMONITOR_MAXTIME_BUSYWAIT, or system will give a warning.
For debugging system latency, -1 means disabled.
config SCHED_CRITMONITOR_MAXTIME_IRQ
int "IRQ max execution time"
default SCHED_CRITMONITOR_MAXTIME_CSECTION
@@ -981,6 +990,7 @@ config SCHED_CRITMONITOR_MAXTIME_PANIC
SCHED_CRITMONITOR_MAXTIME_WQUEUE > 0 || \
SCHED_CRITMONITOR_MAXTIME_PREEMPTION > 0 || \
SCHED_CRITMONITOR_MAXTIME_CSECTION > 0 || \
SCHED_CRITMONITOR_MAXTIME_BUSYWAIT > 0 || \
SCHED_CRITMONITOR_MAXTIME_IRQ > 0
default n
---help---
sched/sched/sched_critmonitor.c
+78
View File
@@ -70,6 +70,22 @@
# define CHECK_CSECTION(pid, elapsed)
#endif
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
# define CHECK_BUSYWAIT(pid, elapsed) \
do \
{ \
if (pid > 0 && \
elapsed > CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT) \
{ \
CRITMONITOR_PANIC("PID %d wait for critical section or spin" \
"lock too long %" PRIu32 "\n", pid, elapsed); \
} \
} \
while (0)
#else
# define CHECK_BUSYWAIT(pid, elapsed)
#endif
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_THREAD > 0
# define CHECK_THREAD(pid, elapsed) \
do \
@@ -108,6 +124,11 @@ clock_t g_preemp_max[CONFIG_SMP_NCPUS];
clock_t g_crit_max[CONFIG_SMP_NCPUS];
#endif
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
clock_t g_busywait_max[CONFIG_SMP_NCPUS];
clock_t g_busywait_total[CONFIG_SMP_NCPUS];
#endif
/****************************************************************************
* Private Functions
****************************************************************************/
@@ -274,6 +295,63 @@ void nxsched_critmon_csection(FAR struct tcb_s *tcb, bool state,
}
#endif /* CONFIG_SCHED_CRITMONITOR_MAXTIME_CSECTION >= 0 */
/****************************************************************************
* Name: nxsched_critmon_busywait
*
* Description:
* Called when a thread try to enter critical section（get spinlock） or
* successfully entered cirtical section.
*
* Assumptions:
* - Called before a critical section or within a critical section.
* - Might be called from an interrupt handler.
*
****************************************************************************/
#if CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0
void nxsched_critmon_busywait(bool state, FAR void *caller)
{
FAR struct tcb_s *tcb = this_task();
clock_t current = perf_gettime();
/* Are we busy waiting for critical section or spinlock? */
if (state)
{
/* Waiting... Save the start time. */
tcb->busywait_start = current;
tcb->busywait_caller = caller;
}
else
{
/* Entered critical section... Check for the max elapsed time */
clock_t elapsed = current - tcb->busywait_start;
int cpu = this_cpu();
if (elapsed > tcb->busywait_max)
{
tcb->busywait_max = elapsed;
tcb->busywait_max_caller = tcb->busywait_caller;
CHECK_BUSYWAIT(tcb->pid, elapsed);
}
/* Check for the global max elapsed time */
if (elapsed > g_busywait_max[cpu])
{
g_busywait_max[cpu] = elapsed;
}
/* Update thread-level and cpu-level busywait */
tcb->busywait_total += elapsed;
g_busywait_total[cpu] += elapsed;
}
}
#endif /* CONFIG_SCHED_CRITMONITOR_MAXTIME_BUSYWAIT >= 0 */
/****************************************************************************
* Name: nxsched_switch_critmon
*