diff --git a/include/common/time.h b/include/common/time.h index d4446dc14..a1664b491 100644 --- a/include/common/time.h +++ b/include/common/time.h @@ -63,6 +63,8 @@ extern THREAD_LOCAL struct timeval date; /* the real current date */ extern struct timeval start_date; /* the process's start date */ extern THREAD_LOCAL struct timeval before_poll; /* system date before calling poll() */ extern THREAD_LOCAL struct timeval after_poll; /* system date after leaving poll() */ +extern THREAD_LOCAL uint64_t prev_cpu_time; /* previous per thread CPU time */ +extern THREAD_LOCAL uint64_t prev_mono_time; /* previous system wide monotonic time */ /**** exported functions *************************************************/ @@ -83,6 +85,11 @@ REGPRM2 int tv_ms_cmp(const struct timeval *tv1, const struct timeval *tv2); */ REGPRM2 int tv_ms_cmp2(const struct timeval *tv1, const struct timeval *tv2); +/* Updates the current thread's statistics about stolen CPU time. The unit for + * is half-milliseconds. + */ +REGPRM1 void report_stolen_time(uint64_t stolen); + /**** general purpose functions and macros *******************************/ @@ -574,6 +581,26 @@ static inline void measure_idle() */ static inline void tv_entering_poll() { + uint64_t new_mono_time; + uint64_t new_cpu_time; + int64_t stolen; + + new_cpu_time = now_cpu_time(); + new_mono_time = now_mono_time(); + + if (prev_cpu_time && prev_mono_time) { + new_cpu_time -= prev_cpu_time; + new_mono_time -= prev_mono_time; + stolen = new_mono_time - new_cpu_time; + if (stolen >= 500000) { + stolen /= 500000; + /* more than half a millisecond difference might + * indicate an undesired preemption. + */ + report_stolen_time(stolen); + } + } + gettimeofday(&before_poll, NULL); } @@ -586,6 +613,8 @@ static inline void tv_leaving_poll(int timeout, int interrupted) { tv_update_date(timeout, interrupted); measure_idle(); + prev_cpu_time = now_cpu_time(); + prev_mono_time = now_mono_time(); } #endif /* _COMMON_TIME_H */ diff --git a/include/types/global.h b/include/types/global.h index 616e8d3e5..5262867df 100644 --- a/include/types/global.h +++ b/include/types/global.h @@ -195,6 +195,9 @@ struct activity { unsigned int stream; // calls to process_stream() unsigned int empty_rq; // calls to process_runnable_tasks() with nothing for the thread unsigned int long_rq; // process_runnable_tasks() left with tasks in the run queue + unsigned int cpust_total; // sum of half-ms stolen per thread + struct freq_ctr cpust_1s; // avg amount of half-ms stolen over last second + struct freq_ctr_period cpust_15s; // avg amount of half-ms stolen over last 15s char __pad[0]; // unused except to check remaining room char __end[0] __attribute__((aligned(64))); // align size to 64. }; diff --git a/src/cli.c b/src/cli.c index ed17aac77..07dce53bf 100644 --- a/src/cli.c +++ b/src/cli.c @@ -972,6 +972,9 @@ static int cli_io_handler_show_activity(struct appctx *appctx) chunk_appendf(&trash, "\nstream:"); for (thr = 0; thr < global.nbthread; thr++) chunk_appendf(&trash, " %u", activity[thr].stream); chunk_appendf(&trash, "\nempty_rq:"); for (thr = 0; thr < global.nbthread; thr++) chunk_appendf(&trash, " %u", activity[thr].empty_rq); chunk_appendf(&trash, "\nlong_rq:"); for (thr = 0; thr < global.nbthread; thr++) chunk_appendf(&trash, " %u", activity[thr].long_rq); + chunk_appendf(&trash, "\ncpust_tot:"); for (thr = 0; thr < global.nbthread; thr++) chunk_appendf(&trash, " %u", activity[thr].cpust_total/2); + chunk_appendf(&trash, "\ncpust_1s:"); for (thr = 0; thr < global.nbthread; thr++) chunk_appendf(&trash, " %u", read_freq_ctr(&activity[thr].cpust_1s)/2); + chunk_appendf(&trash, "\ncpust_15s:"); for (thr = 0; thr < global.nbthread; thr++) chunk_appendf(&trash, " %u", read_freq_ctr_period(&activity[thr].cpust_15s, 15000)/2); chunk_appendf(&trash, "\n"); diff --git a/src/time.c b/src/time.c index 0de69627c..b404b2581 100644 --- a/src/time.c +++ b/src/time.c @@ -10,12 +10,16 @@ * */ +#include +#include #include #include #include #include #include +#include +#include THREAD_LOCAL unsigned int ms_left_scaled; /* milliseconds left for current second (0..2^32-1) */ THREAD_LOCAL unsigned int now_ms; /* internal date in milliseconds (may wrap) */ @@ -27,6 +31,8 @@ THREAD_LOCAL struct timeval date; /* the real current date */ struct timeval start_date; /* the process's start date */ THREAD_LOCAL struct timeval before_poll; /* system date before calling poll() */ THREAD_LOCAL struct timeval after_poll; /* system date after leaving poll() */ +THREAD_LOCAL uint64_t prev_cpu_time = 0; /* previous per thread CPU time */ +THREAD_LOCAL uint64_t prev_mono_time = 0; /* previous system wide monotonic time */ static THREAD_LOCAL struct timeval tv_offset; /* per-thread time ofsset relative to global time */ volatile unsigned long long global_now; /* common date between all threads (32:32) */ @@ -258,6 +264,16 @@ REGPRM2 void tv_update_date(int max_wait, int interrupted) return; } +/* Updates the current thread's statistics about stolen CPU time. The unit for + * is half-milliseconds. + */ +REGPRM1 void report_stolen_time(uint64_t stolen) +{ + activity[tid].cpust_total += stolen; + update_freq_ctr(&activity[tid].cpust_1s, stolen); + update_freq_ctr_period(&activity[tid].cpust_15s, 15000, stolen); +} + /* * Local variables: * c-indent-level: 8