latencytop.c revision 10883:12fb4fb507d6
1/*
2 * CDDL HEADER START
3 *
4 * The contents of this file are subject to the terms of the
5 * Common Development and Distribution License (the "License").
6 * You may not use this file except in compliance with the License.
7 *
8 * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
9 * or http://www.opensolaris.org/os/licensing.
10 * See the License for the specific language governing permissions
11 * and limitations under the License.
12 *
13 * When distributing Covered Code, include this CDDL HEADER in each
14 * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
15 * If applicable, add the following below this CDDL HEADER, with the
16 * fields enclosed by brackets "[]" replaced with your own identifying
17 * information: Portions Copyright [yyyy] [name of copyright owner]
18 *
19 * CDDL HEADER END
20 */
21/*
22 * Copyright (c) 2008-2009, Intel Corporation.
23 * All Rights Reserved.
24 */
25
26#include <unistd.h>
27#include <getopt.h>
28#include <stdio.h>
29#include <string.h>
30#include <stdlib.h>
31#include <limits.h>
32#include <libgen.h>
33#include <signal.h>
34#include "latencytop.h"
35
36#define	CMPOPT(a, b)	strncmp((a), (b), sizeof (b))
37
38/*
39 * This variable is used to check if "dynamic variable drop" in dtrace
40 * has happened.
41 */
42boolean_t lt_drop_detected = 0;
43
44lt_config_t g_config;
45
46typedef enum {
47	LT_CMDOPT_INTERVAL,
48	LT_CMDOPT_LOG_FILE,
49	LT_CMDOPT_LOG_LEVEL,
50	LT_CMDOPT_LOG_INTERVAL,
51	LT_CMDOPT_CONFIG_FILE,
52	LT_CMDOPT_F_FILTER,
53	LT_CMDOPT_F_SCHED,
54	LT_CMDOPT_F_SOBJ,
55	LT_CMDOPT_F_LOW,
56	LT_CMDOPT__LAST	/* Must be last one */
57} lt_cmd_option_id_t;
58
59/*
60 * Check for duplicate command line options.
61 * Returns TRUE if duplicate options with different values are found,
62 * returns FALSE otherwise.
63 */
64static int
65check_opt_dup(lt_cmd_option_id_t id, uint64_t value) {
66
67	static int opt_set[(int)LT_CMDOPT__LAST];
68	static uint64_t opt_val[(int)LT_CMDOPT__LAST];
69
70	const char *errmsg[] = {
71		"-t is set more than once with different values.",
72		"-o is set more than once.",
73		"-k is set more than once with different values.",
74		"-l is set more than once with different values.",
75		"-c is set more than once.",
76		"-f [no]filter is set more than once with different values.",
77		"-f [no]sched is set more than once with different values.",
78		"-f [no]sobj is set more than once with different values.",
79		"-f [no]low is set more than once with different values.",
80	};
81
82	g_assert(sizeof (errmsg)/sizeof (errmsg[0]) == (int)LT_CMDOPT__LAST);
83
84	if (!opt_set[(int)id]) {
85		opt_set[(int)id] = TRUE;
86		opt_val[(int)id] = value;
87		return (FALSE);
88	}
89
90	if (opt_val[(int)id] != value) {
91		(void) fprintf(stderr, "%s\n", errmsg[(int)id]);
92		return (TRUE);
93	}
94
95	return (FALSE);
96}
97
98/*
99 * Print command-line help message.
100 */
101static void
102print_usage(const char *execname, int long_help)
103{
104	char buffer[PATH_MAX];
105	(void) snprintf(buffer, sizeof (buffer), "%s", execname);
106
107	if (!long_help) {
108		/* Print short help to stderr. */
109		(void) fprintf(stderr, "Usage: %s [option(s)], ",
110		    basename(buffer));
111		(void) fprintf(stderr, "use '%s -h' for details.\n",
112		    basename(buffer));
113		return;
114	}
115
116	(void) printf("Usage: %s [option(s)]\n", basename(buffer));
117	(void) printf("Options:\n"
118	    "    -h, --help\n"
119	    "        Print this help.\n"
120	    "    -t, --interval TIME\n"
121	    "        Set refresh interval to TIME. "
122	    "Valid range [1...60] seconds, default = 5\n"
123	/*
124	 * Option "-c, --config FILE" is not user-visible for now.
125	 * When we have chance to properly document the format of translation
126	 * rules, we'll make it user-visible.
127	 */
128	    "    -o, --output-log-file FILE\n"
129	    "        Output kernel log to FILE. Default = "
130	    DEFAULT_KLOG_FILE "\n"
131	    "    -k, --kernel-log-level LEVEL\n"
132	    "        Set kernel log level to LEVEL.\n"
133	    "        0(default) = None, 1 = Unmapped, 2 = Mapped, 3 = All.\n"
134	    "    -f, --feature [no]feature1,[no]feature2,...\n"
135	    "        Enable/disable features in LatencyTOP.\n"
136	    "        [no]filter:\n"
137	    "        Filter large interruptible latencies, e.g. sleep.\n"
138	    "        [no]sched:\n"
139	    "        Monitors sched (PID=0).\n"
140	    "        [no]sobj:\n"
141	    "        Monitors synchronization objects.\n"
142	    "        [no]low:\n"
143	    "        Lower overhead by sampling small latencies.\n"
144	    "    -l, --log-period TIME\n"
145	    "        Write and restart log every TIME seconds, TIME >= 60\n");
146}
147
148/*
149 * Properly exit latencytop when it receives SIGINT or SIGTERM.
150 */
151/* ARGSUSED */
152static void
153signal_handler(int sig)
154{
155	lt_gpipe_break("q");
156}
157
158/*
159 * Convert string to integer. It returns error if extra characters are found.
160 */
161static int
162to_int(const char *str, int *result)
163{
164	char *tail = NULL;
165	long ret;
166
167	if (str == NULL || result == NULL) {
168		return (-1);
169	}
170
171	ret = strtol(str, &tail, 10);
172
173	if (tail != NULL && *tail != '\0') {
174		return (-1);
175	}
176
177	*result = (int)ret;
178
179	return (0);
180}
181
182/*
183 * The main function.
184 */
185int
186main(int argc, char *argv[])
187{
188	const char *opt_string = "t:o:k:hf:l:c:";
189	struct option const longopts[] = {
190		{"interval", required_argument, NULL, 't'},
191		{"output-log-file", required_argument, NULL, 'o'},
192		{"kernel-log-level", required_argument, NULL, 'k'},
193		{"help", no_argument, NULL, 'h'},
194		{"feature", required_argument, NULL, 'f'},
195		{"log-period", required_argument, NULL, 'l'},
196		{"config", required_argument, NULL, 'c'},
197		{NULL, 0, NULL, 0}
198	};
199
200	int optc;
201	int longind = 0;
202	int running = 1;
203	int unknown_option = FALSE;
204	int refresh_interval = 5;
205	int klog_level = 0;
206	int log_interval = 0;
207	long long last_logged = 0;
208	char *token = NULL;
209	int retval = 0;
210	int gpipe;
211	int err;
212	uint64_t collect_end;
213	uint64_t current_time;
214	uint64_t delta_time;
215	char logfile[PATH_MAX] = "";
216	boolean_t no_dtrace_cleanup = B_TRUE;
217
218	lt_gpipe_init();
219	(void) signal(SIGINT, signal_handler);
220	(void) signal(SIGTERM, signal_handler);
221
222	/* Default global settings */
223	g_config.lt_cfg_enable_filter = 0;
224	g_config.lt_cfg_trace_sched = 0;
225	g_config.lt_cfg_trace_syncobj = 1;
226	g_config.lt_cfg_low_overhead_mode = 0;
227	/* dtrace snapshot every 1 second */
228	g_config.lt_cfg_snap_interval = 1000;
229#ifdef EMBED_CONFIGS
230	g_config.lt_cfg_config_name = NULL;
231#else
232	g_config.lt_cfg_config_name = lt_strdup(DEFAULT_CONFIG_NAME);
233#endif
234
235	/* Parse command line arguments. */
236	while ((optc = getopt_long(argc, argv, opt_string,
237	    longopts, &longind)) != -1) {
238		switch (optc) {
239		case 'h':
240			print_usage(argv[0], TRUE);
241			goto end_none;
242		case 't':
243			if (to_int(optarg, &refresh_interval) != 0 ||
244			    refresh_interval < 1 || refresh_interval > 60) {
245				lt_display_error(
246				    "Invalid refresh interval: %s\n", optarg);
247				unknown_option = TRUE;
248			} else if (check_opt_dup(LT_CMDOPT_INTERVAL,
249			    refresh_interval)) {
250				unknown_option = TRUE;
251			}
252
253			break;
254		case 'k':
255			if (to_int(optarg, &klog_level) != 0 ||
256			    lt_klog_set_log_level(klog_level) != 0) {
257				lt_display_error(
258				    "Invalid log level: %s\n", optarg);
259				unknown_option = TRUE;
260			} else if (check_opt_dup(LT_CMDOPT_LOG_LEVEL,
261			    refresh_interval)) {
262				unknown_option = TRUE;
263			}
264
265			break;
266		case 'o':
267			if (check_opt_dup(LT_CMDOPT_LOG_FILE, optind)) {
268				unknown_option = TRUE;
269			} else if (strlen(optarg) >= sizeof (logfile)) {
270				lt_display_error(
271				    "Log file name is too long: %s\n",
272				    optarg);
273				unknown_option = TRUE;
274			} else {
275				(void) strncpy(logfile, optarg,
276				    sizeof (logfile));
277			}
278
279			break;
280		case 'f':
281			for (token = strtok(optarg, ","); token != NULL;
282			    token = strtok(NULL, ",")) {
283				int v = TRUE;
284
285				if (strncmp(token, "no", 2) == 0) {
286					v = FALSE;
287					token = &token[2];
288				}
289
290				if (CMPOPT(token, "filter") == 0) {
291					if (check_opt_dup(LT_CMDOPT_F_FILTER,
292					    v)) {
293						unknown_option = TRUE;
294					} else {
295						g_config.lt_cfg_enable_filter
296						    = v;
297					}
298				} else if (CMPOPT(token, "sched") == 0) {
299					if (check_opt_dup(LT_CMDOPT_F_SCHED,
300					    v)) {
301						unknown_option = TRUE;
302					} else {
303						g_config.lt_cfg_trace_sched
304						    = v;
305					}
306				} else if (CMPOPT(token, "sobj") == 0) {
307					if (check_opt_dup(LT_CMDOPT_F_SOBJ,
308					    v)) {
309						unknown_option = TRUE;
310					} else {
311						g_config.lt_cfg_trace_syncobj
312						    = v;
313					}
314				} else if (CMPOPT(token, "low") == 0) {
315					if (check_opt_dup(LT_CMDOPT_F_LOW,
316					    v)) {
317						unknown_option = TRUE;
318					} else {
319						g_config.
320						    lt_cfg_low_overhead_mode
321						    = v;
322					}
323				} else {
324					lt_display_error(
325					    "Unknown feature: %s\n", token);
326					unknown_option = TRUE;
327				}
328			}
329
330			break;
331		case 'l':
332			if (to_int(optarg, &log_interval) != 0 ||
333			    log_interval < 60) {
334				lt_display_error(
335				    "Invalid log interval: %s\n", optarg);
336				unknown_option = TRUE;
337			} else if (check_opt_dup(LT_CMDOPT_LOG_INTERVAL,
338			    log_interval)) {
339				unknown_option = TRUE;
340			}
341
342			break;
343		case 'c':
344			if (strlen(optarg) >= PATH_MAX) {
345				lt_display_error(
346				    "Configuration name is too long.\n");
347				unknown_option = TRUE;
348			} else if (check_opt_dup(LT_CMDOPT_CONFIG_FILE,
349			    optind)) {
350				unknown_option = TRUE;
351			} else {
352				g_config.lt_cfg_config_name =
353				    lt_strdup(optarg);
354			}
355
356			break;
357		default:
358			unknown_option = TRUE;
359			break;
360		}
361	}
362
363	if (!unknown_option && strlen(logfile) > 0) {
364		err = lt_klog_set_log_file(logfile);
365
366		if (err == -1) {
367			lt_display_error("Log file name is too long: %s\n",
368			    logfile);
369			unknown_option = TRUE;
370		} else if (err == -2) {
371			lt_display_error("Cannot write to log file: %s\n",
372			    logfile);
373			unknown_option = TRUE;
374		}
375	}
376
377	/* Throw error for invalid/junk arguments */
378	if (optind  < argc) {
379		int tmpind = optind;
380		(void) fprintf(stderr, "Unknown option(s): ");
381
382		while (tmpind < argc) {
383			(void) fprintf(stderr, "%s ", argv[tmpind++]);
384		}
385
386		(void) fprintf(stderr, "\n");
387		unknown_option = TRUE;
388	}
389
390	if (unknown_option) {
391		print_usage(argv[0], FALSE);
392		retval = 1;
393		goto end_none;
394	}
395
396	(void) printf("%s\n%s\n", TITLE, COPYRIGHT);
397
398	/*
399	 * Initialization
400	 */
401	lt_klog_init();
402
403	if (lt_table_init() != 0) {
404		lt_display_error("Unable to load configuration table.\n");
405		retval = 1;
406		goto end_notable;
407	}
408
409	if (lt_dtrace_init() != 0) {
410		lt_display_error("Unable to initialize dtrace.\n");
411		retval = 1;
412		goto end_nodtrace;
413	}
414
415	last_logged = lt_millisecond();
416
417	(void) printf("Collecting data for %d seconds...\n",
418	    refresh_interval);
419
420	gpipe = lt_gpipe_readfd();
421	collect_end = last_logged + refresh_interval * 1000;
422	for (;;) {
423		fd_set read_fd;
424		struct timeval timeout;
425		int tsleep = collect_end - lt_millisecond();
426
427		if (tsleep <= 0) {
428			break;
429		}
430
431		/*
432		 * Interval when we call dtrace_status() and collect
433		 * aggregated data.
434		 */
435		if (tsleep > g_config.lt_cfg_snap_interval) {
436			tsleep = g_config.lt_cfg_snap_interval;
437		}
438
439		timeout.tv_sec = tsleep / 1000;
440		timeout.tv_usec = (tsleep % 1000) * 1000;
441
442		FD_ZERO(&read_fd);
443		FD_SET(gpipe, &read_fd);
444
445		if (select(gpipe + 1, &read_fd, NULL, NULL, &timeout) > 0) {
446			goto end_ubreak;
447		}
448
449		(void) lt_dtrace_work(0);
450	}
451
452	lt_display_init();
453
454	do {
455		current_time = lt_millisecond();
456
457		lt_stat_clear_all();
458		(void) lt_dtrace_collect();
459
460		delta_time = current_time;
461		current_time = lt_millisecond();
462		delta_time = current_time - delta_time;
463
464		if (log_interval > 0 &&
465		    current_time - last_logged > log_interval * 1000) {
466			lt_klog_write();
467			last_logged = current_time;
468		}
469
470		running = lt_display_loop(refresh_interval * 1000 -
471		    delta_time);
472
473		/*
474		 * This is to avoid dynamic variable drop
475		 * in DTrace.
476		 */
477		if (lt_drop_detected == B_TRUE) {
478			if (lt_dtrace_deinit() != 0) {
479				no_dtrace_cleanup = B_FALSE;
480				retval = 1;
481				break;
482			}
483
484			lt_drop_detected = B_FALSE;
485			if (lt_dtrace_init() != 0) {
486				retval = 1;
487				break;
488			}
489		}
490	} while (running != 0);
491
492	lt_klog_write();
493
494	/* Cleanup */
495	lt_display_deinit();
496
497end_ubreak:
498	if (no_dtrace_cleanup == B_FALSE || lt_dtrace_deinit() != 0)
499		retval = 1;
500
501	lt_stat_free_all();
502
503end_nodtrace:
504	lt_table_deinit();
505
506end_notable:
507	lt_klog_deinit();
508
509end_none:
510	lt_gpipe_deinit();
511
512	if (g_config.lt_cfg_config_name != NULL) {
513		free(g_config.lt_cfg_config_name);
514	}
515
516	return (retval);
517}
518