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
66nsec_t start;
67nsec_t end;
68static int ret = 0;
69static int iterations = 0;
70static unsigned long long latency_threshold = 0;
71static nsec_t period = DEF_PERIOD;
72static unsigned int load_ms = DEF_LOAD_MS;
73
74stats_container_t dat;
75stats_container_t hist;
76stats_quantiles_t quantiles;
77stats_record_t rec;
78
79void 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
90int 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
117void *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
241int 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