* [RFC PATCH] Add a feature to record spikes
@ 2015-10-21 13:14 John Kacur
0 siblings, 0 replies; only message in thread
From: John Kacur @ 2015-10-21 13:14 UTC (permalink / raw)
To: linux-rt-users; +Cc: Clark Williams
The idea of recording the time stamp everytime the latency spikes belongs
to Clark Williams.
The blame for the implementation is all mine. Consider this a prototype
for now, but it is useable.
>From 96b5aca222e7b4ea8159c16ba1b9f6a7661f224b Mon Sep 17 00:00:00 2001
From: John Kacur <jkacur@redhat.com>
Date: Wed, 21 Oct 2015 13:34:13 +0200
Subject: [PATCH] cyclictest: Add a feature to record spikes
Create a linked-list of data, including a time stamp, that is
recorded everytime a latency measurement is above a given number (trigger).
This data is printed out at the end of a run. If we have
more spikes than we have allocated nodes in our list for, we stop
recording the data, but keep counting the number of spikes.
This introduces two new long options.
--spike=trigger, where the trigger is given in usec. Any time a
spike > trigger occurs we record the data.
--spike-nodes=num_of_nodes, is the amount of data we can record, the
default is 1024
Here is what a sample run looks like. (non-rt kernel)
su -c './cyclictest -t4 -p99 --spike=30 --duration=60'
Password:
policy: fifo: loadavg: 0.69 0.78 0.60 1/641 6420
T: 0 ( 6385) P:99 I:1000 C: 59996 Min: 2 Act: 2 Avg: 2 Max:
1476
T: 1 ( 6386) P:99 I:1500 C: 39999 Min: 1 Act: 2 Avg: 2 Max:
952
T: 2 ( 6387) P:99 I:2000 C: 29999 Min: 2 Act: 2 Avg: 3 Max:
504
T: 3 ( 6388) P:99 I:2500 C: 23999 Min: 1 Act: 2 Avg: 2 Max:
1423
T: 2 Spike: 504: TS: 490531620
T: 2 Spike: 270: TS: 526847386
T: 2 Spike: 51: TS: 527211167
T: 2 Spike: 44: TS: 528261160
T: 1 Spike: 31: TS: 528952631
T: 2 Spike: 32: TS: 529253148
T: 2 Spike: 52: TS: 529317169
T: 0 Spike: 1444: TS: 530049519
T: 1 Spike: 419: TS: 530049520
T: 0 Spike: 1476: TS: 530318551
T: 1 Spike: 952: TS: 530318553
T: 3 Spike: 1423: TS: 530318551
T: 0 Spike: 972: TS: 531532046
T: 0 Spike: 34: TS: 531987109
spikes = 14
Signed-off-by: John Kacur <jkacur@redhat.com>
---
src/cyclictest/cyclictest.c | 114 +++++++++++++++++++++++++++++++++++++++++++-
1 file changed, 112 insertions(+), 2 deletions(-)
diff --git a/src/cyclictest/cyclictest.c b/src/cyclictest/cyclictest.c
index 00168e22fc7f..a208165ac034 100644
--- a/src/cyclictest/cyclictest.c
+++ b/src/cyclictest/cyclictest.c
@@ -173,6 +173,29 @@ struct thread_stat {
long num_outliers;
};
+static pthread_mutex_t trigger_lock = PTHREAD_MUTEX_INITIALIZER;
+
+static int trigger = 0; /* Record spikes > trigger, 0 means don't record */
+static int trigger_list_size = 1024; /* Number of list nodes */
+
+/* Info to store when the diff is greater than the trigger */
+struct thread_trigger {
+ int cpu;
+ int tnum; /* thread number */
+ int64_t ts; /* time-stamp */
+ int diff;
+ struct thread_trigger *next;
+};
+
+struct thread_trigger *head = NULL;
+struct thread_trigger *tail = NULL;
+struct thread_trigger *current = NULL;
+static int spikes; /* count of the number of spikes */
+
+static int trigger_init();
+static void trigger_print();
+static void trigger_update(struct thread_param *par, int diff, int64_t ts);
+
static int shutdown;
static int tracelimit = 0;
static int notrace = 0;
@@ -405,6 +428,14 @@ static inline int64_t calcdiff_ns(struct timespec t1, struct timespec t2)
return diff;
}
+static inline int64_t calctime(struct timespec t)
+{
+ int64_t time;
+ time = USEC_PER_SEC * t.tv_sec;
+ time += ((int) t.tv_nsec) / 1000;
+ return time;
+}
+
static void traceopt(char *option)
{
char *ptr;
@@ -950,6 +981,10 @@ static void *timerthread(void *param)
}
stat->avg += (double) diff;
+ if (trigger && (diff > trigger)) {
+ trigger_update(par, diff, calctime(now));
+ }
+
if (duration && (calcdiff(now, stop) >= 0))
shutdown++;
@@ -1103,6 +1138,9 @@ static void display_help(int error)
"-s --system use sys_nanosleep and sys_setitimer\n"
"-S --smp Standard SMP testing: options -a -t -n and\n"
" same priority of all threads\n"
+ " --spike=trigger record all spikes > trigger\n"
+ " --spike-nodes these are the number of spikes we can record\n"
+ " the default is 1024 if not specified\n"
"-t --threads one thread per available processor\n"
"-t [NUM] --threads=NUM number of threads:\n"
" without NUM, threads = max_cpus\n"
@@ -1246,8 +1284,8 @@ enum option_values {
OPT_INTERVAL, OPT_IRQSOFF, OPT_LOOPS, OPT_MLOCKALL, OPT_REFRESH, OPT_NANOSLEEP,
OPT_NSECS, OPT_OSCOPE, OPT_TRACEOPT, OPT_PRIORITY, OPT_PREEMPTOFF, OPT_QUIET,
OPT_PRIOSPREAD, OPT_RELATIVE, OPT_RESOLUTION, OPT_SYSTEM, OPT_SMP, OPT_THREADS,
- OPT_TRACER, OPT_UNBUFFERED, OPT_NUMA, OPT_VERBOSE, OPT_WAKEUP, OPT_WAKEUPRT,
- OPT_DBGCYCLIC, OPT_POLICY, OPT_HELP, OPT_NUMOPTS,
+ OPT_TRACER, OPT_TRIGGER, OPT_TRIGGER_NODES, OPT_UNBUFFERED, OPT_NUMA, OPT_VERBOSE,
+ OPT_WAKEUP, OPT_WAKEUPRT, OPT_DBGCYCLIC, OPT_POLICY, OPT_HELP, OPT_NUMOPTS,
#ifndef NO_PTHREAD_BARRIER
OPT_ALIGNED, OPT_SECALIGNED,
#endif
@@ -1306,6 +1344,8 @@ static void process_options (int argc, char *argv[], int max_cpus)
#endif
{"system", no_argument, NULL, OPT_SYSTEM },
{"smp", no_argument, NULL, OPT_SMP },
+ {"spike", required_argument, NULL, OPT_TRIGGER },
+ {"spike-nodes", required_argument, NULL, OPT_TRIGGER_NODES },
{"threads", optional_argument, NULL, OPT_THREADS },
{"tracer", required_argument, NULL, OPT_TRACER },
{"unbuffered", no_argument, NULL, OPT_UNBUFFERED },
@@ -1485,6 +1525,13 @@ static void process_options (int argc, char *argv[], int max_cpus)
else
num_threads = max_cpus;
break;
+ case OPT_TRIGGER:
+ trigger = atoi(optarg);
+ break;
+ case OPT_TRIGGER_NODES:
+ if (trigger)
+ trigger_list_size = atoi(optarg);
+ break;
case 'T':
case OPT_TRACER:
tracetype = CUSTOM;
@@ -1853,6 +1900,58 @@ static void *fifothread(void *param)
return NULL;
}
+static int trigger_init()
+{
+ int i;
+ int size = trigger_list_size;
+ struct thread_trigger *trig = NULL;
+ for(i=0; i<size; i++) {
+ trig = malloc(sizeof(struct thread_trigger));
+ if (trig != NULL) {
+ if (head == NULL) {
+ head = trig;
+ tail = trig;
+ } else {
+ tail->next = trig;
+ tail = trig;
+ }
+ trig->tnum = i;
+ trig->next = NULL;
+ } else {
+ return -1;
+ }
+ }
+ current = head;
+ return 0;
+}
+
+static void trigger_print()
+{
+ struct thread_trigger *trig = head;
+ char *fmt = "T:%2d Spike:%8ld: TS: %12ld\n";
+
+ if (current == head) return;
+ printf("\n");
+ while (trig->next != current) {
+ fprintf(stdout, fmt, trig->tnum, trig->diff, trig->ts);
+ trig = trig->next;
+ }
+ fprintf(stdout, fmt, trig->tnum, trig->diff, trig->ts);
+ printf("spikes = %d\n\n", spikes);
+}
+
+static void trigger_update(struct thread_param *par, int diff, int64_t ts)
+{
+ pthread_mutex_lock(&trigger_lock);
+ if (current != NULL) {
+ current->tnum = par->tnum;
+ current->ts = ts;
+ current->diff = diff;
+ current = current->next;
+ }
+ spikes++;
+ pthread_mutex_unlock(&trigger_lock);
+}
int main(int argc, char **argv)
{
@@ -1871,6 +1970,14 @@ int main(int argc, char **argv)
if (verbose)
printf("Max CPUs = %d\n", max_cpus);
+ if (trigger) {
+ int retval;
+ retval = trigger_init();
+ if (retval != 0) {
+ fprintf(stderr, "trigger_init() failed\n");
+ exit(EXIT_FAILURE);
+ }
+ }
/* lock all memory (prevent swapping) */
if (lockall)
@@ -2189,6 +2296,9 @@ int main(int argc, char **argv)
threadfree(statistics[i]->values, VALBUF_SIZE*sizeof(long), parameters[i]->node);
}
+ if (trigger)
+ trigger_print();
+
if (histogram) {
print_hist(parameters, num_threads);
for (i = 0; i < num_threads; i++) {
--
2.4.3
^ permalink raw reply related [flat|nested] only message in thread
only message in thread, other threads:[~2015-10-21 13:14 UTC | newest]
Thread overview: (only message) (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2015-10-21 13:14 [RFC PATCH] Add a feature to record spikes John Kacur
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.