1 5184 ek110237 /* 2 5184 ek110237 * CDDL HEADER START 3 5184 ek110237 * 4 5184 ek110237 * The contents of this file are subject to the terms of the 5 5184 ek110237 * Common Development and Distribution License (the "License"). 6 5184 ek110237 * You may not use this file except in compliance with the License. 7 5184 ek110237 * 8 5184 ek110237 * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE 9 5184 ek110237 * or http://www.opensolaris.org/os/licensing. 10 5184 ek110237 * See the License for the specific language governing permissions 11 5184 ek110237 * and limitations under the License. 12 5184 ek110237 * 13 5184 ek110237 * When distributing Covered Code, include this CDDL HEADER in each 14 5184 ek110237 * file and include the License file at usr/src/OPENSOLARIS.LICENSE. 15 5184 ek110237 * If applicable, add the following below this CDDL HEADER, with the 16 5184 ek110237 * fields enclosed by brackets "[]" replaced with your own identifying 17 5184 ek110237 * information: Portions Copyright [yyyy] [name of copyright owner] 18 5184 ek110237 * 19 5184 ek110237 * CDDL HEADER END 20 5184 ek110237 */ 21 5184 ek110237 /* 22 9356 Andrew * Copyright 2009 Sun Microsystems, Inc. All rights reserved. 23 5184 ek110237 * Use is subject to license terms. 24 5184 ek110237 */ 25 5184 ek110237 26 5184 ek110237 #include "config.h" 27 5184 ek110237 28 5184 ek110237 #include <stdio.h> 29 5184 ek110237 #include <fcntl.h> 30 5184 ek110237 #include <sys/types.h> 31 5184 ek110237 32 5184 ek110237 #ifdef HAVE_SYSINFO 33 5184 ek110237 #include <sys/sysinfo.h> 34 5184 ek110237 #endif 35 5184 ek110237 36 5184 ek110237 #ifdef HAVE_LIBKSTAT 37 5184 ek110237 #include <kstat.h> 38 5184 ek110237 #include <sys/cpuvar.h> 39 5184 ek110237 #endif /* HAVE_LIBKSTAT */ 40 5184 ek110237 41 5184 ek110237 #include <stdarg.h> 42 5184 ek110237 43 5184 ek110237 #include "filebench.h" 44 5184 ek110237 #include "flowop.h" 45 5184 ek110237 #include "vars.h" 46 5184 ek110237 #include "stats.h" 47 5184 ek110237 48 5184 ek110237 /* 49 5184 ek110237 * A set of routines for collecting and dumping various filebench 50 5184 ek110237 * run statistics. 51 5184 ek110237 */ 52 5184 ek110237 53 5184 ek110237 /* Global statistics */ 54 5184 ek110237 static flowstat_t *globalstats = NULL; 55 5184 ek110237 56 5184 ek110237 static hrtime_t stats_cputime = 0; 57 5184 ek110237 58 5184 ek110237 #ifdef HAVE_LIBKSTAT 59 5184 ek110237 static kstat_ctl_t *kstatp = NULL; 60 5184 ek110237 static kstat_t *sysinfo_ksp = NULL; 61 9356 Andrew static kstat_t **cpu_kstat_list = NULL; 62 9356 Andrew static int kstat_ncpus = 0; 63 9356 Andrew 64 9356 Andrew static int 65 9356 Andrew stats_build_kstat_list(void) 66 9356 Andrew { 67 9356 Andrew kstat_t *ksp; 68 9356 Andrew 69 9356 Andrew kstat_ncpus = 0; 70 9356 Andrew for (ksp = kstatp->kc_chain; ksp; ksp = ksp->ks_next) 71 9356 Andrew if (strncmp(ksp->ks_name, "cpu_stat", 8) == 0) 72 9356 Andrew kstat_ncpus++; 73 9356 Andrew 74 9356 Andrew if ((cpu_kstat_list = (kstat_t **) 75 9356 Andrew malloc(kstat_ncpus * sizeof (kstat_t *))) == NULL) { 76 9356 Andrew filebench_log(LOG_ERROR, "malloc failed"); 77 9356 Andrew return (FILEBENCH_ERROR); 78 9356 Andrew } 79 9356 Andrew 80 9356 Andrew kstat_ncpus = 0; 81 9356 Andrew for (ksp = kstatp->kc_chain; ksp; ksp = ksp->ks_next) 82 9356 Andrew if (strncmp(ksp->ks_name, "cpu_stat", 8) == 0 && 83 9356 Andrew kstat_read(kstatp, ksp, NULL) != -1) 84 9356 Andrew cpu_kstat_list[kstat_ncpus++] = ksp; 85 9356 Andrew 86 9356 Andrew if (kstat_ncpus == 0) { 87 9356 Andrew filebench_log(LOG_ERROR, 88 9356 Andrew "kstats can't find any cpu statistics"); 89 9356 Andrew return (FILEBENCH_ERROR); 90 9356 Andrew } 91 9356 Andrew 92 9356 Andrew return (FILEBENCH_OK); 93 9356 Andrew } 94 9356 Andrew 95 9356 Andrew static int 96 9356 Andrew stats_kstat_update(void) 97 9356 Andrew { 98 9356 Andrew if (kstatp == NULL) { 99 9356 Andrew if ((kstatp = kstat_open()) == (kstat_ctl_t *)NULL) { 100 9356 Andrew filebench_log(LOG_ERROR, "Cannot read kstats"); 101 9356 Andrew return (FILEBENCH_ERROR); 102 9356 Andrew } 103 9356 Andrew } 104 9356 Andrew 105 9356 Andrew /* get the sysinfo kstat */ 106 9356 Andrew if (sysinfo_ksp == NULL) 107 9356 Andrew sysinfo_ksp = kstat_lookup(kstatp, "unix", 0, "sysinfo"); 108 9356 Andrew 109 9356 Andrew /* get per cpu kstats, if necessary */ 110 9356 Andrew if (cpu_kstat_list == NULL) { 111 9356 Andrew 112 9356 Andrew /* Initialize the array of cpu kstat pointers */ 113 9356 Andrew if (stats_build_kstat_list() == FILEBENCH_ERROR) 114 9356 Andrew return (FILEBENCH_ERROR); 115 9356 Andrew 116 9356 Andrew } else if (kstat_chain_update(kstatp) != 0) { 117 9356 Andrew 118 9356 Andrew /* free up current array of kstat ptrs and get new one */ 119 9356 Andrew free((void *)cpu_kstat_list); 120 9356 Andrew if (stats_build_kstat_list() == FILEBENCH_ERROR) 121 9356 Andrew return (FILEBENCH_ERROR); 122 9356 Andrew } 123 9356 Andrew 124 9356 Andrew return (FILEBENCH_OK); 125 9356 Andrew } 126 5184 ek110237 127 5184 ek110237 /* 128 5184 ek110237 * Uses the kstat library or, if it is not available, the /proc/stat file 129 5184 ek110237 * to obtain cpu statistics. Collects statistics for each cpu, initializes 130 5184 ek110237 * a local pointer to the sysinfo kstat, and returns the sum of user and 131 5184 ek110237 * kernel time for all the cpus. 132 5184 ek110237 */ 133 6212 aw148015 static fbint_t 134 5184 ek110237 kstats_read_cpu(void) 135 5184 ek110237 { 136 9513 Andrew u_longlong_t cputime_states[CPU_STATES]; 137 9513 Andrew hrtime_t cputime; 138 9513 Andrew int i; 139 5184 ek110237 140 5184 ek110237 /* 141 5184 ek110237 * Per-CPU statistics 142 5184 ek110237 */ 143 5184 ek110237 144 9356 Andrew if (stats_kstat_update() == FILEBENCH_ERROR) 145 5184 ek110237 return (0); 146 5184 ek110237 147 5184 ek110237 /* Sum across all CPUs */ 148 5184 ek110237 (void) memset(&cputime_states, 0, sizeof (cputime_states)); 149 9356 Andrew for (i = 0; i < kstat_ncpus; i++) { 150 5184 ek110237 cpu_stat_t cpu_stats; 151 5184 ek110237 int j; 152 5184 ek110237 153 9356 Andrew (void) kstat_read(kstatp, cpu_kstat_list[i], 154 5184 ek110237 (void *) &cpu_stats); 155 5184 ek110237 for (j = 0; j < CPU_STATES; j++) 156 5184 ek110237 cputime_states[j] += cpu_stats.cpu_sysinfo.cpu[j]; 157 5184 ek110237 } 158 5184 ek110237 159 5184 ek110237 cputime = cputime_states[CPU_KERNEL] + cputime_states[CPU_USER]; 160 5184 ek110237 161 5184 ek110237 return (10000000LL * cputime); 162 5184 ek110237 } 163 5184 ek110237 #else /* HAVE_LIBKSTAT */ 164 5184 ek110237 #ifdef HAVE_PROC_STAT 165 5184 ek110237 static FILE *statfd = 0; 166 6212 aw148015 fbint_t 167 5184 ek110237 kstats_read_cpu(void) 168 5184 ek110237 { 169 5184 ek110237 /* 170 5184 ek110237 * Linux provides system wide statistics in /proc/stat 171 5184 ek110237 * The entry for cpu is 172 5184 ek110237 * cpu 1636 67 1392 208671 5407 20 12 173 5184 ek110237 * cpu0 626 8 997 104476 2499 7 7 174 5184 ek110237 * cpu1 1010 58 395 104195 2907 13 5 175 5184 ek110237 * 176 5184 ek110237 * The number of jiffies (1/100ths of a second) that the 177 5184 ek110237 * system spent in user mode, user mode with low priority 178 5184 ek110237 * (nice), system mode, and the idle task, respectively. 179 5184 ek110237 */ 180 5184 ek110237 unsigned int user, nice, system; 181 5184 ek110237 char cpu[128]; /* placeholder to read "cpu" */ 182 5184 ek110237 if (statfd == 0) { 183 5184 ek110237 statfd = fopen("/proc/stat", "r"); 184 5184 ek110237 if (statfd < 0) { 185 5184 ek110237 filebench_log(LOG_ERROR, "Cannot open /proc/stat"); 186 5184 ek110237 return (-1); 187 5184 ek110237 } 188 5184 ek110237 } 189 5184 ek110237 if (fscanf(statfd, "%s %u %u %u", cpu, &user, &nice, &system) < 0) { 190 5184 ek110237 filebench_log(LOG_ERROR, "Cannot read /proc/stat"); 191 5184 ek110237 return (-1); 192 5184 ek110237 } 193 5184 ek110237 /* convert jiffies to nanosecs */ 194 5184 ek110237 return ((user+nice+system)*1000000); 195 5184 ek110237 } 196 5184 ek110237 197 5184 ek110237 #else /* HAVE_PROC_STAT */ 198 6212 aw148015 fbint_t 199 5184 ek110237 kstats_read_cpu(void) 200 5184 ek110237 { 201 5184 ek110237 return (0); 202 5184 ek110237 } 203 5184 ek110237 #endif 204 5184 ek110237 #endif /* HAVE_LIBKSTAT */ 205 5184 ek110237 206 5184 ek110237 /* 207 5184 ek110237 * Returns the net cpu time used since the beginning of the run. 208 5184 ek110237 * Just calls kstat_read_cpu() and subtracts stats_cputime which 209 5184 ek110237 * is set at the beginning of the filebench run. 210 5184 ek110237 */ 211 5184 ek110237 static hrtime_t 212 5184 ek110237 kstats_read_cpu_relative(void) 213 5184 ek110237 { 214 5184 ek110237 hrtime_t cputime; 215 5184 ek110237 216 5184 ek110237 cputime = kstats_read_cpu(); 217 5184 ek110237 return (cputime - stats_cputime); 218 5184 ek110237 } 219 5184 ek110237 220 5184 ek110237 /* 221 5184 ek110237 * IO Overhead CPU is the amount of CPU that is incurred running 222 5184 ek110237 * the benchmark infrastructure. 223 5184 ek110237 * 224 5184 ek110237 * It is computed as the sum of micro-state cpu time for each 225 5184 ek110237 * thread around the op being tested. 226 5184 ek110237 * 227 5184 ek110237 * Overhead time is computed for each flow. 228 5184 ek110237 * 229 5184 ek110237 * System overhead is computed as the overhead for I/O flows 230 5184 ek110237 * plus all other time running non-io related flowops 231 5184 ek110237 * 232 5184 ek110237 */ 233 5184 ek110237 234 5184 ek110237 /* 235 5184 ek110237 * Computes and returns the overhead CPU time attibutable to 236 5184 ek110237 * IO type flowops. 237 5184 ek110237 */ 238 5184 ek110237 static hrtime_t 239 5184 ek110237 io_stats_ohead(void) 240 5184 ek110237 { 241 5184 ek110237 flowstat_t *iostat = &globalstats[FLOW_TYPE_IO]; 242 5184 ek110237 flowstat_t *aiostat = &globalstats[FLOW_TYPE_AIO]; 243 5184 ek110237 flowstat_t *glstat = &globalstats[FLOW_TYPE_GLOBAL]; 244 5184 ek110237 245 5184 ek110237 filebench_log(LOG_DEBUG_NEVER, 246 6286 aw148015 "Computing overhead as %llu + %llu - %llu - %llu", 247 6286 aw148015 (u_longlong_t)glstat->fs_mstate[FLOW_MSTATE_OHEAD], 248 6286 aw148015 (u_longlong_t)glstat->fs_mstate[FLOW_MSTATE_CPU], 249 6286 aw148015 (u_longlong_t)iostat->fs_mstate[FLOW_MSTATE_CPU], 250 6286 aw148015 (u_longlong_t)aiostat->fs_mstate[FLOW_MSTATE_CPU]); 251 5184 ek110237 252 5184 ek110237 return ((glstat->fs_mstate[FLOW_MSTATE_OHEAD] + 253 5184 ek110237 glstat->fs_mstate[FLOW_MSTATE_CPU] - 254 5184 ek110237 iostat->fs_mstate[FLOW_MSTATE_CPU] - 255 5184 ek110237 aiostat->fs_mstate[FLOW_MSTATE_CPU])); 256 5184 ek110237 } 257 5184 ek110237 258 5184 ek110237 /* 259 5184 ek110237 * Returns the total overhead CPU time. 260 5184 ek110237 */ 261 5184 ek110237 static hrtime_t 262 5184 ek110237 gl_stats_ohead(void) 263 5184 ek110237 { 264 5184 ek110237 flowstat_t *glstat = &globalstats[FLOW_TYPE_GLOBAL]; 265 5184 ek110237 266 5184 ek110237 return (glstat->fs_mstate[FLOW_MSTATE_OHEAD]); 267 5184 ek110237 } 268 5184 ek110237 269 5184 ek110237 /* 270 6212 aw148015 * Places the value represented by "name" into the var_val.integer field of the 271 5184 ek110237 * supplied var_t. Compares the supplied "name" with a set of predefined 272 5184 ek110237 * names and calculates the value from the appropriate globalstats field(s). 273 5184 ek110237 */ 274 5184 ek110237 var_t * 275 5184 ek110237 stats_findvar(var_t *var, char *name) 276 5184 ek110237 { 277 5184 ek110237 flowstat_t *iostat = &globalstats[FLOW_TYPE_IO]; 278 5184 ek110237 flowstat_t *aiostat = &globalstats[FLOW_TYPE_AIO]; 279 5184 ek110237 flowstat_t *glstat = &globalstats[FLOW_TYPE_GLOBAL]; 280 5184 ek110237 281 5184 ek110237 filebench_log(LOG_DEBUG_IMPL, "reading stats %s", name); 282 5184 ek110237 283 5184 ek110237 if (globalstats == NULL) 284 5184 ek110237 globalstats = malloc(FLOW_TYPES * sizeof (flowstat_t)); 285 5184 ek110237 286 5184 ek110237 if (strcmp(name, "iocount") == 0) { 287 6212 aw148015 fbint_t stat; 288 6212 aw148015 289 6212 aw148015 stat = iostat->fs_count + aiostat->fs_count; 290 6212 aw148015 VAR_SET_INT(var, stat); 291 6286 aw148015 filebench_log(LOG_DEBUG_IMPL, "reading stats %s = %llu", 292 6286 aw148015 name, (u_longlong_t)stat); 293 5184 ek110237 return (var); 294 5184 ek110237 } 295 5184 ek110237 296 5184 ek110237 if (strcmp(name, "iorate") == 0) { 297 6212 aw148015 fbint_t stat; 298 6212 aw148015 299 5184 ek110237 /* LINTED E_ASSIGMENT_CAUSE_LOSS_PREC */ 300 6212 aw148015 stat = (iostat->fs_count + aiostat->fs_count) / 301 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS); 302 6212 aw148015 VAR_SET_INT(var, stat); 303 5184 ek110237 return (var); 304 5184 ek110237 } 305 5184 ek110237 306 5184 ek110237 307 5184 ek110237 if (strcmp(name, "ioreadrate") == 0) { 308 6212 aw148015 fbint_t stat; 309 6212 aw148015 310 5184 ek110237 /* LINTED E_ASSIGMENT_CAUSE_LOSS_PREC */ 311 6212 aw148015 stat = (iostat->fs_rcount + aiostat->fs_rcount) / 312 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS); 313 6212 aw148015 VAR_SET_INT(var, stat); 314 5184 ek110237 return (var); 315 5184 ek110237 } 316 5184 ek110237 317 5184 ek110237 318 5184 ek110237 if (strcmp(name, "iowriterate") == 0) { 319 6212 aw148015 fbint_t stat; 320 6212 aw148015 321 5184 ek110237 /* LINTED E_ASSIGMENT_CAUSE_LOSS_PREC */ 322 6212 aw148015 stat = (iostat->fs_wcount + aiostat->fs_wcount) / 323 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS); 324 6212 aw148015 VAR_SET_INT(var, stat); 325 5184 ek110237 return (var); 326 5184 ek110237 } 327 5184 ek110237 328 5184 ek110237 329 5184 ek110237 if (strcmp(name, "iobandwidth") == 0) { 330 6212 aw148015 fbint_t stat; 331 6212 aw148015 332 5184 ek110237 /* LINTED E_ASSIGMENT_CAUSE_LOSS_PREC */ 333 6212 aw148015 stat = 334 5184 ek110237 ((iostat->fs_bytes + aiostat->fs_bytes) / (1024 * 1024)) / 335 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS); 336 6212 aw148015 VAR_SET_INT(var, stat); 337 5184 ek110237 return (var); 338 5184 ek110237 } 339 5184 ek110237 340 5184 ek110237 if (strcmp(name, "iolatency") == 0) { 341 6212 aw148015 fbint_t stat; 342 6212 aw148015 343 6212 aw148015 stat = iostat->fs_count ? iostat->fs_mstate[FLOW_MSTATE_LAT] / 344 5184 ek110237 (iostat->fs_count * 1000UL) : 0; 345 6212 aw148015 VAR_SET_INT(var, stat); 346 5184 ek110237 return (var); 347 5184 ek110237 } 348 5184 ek110237 349 5184 ek110237 if (strcmp(name, "iocpu") == 0) { 350 6212 aw148015 fbint_t stat; 351 6212 aw148015 352 6212 aw148015 stat = (iostat->fs_count + aiostat->fs_count) ? 353 5184 ek110237 (iostat->fs_mstate[FLOW_MSTATE_CPU] + 354 5184 ek110237 aiostat->fs_mstate[FLOW_MSTATE_CPU]) / ((iostat->fs_count + 355 5184 ek110237 aiostat->fs_count) * 1000UL) : 0; 356 6212 aw148015 VAR_SET_INT(var, stat); 357 5184 ek110237 return (var); 358 5184 ek110237 } 359 5184 ek110237 360 5184 ek110237 361 5184 ek110237 if (strcmp(name, "oheadcpu") == 0) { 362 6212 aw148015 fbint_t stat; 363 6212 aw148015 364 6212 aw148015 stat = (iostat->fs_count + aiostat->fs_count) ? 365 5184 ek110237 io_stats_ohead() / ((iostat->fs_count + 366 5184 ek110237 aiostat->fs_count) * 1000UL) : 0; 367 6212 aw148015 VAR_SET_INT(var, stat); 368 5184 ek110237 return (var); 369 5184 ek110237 } 370 5184 ek110237 371 5184 ek110237 if (strcmp(name, "iowait") == 0) { 372 6212 aw148015 fbint_t stat; 373 6212 aw148015 374 6212 aw148015 stat = iostat->fs_count ? 375 5184 ek110237 iostat->fs_mstate[FLOW_MSTATE_WAIT] / 376 5184 ek110237 (iostat->fs_count * 1000UL) : 0; 377 6212 aw148015 VAR_SET_INT(var, stat); 378 5184 ek110237 return (var); 379 5184 ek110237 } 380 5184 ek110237 381 5184 ek110237 if (strcmp(name, "syscpu") == 0) { 382 6212 aw148015 fbint_t stat; 383 6212 aw148015 384 5184 ek110237 /* LINTED E_ASSIGMENT_CAUSE_LOSS_PREC */ 385 6212 aw148015 stat = glstat->fs_syscpu / 1000.0; 386 6212 aw148015 VAR_SET_INT(var, stat); 387 5184 ek110237 return (var); 388 5184 ek110237 } 389 5184 ek110237 390 5184 ek110237 if (strcmp(name, "iocpusys") == 0) { 391 6212 aw148015 fbint_t stat; 392 6212 aw148015 393 6212 aw148015 stat = (iostat->fs_count + aiostat->fs_count) ? 394 5184 ek110237 iostat->fs_syscpu / ((iostat->fs_count + 395 5184 ek110237 aiostat->fs_count) * 1000UL) : 0; 396 5184 ek110237 397 6212 aw148015 VAR_SET_INT(var, stat); 398 5184 ek110237 return (var); 399 5184 ek110237 } 400 5184 ek110237 401 5184 ek110237 filebench_log(LOG_DEBUG_IMPL, 402 5184 ek110237 "error reading stats %s", name); 403 5184 ek110237 404 5184 ek110237 return (NULL); 405 5184 ek110237 } 406 5184 ek110237 407 5184 ek110237 /* 408 5184 ek110237 * Initializes the static variable "stats_cputime" with the 409 5184 ek110237 * current cpu time, for use by kstats_read_cpu_relative. 410 5184 ek110237 */ 411 5184 ek110237 void 412 5184 ek110237 stats_init(void) 413 5184 ek110237 { 414 5184 ek110237 #if defined(HAVE_LIBKSTAT) || defined(LINUX_PORT) 415 5184 ek110237 stats_cputime = kstats_read_cpu(); 416 5184 ek110237 #else 417 5184 ek110237 stats_cputime = 0; 418 5184 ek110237 #endif /* HAVE_LIBKSTAT */ 419 5184 ek110237 } 420 5184 ek110237 421 5184 ek110237 /* 422 5184 ek110237 * Add a flowstat b to a, leave sum in a. 423 5184 ek110237 */ 424 5184 ek110237 static void 425 5184 ek110237 stats_add(flowstat_t *a, flowstat_t *b) 426 5184 ek110237 { 427 5184 ek110237 int i; 428 5184 ek110237 429 5184 ek110237 a->fs_count += b->fs_count; 430 5184 ek110237 a->fs_rcount += b->fs_rcount; 431 5184 ek110237 a->fs_wcount += b->fs_wcount; 432 5184 ek110237 a->fs_bytes += b->fs_bytes; 433 5184 ek110237 a->fs_rbytes += b->fs_rbytes; 434 5184 ek110237 a->fs_wbytes += b->fs_wbytes; 435 5184 ek110237 436 5184 ek110237 for (i = 0; i < FLOW_MSTATES; i++) 437 5184 ek110237 a->fs_mstate[i] += b->fs_mstate[i]; 438 5184 ek110237 } 439 5184 ek110237 440 5184 ek110237 /* 441 5184 ek110237 * Takes a "snapshot" of the global statistics. Actually, it calculates 442 5184 ek110237 * them from the local statistics maintained by each flowop. 443 5184 ek110237 * First the routine pauses filebench, then rolls the statistics for 444 5184 ek110237 * each flowop into its associated FLOW_MASTER flowop. 445 5184 ek110237 * Next all the FLOW_MASTER flowops' statistics are written 446 5184 ek110237 * to the log file followed by the global totals. Then filebench 447 5184 ek110237 * operation is allowed to resume. 448 5184 ek110237 */ 449 5184 ek110237 void 450 5184 ek110237 stats_snap(void) 451 5184 ek110237 { 452 5184 ek110237 flowstat_t *iostat = &globalstats[FLOW_TYPE_IO]; 453 5184 ek110237 flowstat_t *aiostat = &globalstats[FLOW_TYPE_AIO]; 454 5184 ek110237 flowstat_t *glstat = &globalstats[FLOW_TYPE_GLOBAL]; 455 5184 ek110237 hrtime_t cputime; 456 5184 ek110237 flowop_t *flowop; 457 5184 ek110237 char *str; 458 5184 ek110237 459 5184 ek110237 if (globalstats == NULL) { 460 5184 ek110237 filebench_log(LOG_ERROR, 461 5184 ek110237 "'stats snap' called before 'stats clear'"); 462 5184 ek110237 return; 463 5184 ek110237 } 464 5184 ek110237 465 6084 aw148015 /* don't print out if run ended in error */ 466 6391 aw148015 if (filebench_shm->shm_f_abort == FILEBENCH_ABORT_ERROR) { 467 6084 aw148015 filebench_log(LOG_ERROR, 468 6084 aw148015 "NO VALID RESULTS! FileBench run terminated prematurely"); 469 6084 aw148015 return; 470 6084 aw148015 } 471 6084 aw148015 472 5184 ek110237 globalstats->fs_etime = gethrtime(); 473 5184 ek110237 474 5184 ek110237 filebench_log(LOG_DEBUG_SCRIPT, "Stats period = %ds", 475 5184 ek110237 (globalstats->fs_etime - globalstats->fs_stime) / 1000000000); 476 5184 ek110237 477 5184 ek110237 /* Freeze statistics during update */ 478 6391 aw148015 filebench_shm->shm_bequiet = 1; 479 5184 ek110237 480 6391 aw148015 flowop = filebench_shm->shm_flowoplist; 481 5184 ek110237 while (flowop) { 482 5184 ek110237 flowop_t *flowop_master; 483 5184 ek110237 484 6212 aw148015 if (flowop->fo_instance <= FLOW_DEFINITION) { 485 5184 ek110237 flowop = flowop->fo_next; 486 5184 ek110237 continue; 487 5184 ek110237 } 488 5184 ek110237 489 6212 aw148015 flowop_master = flowop_find_one(flowop->fo_name, FLOW_MASTER); 490 5184 ek110237 491 5184 ek110237 /* Roll up per-flowop into global stats */ 492 5184 ek110237 stats_add(&globalstats[flowop->fo_type], 493 5184 ek110237 &flowop->fo_stats); 494 5184 ek110237 stats_add(&globalstats[FLOW_TYPE_GLOBAL], 495 5184 ek110237 &flowop->fo_stats); 496 5184 ek110237 497 5184 ek110237 if (flowop_master && IS_FLOW_ACTIVE(flowop)) { 498 5184 ek110237 flowop_master->fo_stats.fs_active++; 499 5184 ek110237 } 500 5184 ek110237 501 5184 ek110237 if (flowop_master) { 502 5184 ek110237 /* Roll up per-flow stats into master */ 503 5184 ek110237 flowop_master->fo_stats.fs_children++; 504 5184 ek110237 stats_add(&flowop_master->fo_stats, &flowop->fo_stats); 505 5184 ek110237 } else { 506 5184 ek110237 filebench_log(LOG_DEBUG_NEVER, 507 5184 ek110237 "flowop_stats could not find %s", 508 5184 ek110237 flowop->fo_name); 509 5184 ek110237 } 510 5184 ek110237 511 5184 ek110237 filebench_log(LOG_DEBUG_SCRIPT, 512 5184 ek110237 "flowop %-20s-%4d - %5d ops, %5.1lf, ops/s %5.1lfmb/s " 513 5184 ek110237 "%8.3fms/op", 514 5184 ek110237 flowop->fo_name, 515 5184 ek110237 flowop->fo_instance, 516 5184 ek110237 flowop->fo_stats.fs_count, 517 5184 ek110237 flowop->fo_stats.fs_count / 518 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 519 5184 ek110237 (flowop->fo_stats.fs_bytes / (1024 * 1024)) / 520 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 521 5184 ek110237 flowop->fo_stats.fs_count ? 522 5184 ek110237 flowop->fo_stats.fs_mstate[FLOW_MSTATE_LAT] / 523 5184 ek110237 (flowop->fo_stats.fs_count * 1000000.0) : 0); 524 5184 ek110237 525 5184 ek110237 flowop = flowop->fo_next; 526 5184 ek110237 527 5184 ek110237 } 528 5184 ek110237 529 5184 ek110237 #if defined(HAVE_LIBKSTAT) || defined(LINUX_PORT) 530 5184 ek110237 cputime = kstats_read_cpu_relative(); 531 5184 ek110237 #endif /* HAVE_LIBKSTAT */ 532 5184 ek110237 533 5184 ek110237 filebench_log(LOG_DEBUG_IMPL, 534 6286 aw148015 "cputime = %llu, ohead = %llu", 535 6286 aw148015 (u_longlong_t)(cputime / 1000000000), 536 6286 aw148015 (u_longlong_t)(io_stats_ohead() / 1000000000)); 537 5184 ek110237 iostat->fs_syscpu = 538 5184 ek110237 (cputime > io_stats_ohead()) ? 539 5184 ek110237 (cputime - io_stats_ohead()) : 0; 540 5184 ek110237 glstat->fs_syscpu = 541 5184 ek110237 (cputime > gl_stats_ohead()) ? 542 5184 ek110237 (cputime - gl_stats_ohead()) : 0; 543 5184 ek110237 544 5184 ek110237 545 6391 aw148015 flowop = filebench_shm->shm_flowoplist; 546 5184 ek110237 str = malloc(1048576); 547 6613 ek110237 *str = '\0'; 548 5184 ek110237 (void) strcpy(str, "Per-Operation Breakdown\n"); 549 5184 ek110237 while (flowop) { 550 5184 ek110237 char line[1024]; 551 5184 ek110237 552 5184 ek110237 if (flowop->fo_instance != FLOW_MASTER) { 553 5184 ek110237 flowop = flowop->fo_next; 554 5184 ek110237 continue; 555 5184 ek110237 } 556 5184 ek110237 557 5184 ek110237 (void) snprintf(line, sizeof (line), "%-20s %8.0lfops/s " 558 5184 ek110237 "%5.1lfmb/s %8.1fms/op %8.0fus/op-cpu\n", 559 5184 ek110237 flowop->fo_name, 560 5184 ek110237 flowop->fo_stats.fs_count / 561 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 562 5184 ek110237 (flowop->fo_stats.fs_bytes / (1024 * 1024)) / 563 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 564 5184 ek110237 flowop->fo_stats.fs_count ? 565 5184 ek110237 flowop->fo_stats.fs_mstate[FLOW_MSTATE_LAT] / 566 5184 ek110237 (flowop->fo_stats.fs_count * 1000000.0) : 0, 567 5184 ek110237 flowop->fo_stats.fs_count ? 568 5184 ek110237 flowop->fo_stats.fs_mstate[FLOW_MSTATE_CPU] / 569 5184 ek110237 (flowop->fo_stats.fs_count * 1000.0) : 0); 570 5184 ek110237 (void) strcat(str, line); 571 5184 ek110237 572 5184 ek110237 flowop = flowop->fo_next; 573 5184 ek110237 } 574 5184 ek110237 575 5184 ek110237 filebench_log(LOG_INFO, "%s", str); 576 5184 ek110237 free(str); 577 5184 ek110237 578 5184 ek110237 filebench_log(LOG_INFO, 579 7736 Andrew "\nIO Summary: %5d ops, %5.1lf ops/s, (%0.0lf/%0.0lf r/w) " 580 5184 ek110237 "%5.1lfmb/s, %6.0fus cpu/op, %5.1fms latency", 581 5184 ek110237 iostat->fs_count + aiostat->fs_count, 582 5184 ek110237 (iostat->fs_count + aiostat->fs_count) / 583 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 584 5184 ek110237 (iostat->fs_rcount + aiostat->fs_rcount) / 585 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 586 5184 ek110237 (iostat->fs_wcount + aiostat->fs_wcount) / 587 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 588 5184 ek110237 ((iostat->fs_bytes + aiostat->fs_bytes) / (1024 * 1024)) / 589 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 590 5184 ek110237 (iostat->fs_rcount + iostat->fs_wcount + 591 5184 ek110237 aiostat->fs_rcount + aiostat->fs_wcount) ? 592 5184 ek110237 (iostat->fs_syscpu / 1000.0) / 593 5184 ek110237 (iostat->fs_rcount + iostat->fs_wcount + 594 5184 ek110237 aiostat->fs_rcount + aiostat->fs_wcount) : 0, 595 5184 ek110237 (iostat->fs_rcount + iostat->fs_wcount) ? 596 5184 ek110237 iostat->fs_mstate[FLOW_MSTATE_LAT] / 597 5184 ek110237 ((iostat->fs_rcount + iostat->fs_wcount) * 1000000.0) : 0); 598 5184 ek110237 599 5184 ek110237 600 6391 aw148015 filebench_shm->shm_bequiet = 0; 601 5184 ek110237 } 602 5184 ek110237 603 5184 ek110237 /* 604 5184 ek110237 * Dumps the per-operation statistics and global statistics to the dump file. 605 5184 ek110237 */ 606 5184 ek110237 void 607 5184 ek110237 stats_dump(char *filename) 608 5184 ek110237 { 609 5184 ek110237 flowstat_t *iostat = &globalstats[FLOW_TYPE_IO]; 610 5184 ek110237 flowstat_t *aiostat = &globalstats[FLOW_TYPE_AIO]; 611 5184 ek110237 flowop_t *flowop; 612 5184 ek110237 613 6084 aw148015 /* don't dump stats if run ended in error */ 614 6391 aw148015 if (filebench_shm->shm_f_abort == FILEBENCH_ABORT_ERROR) 615 6084 aw148015 return; 616 6084 aw148015 617 6391 aw148015 (void) strcpy(filebench_shm->shm_dump_filename, filename); 618 5184 ek110237 619 5184 ek110237 filebench_log(LOG_INFO, "in statsdump %s", filename); 620 5184 ek110237 621 6391 aw148015 if (filebench_shm->shm_dump_fd > 0) { 622 6391 aw148015 (void) close(filebench_shm->shm_dump_fd); 623 6391 aw148015 filebench_shm->shm_dump_fd = -1; 624 5184 ek110237 } 625 5184 ek110237 626 5184 ek110237 filebench_log(LOG_DUMP, "Flowop totals:"); 627 5184 ek110237 628 6391 aw148015 flowop = filebench_shm->shm_flowoplist; 629 5184 ek110237 while (flowop) { 630 5184 ek110237 631 5184 ek110237 if (flowop->fo_instance != FLOW_MASTER) { 632 5184 ek110237 flowop = flowop->fo_next; 633 5184 ek110237 continue; 634 5184 ek110237 } 635 5184 ek110237 636 5184 ek110237 filebench_log(LOG_DUMP, 637 5184 ek110237 "%-20s %8.0lfops/s %5.1lfmb/s " 638 5184 ek110237 "%8.1fms/op %8.0fus/op-cpu", 639 5184 ek110237 flowop->fo_name, 640 5184 ek110237 flowop->fo_stats.fs_count / 641 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 642 5184 ek110237 (flowop->fo_stats.fs_bytes / (1024 * 1024)) / 643 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 644 5184 ek110237 flowop->fo_stats.fs_count ? 645 5184 ek110237 flowop->fo_stats.fs_mstate[FLOW_MSTATE_LAT] / 646 5184 ek110237 (flowop->fo_stats.fs_count * 1000000.0) : 0, 647 5184 ek110237 flowop->fo_stats.fs_count ? 648 5184 ek110237 flowop->fo_stats.fs_mstate[FLOW_MSTATE_CPU] / 649 5184 ek110237 (flowop->fo_stats.fs_count * 1000.0) : 0); 650 5184 ek110237 651 5184 ek110237 flowop = flowop->fo_next; 652 5184 ek110237 } 653 5184 ek110237 654 5184 ek110237 filebench_log(LOG_DUMP, ""); 655 5184 ek110237 filebench_log(LOG_DUMP, 656 5184 ek110237 "IO Summary: %8d ops %8.1lf ops/s, %8.0lf/%0.0lf r/w" 657 5184 ek110237 "%8.1lfmb/s, %8.0fuscpu/op", 658 5184 ek110237 659 5184 ek110237 iostat->fs_count + aiostat->fs_count, 660 5184 ek110237 (iostat->fs_count + aiostat->fs_count) / 661 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 662 5184 ek110237 663 5184 ek110237 (iostat->fs_rcount + aiostat->fs_rcount) / 664 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 665 5184 ek110237 666 5184 ek110237 (iostat->fs_wcount + aiostat->fs_wcount) / 667 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 668 5184 ek110237 669 5184 ek110237 ((iostat->fs_bytes + aiostat->fs_bytes) / (1024 * 1024)) / 670 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 671 5184 ek110237 672 5184 ek110237 (iostat->fs_rcount + iostat->fs_wcount + 673 5184 ek110237 aiostat->fs_rcount + aiostat->fs_wcount) ? 674 5184 ek110237 (iostat->fs_syscpu / 1000.0) / 675 5184 ek110237 (iostat->fs_rcount + iostat->fs_wcount + 676 5184 ek110237 aiostat->fs_rcount + aiostat->fs_wcount) : 0); 677 5184 ek110237 } 678 5184 ek110237 679 5184 ek110237 /* 680 5184 ek110237 * Same as stats_dump, but in xml format. 681 5184 ek110237 */ 682 5184 ek110237 void 683 5184 ek110237 stats_xmldump(char *filename) 684 5184 ek110237 { 685 5184 ek110237 flowstat_t *iostat = &globalstats[FLOW_TYPE_IO]; 686 5184 ek110237 flowstat_t *aiostat = &globalstats[FLOW_TYPE_AIO]; 687 5184 ek110237 flowop_t *flowop; 688 6084 aw148015 689 6084 aw148015 /* don't dump stats if run ended in error */ 690 6391 aw148015 if (filebench_shm->shm_f_abort == FILEBENCH_ABORT_ERROR) 691 6084 aw148015 return; 692 5184 ek110237 693 6391 aw148015 (void) strcpy(filebench_shm->shm_dump_filename, filename); 694 5184 ek110237 695 6391 aw148015 if (filebench_shm->shm_dump_fd > 0) { 696 6391 aw148015 (void) close(filebench_shm->shm_dump_fd); 697 6391 aw148015 filebench_shm->shm_dump_fd = -1; 698 5184 ek110237 } 699 5184 ek110237 700 5184 ek110237 filebench_log(LOG_DUMP, "<stat_doc name=\"Filebench Workload\">"); 701 5184 ek110237 filebench_log(LOG_DUMP, "<stat_group name=\"Flowop totals\">"); 702 5184 ek110237 filebench_log(LOG_DUMP, "<cell_list>"); 703 5184 ek110237 704 6391 aw148015 flowop = filebench_shm->shm_flowoplist; 705 5184 ek110237 while (flowop) { 706 5184 ek110237 if (flowop->fo_instance != FLOW_MASTER) { 707 5184 ek110237 flowop = flowop->fo_next; 708 5184 ek110237 continue; 709 5184 ek110237 } 710 5184 ek110237 711 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.0lf</cell>", 712 5184 ek110237 flowop->fo_stats.fs_count / 713 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS)); 714 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.1lf</cell>", 715 5184 ek110237 (flowop->fo_stats.fs_bytes / (1024 * 1024)) / 716 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS)); 717 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.1lf</cell>", 718 5184 ek110237 flowop->fo_stats.fs_count ? 719 5184 ek110237 flowop->fo_stats.fs_mstate[FLOW_MSTATE_LAT] / 720 5184 ek110237 (flowop->fo_stats.fs_count * 1000000.0) : 0); 721 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.0lf</cell>", 722 5184 ek110237 flowop->fo_stats.fs_count ? 723 5184 ek110237 flowop->fo_stats.fs_mstate[FLOW_MSTATE_CPU] / 724 5184 ek110237 (flowop->fo_stats.fs_count * 1000.0) : 0); 725 5184 ek110237 726 5184 ek110237 flowop = flowop->fo_next; 727 5184 ek110237 } 728 5184 ek110237 filebench_log(LOG_DUMP, "</cell_list>"); 729 5184 ek110237 730 5184 ek110237 filebench_log(LOG_DUMP, "<dim_list>"); 731 5184 ek110237 filebench_log(LOG_DUMP, "<dim>"); 732 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>Operations/sec</dimval>"); 733 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>MB/sec</dimval>"); 734 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>Latency (ms per operation)</dimval>"); 735 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>CPU (us per operation)</dimval>"); 736 5184 ek110237 filebench_log(LOG_DUMP, "</dim>"); 737 5184 ek110237 738 5184 ek110237 filebench_log(LOG_DUMP, "<dim>"); 739 6391 aw148015 flowop = filebench_shm->shm_flowoplist; 740 5184 ek110237 while (flowop) { 741 5184 ek110237 if (flowop->fo_instance != FLOW_MASTER) { 742 5184 ek110237 flowop = flowop->fo_next; 743 5184 ek110237 continue; 744 5184 ek110237 } 745 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>%s</dimval>", flowop->fo_name); 746 5184 ek110237 flowop = flowop->fo_next; 747 5184 ek110237 } 748 5184 ek110237 filebench_log(LOG_DUMP, "</dim>"); 749 5184 ek110237 filebench_log(LOG_DUMP, "</dim_list>"); 750 5184 ek110237 filebench_log(LOG_DUMP, "</stat_group>"); 751 5184 ek110237 752 5184 ek110237 filebench_log(LOG_DUMP, "<stat_group name=\"IO Summary\">"); 753 5184 ek110237 filebench_log(LOG_DUMP, "<cell_list>"); 754 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0d</cell>", 755 5184 ek110237 iostat->fs_count + aiostat->fs_count); 756 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.1lf</cell>", 757 5184 ek110237 (iostat->fs_count + aiostat->fs_count) / 758 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS)); 759 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.0lf</cell>", 760 5184 ek110237 (iostat->fs_rcount + aiostat->fs_rcount) / 761 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS)); 762 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.0lf</cell>", 763 5184 ek110237 (iostat->fs_wcount + aiostat->fs_wcount) / 764 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS)); 765 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.1lf</cell>", 766 5184 ek110237 ((iostat->fs_bytes + aiostat->fs_bytes) / (1024 * 1024)) / 767 5184 ek110237 ((globalstats->fs_etime - globalstats->fs_stime) / FSECS)); 768 5184 ek110237 filebench_log(LOG_DUMP, "<cell>%0.0f</cell>", 769 5184 ek110237 (iostat->fs_rcount + iostat->fs_wcount + aiostat->fs_rcount + 770 5184 ek110237 aiostat->fs_wcount) ? (iostat->fs_syscpu / 1000.0) / 771 5184 ek110237 (iostat->fs_rcount + iostat->fs_wcount + aiostat->fs_rcount + 772 5184 ek110237 aiostat->fs_wcount) : 0); 773 5184 ek110237 filebench_log(LOG_DUMP, "</cell_list>"); 774 5184 ek110237 775 5184 ek110237 filebench_log(LOG_DUMP, "<dim_list>"); 776 5184 ek110237 filebench_log(LOG_DUMP, "<dim>"); 777 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>Operations</dimval>"); 778 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>Operations/sec</dimval>"); 779 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>Reads</dimval>"); 780 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>Writes</dimval>"); 781 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>MB/sec</dimval>"); 782 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>CPU (us per operation)</dimval>"); 783 5184 ek110237 filebench_log(LOG_DUMP, "</dim>"); 784 5184 ek110237 785 5184 ek110237 filebench_log(LOG_DUMP, "<dim>"); 786 5184 ek110237 filebench_log(LOG_DUMP, "<dimval>IO Summary</dimval>"); 787 5184 ek110237 filebench_log(LOG_DUMP, "</dim>"); 788 5184 ek110237 filebench_log(LOG_DUMP, "</dim_list>"); 789 5184 ek110237 filebench_log(LOG_DUMP, "</stat_group>"); 790 5184 ek110237 filebench_log(LOG_DUMP, "</stat_doc>"); 791 5184 ek110237 } 792 5184 ek110237 793 5184 ek110237 /* 794 7736 Andrew * same as stats_dump, but in computer friendly format 795 7736 Andrew */ 796 7736 Andrew void 797 7736 Andrew stats_multidump(char *filename) 798 7736 Andrew { 799 7736 Andrew flowstat_t *iostat = &globalstats[FLOW_TYPE_IO]; 800 7736 Andrew flowstat_t *aiostat = &globalstats[FLOW_TYPE_AIO]; 801 7736 Andrew flowop_t *flowop; 802 7736 Andrew 803 7736 Andrew /* don't dump stats if run ended in error */ 804 7736 Andrew if (filebench_shm->shm_f_abort == FILEBENCH_ABORT_ERROR) 805 7736 Andrew return; 806 7736 Andrew 807 7736 Andrew (void) strcpy(filebench_shm->shm_dump_filename, filename); 808 7736 Andrew 809 7736 Andrew filebench_log(LOG_INFO, "in statsmultidump %s", filename); 810 7736 Andrew 811 7736 Andrew if (filebench_shm->shm_dump_fd > 0) { 812 7736 Andrew (void) close(filebench_shm->shm_dump_fd); 813 7736 Andrew filebench_shm->shm_dump_fd = -1; 814 7736 Andrew } 815 7736 Andrew 816 7736 Andrew filebench_log(LOG_DUMP, "Flowop totals:"); 817 7736 Andrew 818 7736 Andrew flowop = filebench_shm->shm_flowoplist; 819 7736 Andrew while (flowop) { 820 7736 Andrew 821 7736 Andrew if (flowop->fo_instance != FLOW_MASTER) { 822 7736 Andrew flowop = flowop->fo_next; 823 7736 Andrew continue; 824 7736 Andrew } 825 7736 Andrew 826 7736 Andrew filebench_log(LOG_DUMP, 827 7736 Andrew "%s\t%1.0lf\t%1.1lf\t%1.1f\t%1.0f", 828 7736 Andrew flowop->fo_name, 829 7736 Andrew flowop->fo_stats.fs_count / 830 7736 Andrew ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 831 7736 Andrew (flowop->fo_stats.fs_bytes / (1024 * 1024)) / 832 7736 Andrew ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 833 7736 Andrew flowop->fo_stats.fs_count ? 834 7736 Andrew flowop->fo_stats.fs_mstate[FLOW_MSTATE_LAT] / 835 7736 Andrew (flowop->fo_stats.fs_count * 1000000.0) : 0, 836 7736 Andrew flowop->fo_stats.fs_count ? 837 7736 Andrew flowop->fo_stats.fs_mstate[FLOW_MSTATE_CPU] / 838 7736 Andrew (flowop->fo_stats.fs_count * 1000.0) : 0); 839 7736 Andrew 840 7736 Andrew flowop = flowop->fo_next; 841 7736 Andrew } 842 7736 Andrew 843 7736 Andrew filebench_log(LOG_DUMP, ""); 844 7736 Andrew filebench_log(LOG_DUMP, 845 7736 Andrew "IO Summary:\n%d\t%1.1lf\t%1.0lf\t%1.0lf\t%1.1lf\t%1.0f\t%1.1f\n", 846 7736 Andrew 847 7736 Andrew iostat->fs_count + aiostat->fs_count, 848 7736 Andrew 849 7736 Andrew (iostat->fs_count + aiostat->fs_count) / 850 7736 Andrew ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 851 7736 Andrew 852 7736 Andrew (iostat->fs_rcount + aiostat->fs_rcount) / 853 7736 Andrew ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 854 7736 Andrew 855 7736 Andrew (iostat->fs_wcount + aiostat->fs_wcount) / 856 7736 Andrew ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 857 7736 Andrew 858 7736 Andrew ((iostat->fs_bytes + aiostat->fs_bytes) / (1024 * 1024)) / 859 7736 Andrew ((globalstats->fs_etime - globalstats->fs_stime) / FSECS), 860 7736 Andrew 861 7736 Andrew (iostat->fs_rcount + iostat->fs_wcount + 862 7736 Andrew aiostat->fs_rcount + aiostat->fs_wcount) ? 863 7736 Andrew (iostat->fs_syscpu / 1000.0) / 864 7736 Andrew (iostat->fs_rcount + iostat->fs_wcount + 865 7736 Andrew aiostat->fs_rcount + aiostat->fs_wcount) : 0, 866 7736 Andrew 867 7736 Andrew (iostat->fs_rcount + iostat->fs_wcount) ? 868 7736 Andrew iostat->fs_mstate[FLOW_MSTATE_LAT] / 869 7736 Andrew ((iostat->fs_rcount + iostat->fs_wcount) * 1000000.0) : 0); 870 7736 Andrew } 871 7736 Andrew 872 7736 Andrew /* 873 5184 ek110237 * Clears all the statistics variables (fo_stats) for every defined flowop. 874 5184 ek110237 * It also creates a global flowstat table if one doesn't already exist and 875 5184 ek110237 * clears it. 876 5184 ek110237 */ 877 5184 ek110237 void 878 5184 ek110237 stats_clear(void) 879 5184 ek110237 { 880 5184 ek110237 flowop_t *flowop; 881 5184 ek110237 882 5184 ek110237 #ifdef HAVE_LIBKSTAT 883 5184 ek110237 stats_cputime = kstats_read_cpu(); 884 5184 ek110237 #else 885 5184 ek110237 stats_cputime = 0; 886 5184 ek110237 #endif /* HAVE_LIBKSTAT */ 887 5184 ek110237 888 5184 ek110237 if (globalstats == NULL) 889 5184 ek110237 globalstats = malloc(FLOW_TYPES * sizeof (flowstat_t)); 890 5184 ek110237 891 5184 ek110237 (void) memset(globalstats, 0, FLOW_TYPES * sizeof (flowstat_t)); 892 5184 ek110237 893 6391 aw148015 flowop = filebench_shm->shm_flowoplist; 894 5184 ek110237 895 5184 ek110237 while (flowop) { 896 5184 ek110237 filebench_log(LOG_DEBUG_IMPL, "Clearing stats for %s-%d", 897 5184 ek110237 flowop->fo_name, 898 5184 ek110237 flowop->fo_instance); 899 5184 ek110237 (void) memset(&flowop->fo_stats, 0, sizeof (flowstat_t)); 900 5184 ek110237 flowop = flowop->fo_next; 901 5184 ek110237 } 902 5184 ek110237 903 5184 ek110237 (void) memset(globalstats, 0, sizeof (flowstat_t)); 904 5184 ek110237 globalstats->fs_stime = gethrtime(); 905 5184 ek110237 } 906