xref: /onnv-gate/usr/src/cmd/filebench/common/misc.c (revision 6212:d9dcad6dd79c)
15184Sek110237 /*
25184Sek110237  * CDDL HEADER START
35184Sek110237  *
45184Sek110237  * The contents of this file are subject to the terms of the
55184Sek110237  * Common Development and Distribution License (the "License").
65184Sek110237  * You may not use this file except in compliance with the License.
75184Sek110237  *
85184Sek110237  * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
95184Sek110237  * or http://www.opensolaris.org/os/licensing.
105184Sek110237  * See the License for the specific language governing permissions
115184Sek110237  * and limitations under the License.
125184Sek110237  *
135184Sek110237  * When distributing Covered Code, include this CDDL HEADER in each
145184Sek110237  * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
155184Sek110237  * If applicable, add the following below this CDDL HEADER, with the
165184Sek110237  * fields enclosed by brackets "[]" replaced with your own identifying
175184Sek110237  * information: Portions Copyright [yyyy] [name of copyright owner]
185184Sek110237  *
195184Sek110237  * CDDL HEADER END
205184Sek110237  */
215184Sek110237 /*
226084Saw148015  * Copyright 2008 Sun Microsystems, Inc.  All rights reserved.
235184Sek110237  * Use is subject to license terms.
245184Sek110237  */
255184Sek110237 
265184Sek110237 #pragma ident	"%Z%%M%	%I%	%E% SMI"
275184Sek110237 
285184Sek110237 #include <stdio.h>
295184Sek110237 #include <fcntl.h>
305184Sek110237 #include <limits.h>
315184Sek110237 #include <time.h>
325184Sek110237 #include <libgen.h>
335184Sek110237 #include <unistd.h>
345184Sek110237 #include <strings.h>
355184Sek110237 #include "filebench.h"
365184Sek110237 #include "ipc.h"
375184Sek110237 #include "eventgen.h"
385184Sek110237 #include "utils.h"
395184Sek110237 
405184Sek110237 /*
415184Sek110237  * Routines to access high resolution system time, initialize and
42*6212Saw148015  * shutdown filebench, log filebench run progress and errors, and
43*6212Saw148015  * access system information strings.
445184Sek110237  */
455184Sek110237 
465184Sek110237 
475184Sek110237 #if !defined(sun) && defined(USE_RDTSC)
485184Sek110237 /*
495184Sek110237  * Lets us use the rdtsc instruction to get highres time.
505184Sek110237  * Thanks to libmicro
515184Sek110237  */
525184Sek110237 uint64_t	cpu_hz = 0;
535184Sek110237 
545184Sek110237 /*
555184Sek110237  * Uses the rdtsc instruction to get high resolution (cpu
565184Sek110237  * clock ticks) time. Only used for non Sun compiles.
575184Sek110237  */
585184Sek110237 __inline__ long long
595184Sek110237 rdtsc(void)
605184Sek110237 {
615184Sek110237 	unsigned long long x;
625184Sek110237 	__asm__ volatile(".byte 0x0f, 0x31" : "=A" (x));
635184Sek110237 	return (x);
645184Sek110237 }
655184Sek110237 
665184Sek110237 /*
675184Sek110237  * Get high resolution time in nanoseconds. This is the version
685184Sek110237  * used when not compiled for Sun systems. It uses rdtsc call to
695184Sek110237  * get clock ticks and converts to nanoseconds
705184Sek110237  */
715184Sek110237 uint64_t
725184Sek110237 gethrtime(void)
735184Sek110237 {
745184Sek110237 	uint64_t hrt;
755184Sek110237 
765184Sek110237 	/* convert to nanosecs and return */
775184Sek110237 	hrt = 1000000000UL * rdtsc() / cpu_hz;
785184Sek110237 	return (hrt);
795184Sek110237 }
805184Sek110237 
815184Sek110237 /*
825184Sek110237  * Gets CPU clock frequency in MHz from cpuinfo file.
835184Sek110237  * Converts to cpu_hz and stores in cpu_hz global uint64_t.
845184Sek110237  * Only used for non Sun compiles.
855184Sek110237  */
865184Sek110237 static uint64_t
875184Sek110237 parse_cpu_hz(void)
885184Sek110237 {
895184Sek110237 	/*
905184Sek110237 	 * Parse the following from /proc/cpuinfo.
915184Sek110237 	 * cpu MHz		: 2191.563
925184Sek110237 	 */
935184Sek110237 	FILE *cpuinfo;
945184Sek110237 	double hertz = -1;
955184Sek110237 	uint64_t hz;
965184Sek110237 
975184Sek110237 	if ((cpuinfo = fopen("/proc/cpuinfo", "r")) == NULL) {
985184Sek110237 		filebench_log(LOG_ERROR, "open /proc/cpuinfo failed: %s",
995184Sek110237 		    strerror(errno));
1005184Sek110237 		filebench_shutdown(1);
1015184Sek110237 	}
1025184Sek110237 	while (!feof(cpuinfo)) {
1035184Sek110237 		char buffer[80];
1045184Sek110237 
1055184Sek110237 		fgets(buffer, 80, cpuinfo);
1065184Sek110237 		if (strlen(buffer) == 0) continue;
1075184Sek110237 		if (strncasecmp(buffer, "cpu MHz", 7) == 0) {
1085184Sek110237 			char *token = strtok(buffer, ":");
1095184Sek110237 
1105184Sek110237 			if (token != NULL) {
1115184Sek110237 				token = strtok((char *)NULL, ":");
1125184Sek110237 				hertz = strtod(token, NULL);
1135184Sek110237 			}
1145184Sek110237 			break;
1155184Sek110237 		}
1165184Sek110237 	}
1175184Sek110237 	hz = hertz * 1000000;
1185184Sek110237 
1195184Sek110237 	return (hz);
1205184Sek110237 }
1215184Sek110237 
1225184Sek110237 #elif !defined(sun)
1235184Sek110237 
1245184Sek110237 /*
1255184Sek110237  * Get high resolution time in nanoseconds. This is the version
1265184Sek110237  * used if compiled for Sun systems. It calls gettimeofday
1275184Sek110237  * to get current time and converts it to nanoseconds.
1285184Sek110237  */
1295184Sek110237 uint64_t
1305184Sek110237 gethrtime(void)
1315184Sek110237 {
1325184Sek110237 	struct timeval tv;
1335184Sek110237 	uint64_t hrt;
1345184Sek110237 
1355184Sek110237 	gettimeofday(&tv, NULL);
1365184Sek110237 
1375184Sek110237 	hrt = (uint64_t)tv.tv_sec * 1000000000UL +
1385184Sek110237 	    (uint64_t)tv.tv_usec * 1000UL;
1395184Sek110237 	return (hrt);
1405184Sek110237 }
1415184Sek110237 #endif
1425184Sek110237 
1435184Sek110237 /*
1445184Sek110237  * Main filebench initialization. Opens the random number
1455184Sek110237  * "device" file or shuts down the run if one is not found.
1465184Sek110237  * Sets the cpu clock frequency variable or shuts down the
1475184Sek110237  * run if one is not found.
1485184Sek110237  */
1495184Sek110237 void
1505184Sek110237 filebench_init(void)
1515184Sek110237 {
152*6212Saw148015 	fb_random_init();
153*6212Saw148015 
1545184Sek110237 #if defined(USE_RDTSC) && (LINUX_PORT)
1555184Sek110237 	cpu_hz = parse_cpu_hz();
1565184Sek110237 	if (cpu_hz <= 0) {
1575184Sek110237 		filebench_log(LOG_ERROR, "Error getting CPU Mhz: %s",
1585184Sek110237 		    strerror(errno));
1595184Sek110237 		filebench_shutdown(1);
1605184Sek110237 	}
1615184Sek110237 #endif /* USE_RDTSC */
1625184Sek110237 
1635184Sek110237 }
1645184Sek110237 
1655184Sek110237 extern int lex_lineno;
1665184Sek110237 
1675184Sek110237 /*
1685184Sek110237  * Writes a message consisting of information formated by
1695184Sek110237  * "fmt" to the log file, dump file or stdout.  The supplied
1705184Sek110237  * "level" argument determines which file to write to and
1715184Sek110237  * what other actions to take. The level LOG_LOG writes to
1725184Sek110237  * the "log" file, and will open the file on the first
1735184Sek110237  * invocation. The level LOG_DUMP writes to the "dump" file,
1745184Sek110237  * and will open it on the first invocation. Other levels
1755184Sek110237  * print to the stdout device, with the amount of information
1765184Sek110237  * dependent on the error level and the current error level
1775184Sek110237  * setting in filebench_shm->debug_level.
1785184Sek110237  */
1795184Sek110237 void filebench_log
1805184Sek110237 __V((int level, const char *fmt, ...))
1815184Sek110237 {
1825184Sek110237 	va_list args;
1835184Sek110237 	hrtime_t now;
1845184Sek110237 	char line[131072];
1855184Sek110237 	char buf[131072];
1865184Sek110237 
1875184Sek110237 	if (level == LOG_FATAL)
1885184Sek110237 		goto fatal;
1895184Sek110237 
1905184Sek110237 	/* open logfile if not already open and writing to it */
1915184Sek110237 	if ((level == LOG_LOG) &&
1925184Sek110237 	    (filebench_shm->log_fd < 0)) {
1935184Sek110237 		char path[MAXPATHLEN];
1945184Sek110237 		char *s;
1955184Sek110237 
1965184Sek110237 		(void) strcpy(path, filebench_shm->fscriptname);
1975184Sek110237 		if ((s = strstr(path, ".f")))
1985184Sek110237 			*s = 0;
1995184Sek110237 		else
2005184Sek110237 			(void) strcpy(path, "filebench");
2015184Sek110237 
2025184Sek110237 		(void) strcat(path, ".csv");
2035184Sek110237 
2045184Sek110237 		filebench_shm->log_fd =
2055184Sek110237 		    open(path, O_RDWR | O_CREAT | O_TRUNC, 0666);
2065184Sek110237 	}
2075184Sek110237 
2085184Sek110237 	/*
2095184Sek110237 	 * if logfile still not open, switch to LOG_ERROR level so
2105184Sek110237 	 * it gets reported to stdout
2115184Sek110237 	 */
2125184Sek110237 	if ((level == LOG_LOG) &&
2135184Sek110237 	    (filebench_shm->log_fd < 0)) {
2145184Sek110237 		(void) snprintf(line, sizeof (line),  "Open logfile failed: %s",
2155184Sek110237 		    strerror(errno));
2165184Sek110237 		level = LOG_ERROR;
2175184Sek110237 	}
2185184Sek110237 
2195184Sek110237 	/* open dumpfile if not already open and writing to it */
2205184Sek110237 	if ((level == LOG_DUMP) &&
2215184Sek110237 	    (*filebench_shm->dump_filename == 0))
2225184Sek110237 		return;
2235184Sek110237 
2245184Sek110237 	if ((level == LOG_DUMP) &&
2255184Sek110237 	    (filebench_shm->dump_fd < 0)) {
2265184Sek110237 
2275184Sek110237 		filebench_shm->dump_fd =
2285184Sek110237 		    open(filebench_shm->dump_filename,
2295184Sek110237 		    O_RDWR | O_CREAT | O_TRUNC, 0666);
2305184Sek110237 	}
2315184Sek110237 
2325184Sek110237 	if ((level == LOG_DUMP) &&
2335184Sek110237 	    (filebench_shm->dump_fd < 0)) {
2345184Sek110237 		(void) snprintf(line, sizeof (line), "Open logfile failed: %s",
2355184Sek110237 		    strerror(errno));
2365184Sek110237 		level = LOG_ERROR;
2375184Sek110237 	}
2385184Sek110237 
2396084Saw148015 	/* Quit if this is a LOG_ERROR messages and they are disabled */
2406084Saw148015 	if ((filebench_shm->shm_1st_err) && (level == LOG_ERROR))
2416084Saw148015 		return;
2426084Saw148015 
2436084Saw148015 	if (level == LOG_ERROR1) {
2446084Saw148015 		if (filebench_shm->shm_1st_err)
2456084Saw148015 			return;
2466084Saw148015 
2476084Saw148015 		/* A LOG_ERROR1 temporarily disables LOG_ERROR messages */
2486084Saw148015 		filebench_shm->shm_1st_err = 1;
2496084Saw148015 		level = LOG_ERROR;
2506084Saw148015 	}
2516084Saw148015 
2525184Sek110237 	/* Only log greater than debug setting */
2535184Sek110237 	if ((level != LOG_DUMP) && (level != LOG_LOG) &&
2545184Sek110237 	    (level > filebench_shm->debug_level))
2555184Sek110237 		return;
2565184Sek110237 
2575184Sek110237 	now = gethrtime();
2585184Sek110237 
2595184Sek110237 fatal:
2605184Sek110237 
2615184Sek110237 #ifdef __STDC__
2625184Sek110237 	va_start(args, fmt);
2635184Sek110237 #else
2645184Sek110237 	char *fmt;
2655184Sek110237 	va_start(args);
2665184Sek110237 	fmt = va_arg(args, char *);
2675184Sek110237 #endif
2685184Sek110237 
2695184Sek110237 	(void) vsprintf(line, fmt, args);
2705184Sek110237 
2715184Sek110237 	va_end(args);
2725184Sek110237 
2735184Sek110237 	if (level == LOG_FATAL) {
2745184Sek110237 		(void) fprintf(stdout, "%s\n", line);
2755184Sek110237 		return;
2765184Sek110237 	}
2775184Sek110237 
2785184Sek110237 	/* Serialize messages to log */
2795184Sek110237 	(void) ipc_mutex_lock(&filebench_shm->msg_lock);
2805184Sek110237 
2815184Sek110237 	if (level == LOG_LOG) {
2825184Sek110237 		if (filebench_shm->log_fd > 0) {
2835184Sek110237 			(void) snprintf(buf, sizeof (buf), "%s\n", line);
2845184Sek110237 			(void) write(filebench_shm->log_fd, buf, strlen(buf));
2855184Sek110237 			(void) fsync(filebench_shm->log_fd);
2865184Sek110237 		}
2875184Sek110237 
2885184Sek110237 	} else if (level == LOG_DUMP) {
2895184Sek110237 		if (filebench_shm->dump_fd != -1) {
2905184Sek110237 			(void) snprintf(buf, sizeof (buf), "%s\n", line);
2915184Sek110237 			(void) write(filebench_shm->dump_fd, buf, strlen(buf));
2925184Sek110237 			(void) fsync(filebench_shm->dump_fd);
2935184Sek110237 		}
2945184Sek110237 
2955184Sek110237 	} else if (filebench_shm->debug_level > LOG_INFO) {
2965216Sek110237 		(void) fprintf(stdout, "%5d: %4.3f: %s",
2976084Saw148015 		    (int)my_pid, (now - filebench_shm->epoch) / FSECS,
2985184Sek110237 		    line);
2995184Sek110237 	} else {
3005184Sek110237 		(void) fprintf(stdout, "%4.3f: %s",
3015184Sek110237 		    (now - filebench_shm->epoch) / FSECS,
3025184Sek110237 		    line);
3035184Sek110237 	}
3045184Sek110237 
3055184Sek110237 	if (level == LOG_ERROR) {
3066084Saw148015 		if (my_procflow == NULL)
3076084Saw148015 			(void) fprintf(stdout, " on line %d", lex_lineno);
3085184Sek110237 	}
3095184Sek110237 
3105184Sek110237 	if ((level != LOG_LOG) && (level != LOG_DUMP)) {
3115184Sek110237 		(void) fprintf(stdout, "\n");
3125184Sek110237 		(void) fflush(stdout);
3135184Sek110237 	}
3145184Sek110237 
3155184Sek110237 	(void) ipc_mutex_unlock(&filebench_shm->msg_lock);
3165184Sek110237 }
3175184Sek110237 
3185184Sek110237 /*
3195184Sek110237  * Stops the run and exits filebench. If filebench is
3205184Sek110237  * currently running a workload, calls procflow_shutdown()
3215184Sek110237  * to stop the run. Also closes and deletes shared memory.
3225184Sek110237  */
3235184Sek110237 void
3245184Sek110237 filebench_shutdown(int error) {
3255184Sek110237 	filebench_log(LOG_DEBUG_IMPL, "Shutdown");
3265184Sek110237 	(void) unlink("/tmp/filebench_shm");
3276084Saw148015 	if (filebench_shm->shm_running)
3285184Sek110237 		procflow_shutdown();
3295184Sek110237 	filebench_shm->f_abort = 1;
3305184Sek110237 	ipc_ismdelete();
3315184Sek110237 	exit(error);
3325184Sek110237 }
3335184Sek110237 
3345184Sek110237 /*
3355184Sek110237  * Put the hostname in ${hostname}. The system supplied
3365184Sek110237  * host name string is copied into an allocated string and
3375184Sek110237  * the pointer to the string is placed in the supplied
338*6212Saw148015  * variable "var". If var->var_val.string already points to
3395184Sek110237  * a string, the string is freed. The routine always
3405184Sek110237  * returns zero (0).
3415184Sek110237  */
3425184Sek110237 var_t *
3435184Sek110237 host_var(var_t *var)
3445184Sek110237 {
3455184Sek110237 	char hoststr[128];
346*6212Saw148015 	char *strptr;
3475184Sek110237 
3485184Sek110237 	(void) gethostname(hoststr, 128);
349*6212Saw148015 	if (VAR_HAS_STRING(var) && var->var_val.string)
350*6212Saw148015 		free(var->var_val.string);
351*6212Saw148015 
352*6212Saw148015 	if ((strptr = fb_stralloc(hoststr)) == NULL) {
353*6212Saw148015 		filebench_log(LOG_ERROR,
354*6212Saw148015 		    "unable to allocate string for host name");
355*6212Saw148015 		return (NULL);
356*6212Saw148015 	}
357*6212Saw148015 
358*6212Saw148015 	VAR_SET_STR(var, strptr);
3595184Sek110237 	return (0);
3605184Sek110237 }
3615184Sek110237 
3625184Sek110237 /*
3635184Sek110237  * Put the date string in ${date}. The system supplied date is
3645184Sek110237  * copied into an allocated string and the pointer to the string
365*6212Saw148015  * is placed in the supplied var_t's var_val.string. If
366*6212Saw148015  * var->var_val.string already points to a string, the string
367*6212Saw148015  * is freed. The routine returns a pointer to the supplied var_t,
368*6212Saw148015  * unless it is unable to allocate string for the date, in which
369*6212Saw148015  * case it returns NULL.
3705184Sek110237  */
3715184Sek110237 var_t *
3725184Sek110237 date_var(var_t *var)
3735184Sek110237 {
3745184Sek110237 	char datestr[128];
375*6212Saw148015 	char *strptr;
3765184Sek110237 #ifdef HAVE_CFTIME
3775184Sek110237 	time_t t = time(NULL);
3785184Sek110237 #else
3795184Sek110237 	struct tm t;
3805184Sek110237 #endif
3815184Sek110237 
3825184Sek110237 #ifdef HAVE_CFTIME
3835184Sek110237 	cftime(datestr, "%y%m%d%H" "%M", &t);
3845184Sek110237 #else
3855184Sek110237 	(void) strftime(datestr, sizeof (datestr), "%y%m%d%H %M", &t);
3865184Sek110237 #endif
3875184Sek110237 
388*6212Saw148015 	if (VAR_HAS_STRING(var) && var->var_val.string)
389*6212Saw148015 		free(var->var_val.string);
390*6212Saw148015 
391*6212Saw148015 	if ((strptr = fb_stralloc(datestr)) == NULL) {
392*6212Saw148015 		filebench_log(LOG_ERROR,
393*6212Saw148015 		    "unable to allocate string for date");
394*6212Saw148015 		return (NULL);
395*6212Saw148015 	}
396*6212Saw148015 
397*6212Saw148015 	VAR_SET_STR(var, strptr);
3985184Sek110237 
3995184Sek110237 	return (var);
4005184Sek110237 }
4015184Sek110237 
4025184Sek110237 extern char *fscriptname;
4035184Sek110237 
4045184Sek110237 /*
4055184Sek110237  * Put the script name in ${script}. The path name of the script
4065184Sek110237  * used with this filebench run trimmed of the trailing ".f" and
4075184Sek110237  * all leading subdirectories. The remaining script name is
408*6212Saw148015  * copied into the var_val.string field of the supplied variable
409*6212Saw148015  * "var". The routine returns a pointer to the supplied var_t,
410*6212Saw148015  * unless it is unable to allocate string space, in which case it
411*6212Saw148015  * returns NULL.
4125184Sek110237  */
4135184Sek110237 var_t *
4145184Sek110237 script_var(var_t *var)
4155184Sek110237 {
4165184Sek110237 	char *scriptstr;
4175184Sek110237 	char *f = fb_stralloc(fscriptname);
418*6212Saw148015 	char *strptr;
4195184Sek110237 
4205184Sek110237 	/* Trim the .f suffix */
4215184Sek110237 	for (scriptstr = f + strlen(f) - 1; scriptstr != f; scriptstr--) {
4225184Sek110237 		if (*scriptstr == '.') {
4235184Sek110237 			*scriptstr = 0;
4245184Sek110237 			break;
4255184Sek110237 		}
4265184Sek110237 	}
4275184Sek110237 
428*6212Saw148015 	if ((strptr = fb_stralloc(basename(f))) == NULL) {
429*6212Saw148015 		filebench_log(LOG_ERROR,
430*6212Saw148015 		    "unable to allocate string for script name");
431*6212Saw148015 		free(f);
432*6212Saw148015 		return (NULL);
433*6212Saw148015 	}
434*6212Saw148015 
435*6212Saw148015 	VAR_SET_STR(var, strptr);
4365184Sek110237 	free(f);
4375184Sek110237 
4385184Sek110237 	return (var);
4395184Sek110237 }
440