1 /****************************************************************************** 2 * 3 * Copyright International Business Machines Corp., 2006-2008 4 * 5 * This program is free software; you can redistribute it and/or modify 6 * it under the terms of the GNU General Public License as published by 7 * the Free Software Foundation; either version 2 of the License, or 8 * (at your option) any later version. 9 * 10 * This program is distributed in the hope that it will be useful, 11 * but WITHOUT ANY WARRANTY; without even the implied warranty of 12 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See 13 * the GNU General Public License for more details. 14 * 15 * You should have received a copy of the GNU General Public License 16 * along with this program; if not, write to the Free Software 17 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA 18 * 19 * NAME 20 * sched_latency.c 21 * 22 * DESCRIPTION 23 * Measure the latency involved with periodic scheduling. 24 * Steps: 25 * - A thread is created at a priority of 89. 26 * - It periodically sleeps for a specified duration(period). 27 * - The delay is measured as 28 * 29 * delay = (now - start - i*period) converted to microseconds 30 * 31 * where, 32 * now = CLOCK_MONOTONIC gettime in ns, start = CLOCK_MONOTONIC gettime 33 * at the start of the test, i = iteration number, period = period chosen 34 * 35 * USAGE: 36 * Use run_auto.sh script in current directory to build and run test. 37 * 38 * AUTHOR 39 * Darren Hart <dvhltc (at) us.ibm.com> 40 * 41 * HISTORY 42 * 2006-May-10: Initial version by Darren Hart <dvhltc (at) us.ibm.com> 43 * 2007-Jul-11: Quantiles added by Josh Triplett <josh (at) kernel.org> 44 * 2007-Jul-12: Latency tracing added by Josh Triplett <josh (at) kernel.org> 45 * 46 * This line has to be added to avoid a stupid CVS problem 47 *****************************************************************************/ 48 49 #include <stdio.h> 50 #include <stdlib.h> 51 #include <math.h> 52 #include <librttest.h> 53 #include <libstats.h> 54 55 #define PRIO 89 56 //#define PERIOD 17*NS_PER_MS 57 //#define ITERATIONS 100 58 #define MIN_ITERATIONS 100 59 #define DEFAULT_ITERATIONS 10000 60 #define DEF_PERIOD 5*NS_PER_MS 61 #define DEF_LOAD_MS 1 62 #define PASS_US 100 63 #define HIST_BUCKETS 100 64 #define OVERHEAD 50000 // allow for 50 us of periodic overhead (context switch, etc.) 65 66 nsec_t start; 67 nsec_t end; 68 static int ret = 0; 69 static int iterations = 0; 70 static unsigned long long latency_threshold = 0; 71 static nsec_t period = DEF_PERIOD; 72 static unsigned int load_ms = DEF_LOAD_MS; 73 74 stats_container_t dat; 75 stats_container_t hist; 76 stats_quantiles_t quantiles; 77 stats_record_t rec; 78 79 void usage(void) 80 { 81 rt_help(); 82 printf("sched_latency specific options:\n"); 83 printf(" -dLOAD periodic load in ms (default 1)\n"); 84 printf(" -lTHRESHOLD trace latency, with given threshold in us\n"); 85 printf(" -tPERIOD period in ms (default 5)\n"); 86 printf(" -iITERATIONS number of iterations (default %d)\n", 87 DEFAULT_ITERATIONS); 88 } 89 90 int parse_args(int c, char *v) 91 { 92 93 int handled = 1; 94 switch (c) { 95 case 'h': 96 usage(); 97 exit(0); 98 case 'd': 99 load_ms = atoi(v); 100 break; 101 case 'i': 102 iterations = atoi(v); 103 break; 104 case 'l': 105 latency_threshold = strtoull(v, NULL, 0); 106 break; 107 case 't': 108 period = strtoull(v, NULL, 0) * NS_PER_MS; 109 break; 110 default: 111 handled = 0; 112 break; 113 } 114 return handled; 115 } 116 117 void *periodic_thread(void *arg) 118 { 119 int i; 120 nsec_t delay, avg_delay = 0, start_delay, min_delay = -1ULL, max_delay = 121 0; 122 int failures = 0; 123 nsec_t next = 0, now = 0, sched_delta = 0, delta = 0, prev = 124 0, iter_start; 125 126 /* wait for the specified start time */ 127 rt_nanosleep_until(start); 128 129 now = rt_gettime(); 130 start_delay = (now - start) / NS_PER_US; 131 iter_start = next = now; 132 133 debug(DBG_INFO, "ITERATION DELAY(US) MAX_DELAY(US) FAILURES\n"); 134 debug(DBG_INFO, "--------- --------- ------------- --------\n"); 135 136 if (latency_threshold) { 137 latency_trace_enable(); 138 latency_trace_start(); 139 } 140 for (i = 0; i < iterations; i++) { 141 /* wait for the period to start */ 142 next += period; 143 prev = now; 144 now = rt_gettime(); 145 146 if (next < now) { 147 printf("\nPERIOD MISSED!\n"); 148 printf(" scheduled delta: %8llu us\n", 149 sched_delta / 1000); 150 printf(" actual delta: %8llu us\n", 151 delta / 1000); 152 printf(" latency: %8llu us\n", 153 (delta - sched_delta) / 1000); 154 printf("---------------------------------------\n"); 155 printf(" previous start: %8llu us\n", 156 (prev - iter_start) / 1000); 157 printf(" now: %8llu us\n", 158 (now - iter_start) / 1000); 159 printf(" scheduled start: %8llu us\n", 160 (next - iter_start) / 1000); 161 printf("next scheduled start is in the past!\n"); 162 ret = 1; 163 break; 164 } 165 166 sched_delta = next - now; /* how long we should sleep */ 167 delta = 0; 168 do { 169 nsec_t new_now; 170 171 rt_nanosleep(next - now); 172 new_now = rt_gettime(); 173 delta += new_now - now; /* how long we did sleep */ 174 now = new_now; 175 } while (now < next); 176 177 /* start of period */ 178 delay = 179 (now - iter_start - (nsec_t) (i + 1) * period) / NS_PER_US; 180 rec.x = i; 181 rec.y = delay; 182 stats_container_append(&dat, rec); 183 184 if (delay < min_delay) 185 min_delay = delay; 186 if (delay > max_delay) 187 max_delay = delay; 188 if (delay > pass_criteria) { 189 failures++; 190 ret = 1; 191 } 192 avg_delay += delay; 193 if (latency_threshold && delay > latency_threshold) 194 break; 195 196 /* continuous status ticker */ 197 debug(DBG_INFO, "%9i %9llu %13llu %8i\r", i, delay, max_delay, 198 failures); 199 fflush(stdout); 200 201 busy_work_ms(load_ms); 202 } 203 if (latency_threshold) { 204 latency_trace_stop(); 205 if (i != iterations) { 206 printf 207 ("Latency threshold (%lluus) exceeded at iteration %d\n", 208 latency_threshold, i); 209 latency_trace_print(); 210 stats_container_resize(&dat, i + 1); 211 } 212 } 213 214 /* save samples before the quantile calculation messes things up! */ 215 stats_hist(&hist, &dat); 216 stats_container_save("samples", 217 "Periodic Scheduling Latency Scatter Plot", 218 "Iteration", "Latency (us)", &dat, "points"); 219 stats_container_save("hist", "Periodic Scheduling Latency Histogram", 220 "Latency (us)", "Samples", &hist, "steps"); 221 222 avg_delay /= i; 223 printf("\n\n"); 224 printf("Start: %4llu us: %s\n", start_delay, 225 start_delay < pass_criteria ? "PASS" : "FAIL"); 226 printf("Min: %4llu us: %s\n", min_delay, 227 min_delay < pass_criteria ? "PASS" : "FAIL"); 228 printf("Max: %4llu us: %s\n", max_delay, 229 max_delay < pass_criteria ? "PASS" : "FAIL"); 230 printf("Avg: %4llu us: %s\n", avg_delay, 231 avg_delay < pass_criteria ? "PASS" : "FAIL"); 232 printf("StdDev: %.4f us\n", stats_stddev(&dat)); 233 printf("Quantiles:\n"); 234 stats_quantiles_calc(&dat, &quantiles); 235 stats_quantiles_print(&quantiles); 236 printf("Failed Iterations: %d\n", failures); 237 238 return NULL; 239 } 240 241 int main(int argc, char *argv[]) 242 { 243 int per_id; 244 setup(); 245 246 pass_criteria = PASS_US; 247 rt_init("d:l:ht:i:", parse_args, argc, argv); 248 249 printf("-------------------------------\n"); 250 printf("Scheduling Latency\n"); 251 printf("-------------------------------\n\n"); 252 253 if (load_ms * NS_PER_MS >= period - OVERHEAD) { 254 printf("ERROR: load must be < period - %d us\n", 255 OVERHEAD / NS_PER_US); 256 exit(1); 257 } 258 259 if (iterations == 0) 260 iterations = DEFAULT_ITERATIONS; 261 if (iterations < MIN_ITERATIONS) { 262 printf 263 ("Too few iterations (%d), use min iteration instead (%d)\n", 264 iterations, MIN_ITERATIONS); 265 iterations = MIN_ITERATIONS; 266 } 267 268 printf("Running %d iterations with a period of %llu ms\n", iterations, 269 period / NS_PER_MS); 270 printf("Periodic load duration: %d ms\n", load_ms); 271 printf("Expected running time: %d s\n", 272 (int)(iterations * ((float)period / NS_PER_SEC))); 273 274 if (stats_container_init(&dat, iterations)) 275 exit(1); 276 277 if (stats_container_init(&hist, HIST_BUCKETS)) { 278 stats_container_free(&dat); 279 exit(1); 280 } 281 282 /* use the highest value for the quantiles */ 283 if (stats_quantiles_init(&quantiles, (int)log10(iterations))) { 284 stats_container_free(&hist); 285 stats_container_free(&dat); 286 exit(1); 287 } 288 289 /* wait one quarter second to execute */ 290 start = rt_gettime() + 250 * NS_PER_MS; 291 per_id = create_fifo_thread(periodic_thread, NULL, PRIO); 292 293 join_thread(per_id); 294 join_threads(); 295 296 printf("\nCriteria: latencies < %d us\n", (int)pass_criteria); 297 printf("Result: %s\n", ret ? "FAIL" : "PASS"); 298 299 stats_container_free(&dat); 300 stats_container_free(&hist); 301 stats_quantiles_free(&quantiles); 302 303 return ret; 304 } 305
