• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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@us.ibm.com>
40  *
41  * HISTORY
42  *      2006-May-10: Initial version by Darren Hart <dvhltc@us.ibm.com>
43  *      2007-Jul-11: Quantiles added by Josh Triplett <josh@kernel.org>
44  *      2007-Jul-12: Latency tracing added by Josh Triplett <josh@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 
usage(void)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 
parse_args(int c,char * v)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 
periodic_thread(void * arg)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 
main(int argc,char * argv[])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