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