diff --git a/configure.ac b/configure.ac index 6503dd3..71d6c03 100644 --- a/configure.ac +++ b/configure.ac @@ -206,6 +206,7 @@ sys/mman.h \ sys/shm.h \ thread.h \ unistd.h \ +limits.h \ ]) diff --git a/sysbench/sb_list.h b/sysbench/sb_list.h index 27ad67b..5c68c78 100644 --- a/sysbench/sb_list.h +++ b/sysbench/sb_list.h @@ -85,7 +85,7 @@ typedef sb_list_item_t sb_list_t ; ((item_p)->prev_p != (head_p)) #define SB_LIST_ITEM_LAST(item_p, head_p) \ - ((item_p)->next_p != (head_p)) + ((item_p)->next_p == (head_p)) #define SB_LIST_ITEM_NEXT(item_p) \ ((item_p)->next_p) diff --git a/sysbench/sb_logger.c b/sysbench/sb_logger.c index 2610698..103898d 100644 --- a/sysbench/sb_logger.c +++ b/sysbench/sb_logger.c @@ -46,6 +46,9 @@ #define OPER_LOG_MIN_VALUE 1 #define OPER_LOG_MAX_VALUE 1E13 +/* per-thread timers for response time stats */ +sb_timer_t *timers; + /* Array of message handlers (one chain per message type) */ static sb_list_t handlers[LOG_MSG_TYPE_MAX]; @@ -63,6 +66,15 @@ static pthread_mutex_t text_mutex; static unsigned int text_cnt; static char text_buf[TEXT_BUFFER_SIZE]; +/* Temporary copy of timers */ +static sb_timer_t *timers_copy; + +/* + Mutex protecting timers. + TODO: replace with an rwlock (and implement pthread rwlocks for Windows). +*/ +static pthread_mutex_t timers_mutex; + static int text_handler_init(void); static int text_handler_process(log_msg_t *msg); @@ -472,6 +484,8 @@ int text_handler_process(log_msg_t *msg) int oper_handler_init(void) { + unsigned int i; + oper_percentile = sb_get_value_int("percentile"); if (oper_percentile < 1 || oper_percentile > 100) { @@ -484,6 +498,20 @@ int oper_handler_init(void) OPER_LOG_MAX_VALUE)) return 1; + timers = (sb_timer_t *)malloc(sb_globals.num_threads * sizeof(sb_timer_t)); + timers_copy = (sb_timer_t *)malloc(sb_globals.num_threads * + sizeof(sb_timer_t)); + if (timers == NULL || timers_copy == NULL) + { + log_text(LOG_FATAL, "Memory allocation failure"); + return 1; + } + + for (i = 0; i < sb_globals.num_threads; i++) + sb_timer_init(&timers[i]); + + pthread_mutex_init(&timers_mutex, NULL); + return 0; } @@ -494,27 +522,36 @@ int oper_handler_init(void) int oper_handler_process(log_msg_t *msg) { log_msg_oper_t *oper_msg = (log_msg_oper_t *)msg->data; - sb_timer_t *timer = sb_globals.op_timers + oper_msg->thread_id; + sb_timer_t *timer = &timers[oper_msg->thread_id]; long long value; if (oper_msg->action == LOG_MSG_OPER_START) { + pthread_mutex_lock(&timers_mutex); sb_timer_start(timer); + pthread_mutex_unlock(&timers_mutex); + return 0; } + pthread_mutex_lock(&timers_mutex); + sb_timer_stop(timer); value = sb_timer_value(timer); + + pthread_mutex_unlock(&timers_mutex); + sb_percentile_update(&percentile, value); return 0; } +/* + Print global stats either from the last checkpoint (if used) or + from the test start. +*/ -/* Uninitialize operations messages handler */ - - -int oper_handler_done(void) +int print_global_stats(void) { double diff; unsigned int i; @@ -525,23 +562,40 @@ int oper_handler_done(void) double events_stddev; double time_avg; double time_stddev; + double percentile_val; + unsigned long long total_time_ns; sb_timer_init(&t); nthreads = sb_globals.num_threads; - for(i = 0; i < nthreads; i++) - t = merge_timers(&t,&(sb_globals.op_timers[i])); - /* Print total statistics */ + /* Create a temporary copy of timers and reset them */ + pthread_mutex_lock(&timers_mutex); + + memcpy(timers_copy, timers, sb_globals.num_threads * sizeof(sb_timer_t)); + for (i = 0; i < sb_globals.num_threads; i++) + sb_timer_reset(&timers[i]); + + total_time_ns = sb_timer_split(&sb_globals.cumulative_timer2); + + percentile_val = sb_percentile_calculate(&percentile, oper_percentile); + sb_percentile_reset(&percentile); + + pthread_mutex_unlock(&timers_mutex); + + for(i = 0; i < nthreads; i++) + t = merge_timers(&t, &timers_copy[i]); + +/* Print total statistics */ log_text(LOG_NOTICE, ""); - log_text(LOG_NOTICE, "Test execution summary:"); + log_text(LOG_NOTICE, "General statistics:"); log_text(LOG_NOTICE, " total time: %.4fs", - NS2SEC(sb_timer_value(&sb_globals.exec_timer))); + NS2SEC(total_time_ns)); log_text(LOG_NOTICE, " total number of events: %lld", t.events); log_text(LOG_NOTICE, " total time taken by event execution: %.4f", NS2SEC(get_sum_time(&t))); - log_text(LOG_NOTICE, " per-request statistics:"); + log_text(LOG_NOTICE, " response time:"); log_text(LOG_NOTICE, " min: %10.2fms", NS2MS(get_min_time(&t))); log_text(LOG_NOTICE, " avg: %10.2fms", @@ -553,8 +607,7 @@ int oper_handler_done(void) if (t.events > 0) { log_text(LOG_NOTICE, " approx. %3d percentile: %10.2fms", - oper_percentile, - NS2MS(sb_percentile_calculate(&percentile, oper_percentile))); + oper_percentile, NS2MS(percentile_val)); } log_text(LOG_NOTICE, ""); @@ -570,10 +623,10 @@ int oper_handler_done(void) time_stddev = 0; for(i = 0; i < nthreads; i++) { - diff = fabs(events_avg - sb_globals.op_timers[i].events); + diff = fabs(events_avg - timers_copy[i].events); events_stddev += diff*diff; - diff = fabs(time_avg - NS2SEC(get_sum_time(&sb_globals.op_timers[i]))); + diff = fabs(time_avg - NS2SEC(get_sum_time(&timers_copy[i]))); time_stddev += diff*diff; } events_stddev = sqrt(events_stddev / nthreads); @@ -593,13 +646,13 @@ int oper_handler_done(void) { log_text(LOG_DEBUG, " thread #%3d: min: %.4fs avg: %.4fs max: %.4fs " "events: %lld",i, - NS2SEC(get_min_time(&sb_globals.op_timers[i])), - NS2SEC(get_avg_time(&sb_globals.op_timers[i])), - NS2SEC(get_max_time(&sb_globals.op_timers[i])), - sb_globals.op_timers[i].events); + NS2SEC(get_min_time(&timers_copy[i])), + NS2SEC(get_avg_time(&timers_copy[i])), + NS2SEC(get_max_time(&timers_copy[i])), + timers_copy[i].events); log_text(LOG_DEBUG, " " "total time taken by even execution: %.4fs", - NS2SEC(get_sum_time(&sb_globals.op_timers[i])) + NS2SEC(get_sum_time(&timers_copy[i])) ); } log_text(LOG_NOTICE, ""); @@ -607,3 +660,17 @@ int oper_handler_done(void) return 0; } + +/* Uninitialize operations messages handler */ + +int oper_handler_done(void) +{ + print_global_stats(); + + free(timers); + free(timers_copy); + + pthread_mutex_destroy(&timers_mutex); + + return 0; +} diff --git a/sysbench/sb_logger.h b/sysbench/sb_logger.h index 4403354..740eec5 100644 --- a/sysbench/sb_logger.h +++ b/sysbench/sb_logger.h @@ -118,6 +118,9 @@ typedef struct { sb_list_item_t listitem; /* can be linked in a list */ } log_handler_t; +/* per-thread timers for response time stats */ +extern sb_timer_t *timers; + /* Register logger */ int log_register(void); @@ -158,4 +161,11 @@ void log_errno(log_msg_priority_t priority, const char *fmt, ...); void log_done(void); +/* + Print global stats either from the last checkpoint (if used) or + from the test start. +*/ + +int print_global_stats(void); + #endif /* SB_LOGGER_H */ diff --git a/sysbench/sb_options.c b/sysbench/sb_options.c index 25840f8..3c5092c 100644 --- a/sysbench/sb_options.c +++ b/sysbench/sb_options.c @@ -29,6 +29,10 @@ # include #endif +#ifdef HAVE_LIMITS_H +# include +#endif + #include "sb_options.h" #define VALUE_DELIMITER '=' @@ -177,6 +181,8 @@ int sb_get_value_int(const char *name) option_t *opt; value_t *val; sb_list_item_t *pos; + long res; + char *endptr; opt = find_option(&options, name); if (opt == NULL) @@ -185,7 +191,14 @@ int sb_get_value_int(const char *name) SB_LIST_FOR_EACH(pos, &opt->values) { val = SB_LIST_ENTRY(pos, value_t, listitem); - return atoi(val->data); + res = strtol(val->data, &endptr, 10); + if (*endptr != '\0' || res > INT_MAX || res < INT_MIN) + { + fprintf(stderr, "Invalid value for the '%s' option: '%s'\n", + name, val->data); + exit(EXIT_FAILURE); + } + return (int) res; } return 0; @@ -606,4 +619,3 @@ int write_config(FILE *fp, sb_list_t *options) return 0; } - diff --git a/sysbench/sb_timer.c b/sysbench/sb_timer.c index a9443bd..cd5ec4e 100644 --- a/sysbench/sb_timer.c +++ b/sysbench/sb_timer.c @@ -34,25 +34,40 @@ static inline void sb_timer_update(sb_timer_t *t) { - struct timespec time_end; - - SB_GETTIME(&time_end); - t->elapsed = TIMESPEC_DIFF(time_end, t->time_start); + SB_GETTIME(&t->time_end); + t->elapsed = TIMESPEC_DIFF(t->time_end, t->time_start); } /* initialize timer */ void sb_timer_init(sb_timer_t *t) +{ + memset(&t->time_start, 0, sizeof(struct timespec)); + memset(&t->time_end, 0, sizeof(struct timespec)); + memset(&t->time_split, 0, sizeof(struct timespec)); + sb_timer_reset(t); + t->state = TIMER_INITIALIZED; +} + + +/* Reset timer counters, but leave the current state intact */ +void sb_timer_reset(sb_timer_t *t) { t->min_time = 0xffffffffffffffffULL; t->max_time = 0; t->sum_time = 0; t->events = 0; - t->state = TIMER_INITIALIZED; + t->elapsed = 0; } +/* check whether the timer is initialized */ +int sb_timer_initialized(sb_timer_t *t) +{ + return t->state != TIMER_UNINITIALIZED; +} + /* start timer */ @@ -148,8 +163,15 @@ unsigned long long sb_timer_split(sb_timer_t *t) log_text(LOG_WARNING, "timer was never started"); return 0; case TIMER_STOPPED: - log_text(LOG_WARNING, "timer was already stopped"); - return 0;; + res = TIMESPEC_DIFF(t->time_end, t->time_split); + t->time_split = t->time_end; + if (res) + return res; + else + { + log_text(LOG_WARNING, "timer was already stopped"); + return 0; + } case TIMER_RUNNING: break; default: diff --git a/sysbench/sb_timer.h b/sysbench/sb_timer.h index 10ac905..dacb0ea 100644 --- a/sysbench/sb_timer.h +++ b/sysbench/sb_timer.h @@ -69,6 +69,7 @@ typedef enum {TIMER_UNINITIALIZED, TIMER_INITIALIZED, TIMER_STOPPED, \ typedef struct { struct timespec time_start; + struct timespec time_end; struct timespec time_split; unsigned long long elapsed; unsigned long long min_time; @@ -84,6 +85,12 @@ typedef struct /* Initialize timer */ void sb_timer_init(sb_timer_t *); +/* Reset timer counters, but leave the current state intact */ +void sb_timer_reset(sb_timer_t *t); + +/* check whether the timer is initialized */ +int sb_timer_initialized(sb_timer_t *t); + /* start timer */ void sb_timer_start(sb_timer_t *); diff --git a/sysbench/sysbench.c b/sysbench/sysbench.c index f38270d..eac3990 100644 --- a/sysbench/sysbench.c +++ b/sysbench/sysbench.c @@ -59,6 +59,9 @@ #ifdef HAVE_SIGNAL_H # include #endif +#ifdef HAVE_LIMITS_H +# include +#endif #include "sysbench.h" #include "sb_options.h" @@ -91,6 +94,11 @@ sb_arg_t general_args[] = {"report-interval", "periodically report intermediate statistics " "with a specified interval in seconds. 0 disables intermediate reports", SB_ARG_TYPE_INT, "0"}, + {"report-checkpoints", "dump full statistics and reset all counters at " + "specified points in time. The argument is a list of comma-separated values " + "representing the amount of time in seconds elapsed from start of test " + "when report checkpoint(s) must be performed. Report checkpoints are off by " + "default.", SB_ARG_TYPE_LIST, ""}, {"test", "test to run", SB_ARG_TYPE_STRING, NULL}, {"debug", "print more debugging info", SB_ARG_TYPE_FLAG, "off"}, {"validate", "perform validation checks where possible", SB_ARG_TYPE_FLAG, "off"}, @@ -125,6 +133,8 @@ static void sigalrm_handler(int sig) if (sig == SIGALRM) { sb_timer_stop(&sb_globals.exec_timer); + sb_timer_stop(&sb_globals.cumulative_timer1); + sb_timer_stop(&sb_globals.cumulative_timer2); log_text(LOG_FATAL, "The --max-time limit has expired, forcing shutdown..."); if (current_test && current_test->ops.print_stats) @@ -337,6 +347,27 @@ void print_run_mode(sb_test_t *test) sb_globals.report_interval); } + if (sb_globals.n_checkpoints > 0) + { + char list_str[MAX_CHECKPOINTS * 12]; + char *tmp = list_str; + unsigned int i; + int n, size = sizeof(list_str); + + for (i = 0; i < sb_globals.n_checkpoints - 1; i++) + { + n = snprintf(tmp, size, "%u, ", sb_globals.checkpoints[i]); + if (n >= size) + break; + tmp += n; + size -= n; + } + if (i == sb_globals.n_checkpoints - 1) + snprintf(tmp, size, "%u", sb_globals.checkpoints[i]); + log_text(LOG_NOTICE, "Report checkpoint(s) at %s seconds", + list_str); + } + if (sb_globals.debug) log_text(LOG_NOTICE, "Debug mode enabled.\n"); @@ -511,6 +542,53 @@ static void *report_thread_proc(void *arg) return NULL; } +/* Checkpoints reports thread */ + +static void *checkpoints_thread_proc(void *arg) +{ + unsigned long long pause_ns; + unsigned long long next_ns; + unsigned long long curr_ns; + unsigned int i; + + (void)arg; /* unused */ + + if (current_test->ops.print_stats == NULL) + { + log_text(LOG_DEBUG, "Reporting not supported by the current test, ", + "terminating the reporting thread"); + return NULL; + } + + log_text(LOG_DEBUG, "Checkpoints report thread started"); + + pthread_mutex_lock(&thread_start_mutex); + pthread_mutex_unlock(&thread_start_mutex); + + for (i = 0; i < sb_globals.n_checkpoints; i++) + { + next_ns = SEC2NS(sb_globals.checkpoints[i]); + curr_ns = sb_timer_value(&sb_globals.exec_timer); + if (next_ns <= curr_ns) + continue; + + pause_ns = next_ns - curr_ns; + usleep(pause_ns / 1000); + /* + Just to update elapsed time in timer which is alter used by + log_timestamp. + */ + curr_ns = sb_timer_value(&sb_globals.exec_timer); + + SB_THREAD_MUTEX_LOCK(); + log_timestamp(LOG_NOTICE, &sb_globals.exec_timer, "Checkpoint report:"); + current_test->ops.print_stats(SB_STAT_CUMULATIVE); + print_global_stats(); + SB_THREAD_MUTEX_UNLOCK(); + } + + return NULL; +} /* Main test function. Start threads. @@ -522,7 +600,9 @@ static int run_test(sb_test_t *test) unsigned int i; int err; pthread_t report_thread; + pthread_t checkpoints_thread; int report_thread_created = 0; + int checkpoints_thread_created = 0; /* initialize test */ if (test->ops.init != NULL && test->ops.init() != 0) @@ -533,9 +613,10 @@ static int run_test(sb_test_t *test) /* initialize and start timers */ sb_timer_init(&sb_globals.exec_timer); + sb_timer_init(&sb_globals.cumulative_timer1); + sb_timer_init(&sb_globals.cumulative_timer2); for(i = 0; i < sb_globals.num_threads; i++) { - sb_timer_init(&sb_globals.op_timers[i]); threads[i].id = i; threads[i].test = test; } @@ -575,6 +656,19 @@ static int run_test(sb_test_t *test) report_thread_created = 1; } + if (sb_globals.n_checkpoints > 0) + { + /* Create a thread for checkpoint statistic reports */ + if ((err = pthread_create(&checkpoints_thread, &thread_attr, + &checkpoints_thread_proc, NULL)) != 0) + { + log_errno(LOG_FATAL, "pthread_create() for the checkpoint thread " + "failed."); + return 1; + } + checkpoints_thread_created = 1; + } + /* Starting the test threads */ for(i = 0; i < sb_globals.num_threads; i++) { @@ -589,6 +683,8 @@ static int run_test(sb_test_t *test) } sb_timer_start(&sb_globals.exec_timer); /* Start benchmark timer */ + sb_timer_start(&sb_globals.cumulative_timer1); + sb_timer_start(&sb_globals.cumulative_timer2); #ifdef HAVE_ALARM /* Set the alarm to force shutdown */ @@ -607,6 +703,8 @@ static int run_test(sb_test_t *test) } sb_timer_stop(&sb_globals.exec_timer); + sb_timer_stop(&sb_globals.cumulative_timer1); + sb_timer_stop(&sb_globals.cumulative_timer2); /* Silence periodic reports if they were on */ sb_globals.report_interval = 0; @@ -633,12 +731,18 @@ static int run_test(sb_test_t *test) if (test->ops.done != NULL) (*(test->ops.done))(); - /* Delay killing the reporting thread to avoid mutex lock leaks */ + /* Delay killing the reporting threads to avoid mutex lock leaks */ if (report_thread_created) { if (pthread_cancel(report_thread) || pthread_join(report_thread, NULL)) log_errno(LOG_FATAL, "Terminating the reporting thread failed."); } + if (checkpoints_thread_created) + { + if (pthread_cancel(checkpoints_thread) || + pthread_join(checkpoints_thread, NULL)) + log_errno(LOG_FATAL, "Terminating the checkpoint thread failed."); + } return sb_globals.error != 0; } @@ -660,10 +764,23 @@ static sb_test_t *find_test(char *name) } +static int checkpoint_cmp(const void *a_ptr, const void *b_ptr) +{ + const unsigned int a = *(const unsigned int *) a_ptr; + const unsigned int b = *(const unsigned int *) b_ptr; + + return (int) (a - b); +} + + static int init(void) { option_t *opt; char *tmp; + sb_list_t *checkpoints_list; + sb_list_item_t *pos_val; + value_t *val; + long res; sb_globals.num_threads = sb_get_value_int("num-threads"); if (sb_globals.num_threads <= 0) @@ -703,12 +820,10 @@ static int init(void) else sb_globals.force_shutdown = 0; } - - sb_globals.op_timers = (sb_timer_t *)malloc(sb_globals.num_threads * - sizeof(sb_timer_t)); + threads = (sb_thread_ctxt_t *)malloc(sb_globals.num_threads * sizeof(sb_thread_ctxt_t)); - if (sb_globals.op_timers == NULL || threads == NULL) + if (threads == NULL) { log_text(LOG_FATAL, "Memory allocation failure.\n"); return 1; @@ -740,9 +855,37 @@ static int init(void) } sb_globals.tx_rate = sb_get_value_int("tx-rate"); sb_globals.tx_jitter = sb_get_value_int("tx-jitter"); - sb_globals.report_interval = - sb_get_value_int("report-interval"); - + sb_globals.report_interval = sb_get_value_int("report-interval"); + + sb_globals.n_checkpoints = 0; + checkpoints_list = sb_get_value_list("report-checkpoints"); + SB_LIST_FOR_EACH(pos_val, checkpoints_list) + { + char *endptr; + + val = SB_LIST_ENTRY(pos_val, value_t, listitem); + res = strtol(val->data, &endptr, 10); + if (*endptr != '\0' || res < 0 || res > UINT_MAX) + { + log_text(LOG_FATAL, "Invalid value for --report-checkpoints: '%s'", + val->data); + return 1; + } + if (++sb_globals.n_checkpoints > MAX_CHECKPOINTS) + { + log_text(LOG_FATAL, "Too many checkpoints in --report-checkpoints " + "(up to %d can be defined)", MAX_CHECKPOINTS); + return 1; + } + sb_globals.checkpoints[sb_globals.n_checkpoints-1] = (unsigned int) res; + } + + if (sb_globals.n_checkpoints > 0) + { + qsort(sb_globals.checkpoints, sb_globals.n_checkpoints, + sizeof(unsigned int), checkpoint_cmp); + } + return 0; } diff --git a/sysbench/sysbench.h b/sysbench/sysbench.h index 692a217..7106c95 100644 --- a/sysbench/sysbench.h +++ b/sysbench/sysbench.h @@ -53,6 +53,9 @@ #define SB_MAX_RND 0x3fffffffu +/* Maximum number of elements in --report-checkpoints list */ +#define MAX_CHECKPOINTS 256 + /* random() is not thread-safe on most platforms, use lrand48() if available */ #ifdef HAVE_LRAND48 #define sb_rnd() (lrand48() % SB_MAX_RND) @@ -192,11 +195,16 @@ typedef struct sb_cmd_t command; /* command passed from command line */ int error; /* global error - everyone exit */ pthread_mutex_t exec_mutex; /* execution mutex */ - sb_timer_t *op_timers; /* timers to measure each thread's run time */ sb_timer_t exec_timer; /* total execution timer */ + /* timers for cumulative reports */ + sb_timer_t cumulative_timer1; + sb_timer_t cumulative_timer2; unsigned int num_threads; /* number of threads to use */ unsigned int num_running; /* number of threads currently active */ unsigned int report_interval;/* intermediate reports interval */ + /* array of report checkpoints */ + unsigned int checkpoints[MAX_CHECKPOINTS]; + unsigned int n_checkpoints; /* number of checkpoints */ unsigned int tx_rate; /* target transaction rate */ unsigned int tx_jitter; /* target transaction variation (us) */ unsigned int max_requests; /* maximum number of requests */ diff --git a/sysbench/tests/fileio/sb_fileio.c b/sysbench/tests/fileio/sb_fileio.c index 862bf60..87c334b 100644 --- a/sysbench/tests/fileio/sb_fileio.c +++ b/sysbench/tests/fileio/sb_fileio.c @@ -259,6 +259,7 @@ static int create_files(void); static int remove_files(void); static int parse_arguments(void); static void clear_stats(void); +static void init_vars(void); static sb_request_t file_get_seq_request(void); static sb_request_t file_get_rnd_request(void); static void check_seq_req(sb_file_request_t *, sb_file_request_t *); @@ -313,6 +314,7 @@ int file_init(void) return 1; #endif + init_vars(); clear_stats(); return 0; @@ -785,7 +787,7 @@ void file_print_stats(sb_stat_t type) } case SB_STAT_CUMULATIVE: - seconds = NS2SEC(sb_timer_value(&sb_globals.exec_timer)); + seconds = NS2SEC(sb_timer_split(&sb_globals.cumulative_timer1)); log_text(LOG_NOTICE, "Operations performed: %d reads, %d writes, %d Other = %d Total", @@ -799,6 +801,8 @@ void file_print_stats(sb_stat_t type) (bytes_read + bytes_written) / seconds)); log_text(LOG_NOTICE, "%8.2f Requests/sec executed", (read_ops + write_ops) / seconds); + clear_stats(); + break; } } @@ -962,12 +966,25 @@ int file_cmd_cleanup(void) return remove_files(); } -void clear_stats(void) +void init_vars(void) { position = 0; /* position in file */ current_file = 0; fsynced_file = 0; /* for counting file to be fsynced */ fsynced_file2 = 0; + req_performed = 0; + is_dirty = 0; + if (sb_globals.validate) + { + prev_req.size = 0; + prev_req.operation = FILE_OP_TYPE_NULL; + prev_req.file_id = 0; + prev_req.pos = 0; + } +} + +void clear_stats(void) +{ read_ops = 0; real_read_ops = 0; write_ops = 0; @@ -978,15 +995,12 @@ void clear_stats(void) last_bytes_read = 0; bytes_written = 0; last_bytes_written = 0; - req_performed = 0; - is_dirty = 0; - if (sb_globals.validate) - { - prev_req.size = 0; - prev_req.operation = FILE_OP_TYPE_NULL; - prev_req.file_id = 0; - prev_req.pos = 0; - } + /* + So that intermediate stats are calculated from the current moment + rather than from the previous intermediate report + */ + if (sb_timer_initialized(&sb_globals.exec_timer)) + sb_timer_split(&sb_globals.exec_timer); } diff --git a/sysbench/tests/memory/sb_memory.c b/sysbench/tests/memory/sb_memory.c index cc43b00..3f11c42 100644 --- a/sysbench/tests/memory/sb_memory.c +++ b/sysbench/tests/memory/sb_memory.c @@ -379,7 +379,7 @@ void memory_print_stats(sb_stat_t type) break; case SB_STAT_CUMULATIVE: - seconds = NS2SEC(sb_timer_value(&sb_globals.exec_timer)); + seconds = NS2SEC(sb_timer_split(&sb_globals.cumulative_timer1)); log_text(LOG_NOTICE, "Operations performed: %d (%8.2f ops/sec)\n", total_ops, total_ops / seconds); @@ -387,6 +387,14 @@ void memory_print_stats(sb_stat_t type) log_text(LOG_NOTICE, "%4.2f MB transferred (%4.2f MB/sec)\n", total_bytes / megabyte, total_bytes / megabyte / seconds); + total_ops = 0; + total_bytes = 0; + /* + So that intermediate stats are calculated from the current moment + rather than from the previous intermediate report + */ + if (sb_timer_initialized(&sb_globals.exec_timer)) + sb_timer_split(&sb_globals.exec_timer); break; } diff --git a/sysbench/tests/oltp/sb_oltp.c b/sysbench/tests/oltp/sb_oltp.c index 51bbca9..26e9485 100644 --- a/sysbench/tests/oltp/sb_oltp.c +++ b/sysbench/tests/oltp/sb_oltp.c @@ -300,6 +300,8 @@ static int prepare_stmt_set_trx(oltp_stmt_set_t *, oltp_bind_set_t *, db_conn_t static int prepare_stmt_set_nontrx(oltp_stmt_set_t *, oltp_bind_set_t *, db_conn_t *); static int prepare_stmt_set_sp(oltp_stmt_set_t *, oltp_bind_set_t *, db_conn_t *); +static void oltp_reset_stats(void); + /* Close a set of statements */ void close_stmt_set(oltp_stmt_set_t *set); @@ -505,12 +507,8 @@ int oltp_cmd_prepare(void) oltp_disconnect(con); - read_ops = last_read_ops = 0; - write_ops = last_write_ops = 0; - other_ops = 0; - transactions = last_transactions = 0; - deadlocks = 0; - + oltp_reset_stats(); + return 0; error: @@ -645,13 +643,10 @@ int oltp_init(void) { exec_timers = (sb_timer_t *)malloc(sb_globals.num_threads * sizeof(sb_timer_t)); fetch_timers = (sb_timer_t *)malloc(sb_globals.num_threads * sizeof(sb_timer_t)); - for (thread_id = 0; thread_id < sb_globals.num_threads; thread_id++) - { - sb_timer_init(exec_timers + thread_id); - sb_timer_init(fetch_timers + thread_id); - } } + oltp_reset_stats(); + /* Percentile stats for --report-interval */ if (sb_percentile_init(&local_percentile, 100000, 1.0, 1e13)) return 1; @@ -1348,8 +1343,7 @@ int oltp_execute_request(sb_request_t *sb_req, int thread_id) LOG_EVENT_STOP(msg, thread_id); /* Update percentile stats for --report-interval */ - sb_percentile_update(&local_percentile, - sb_timer_value(&sb_globals.op_timers[thread_id])); + sb_percentile_update(&local_percentile, sb_timer_value(&timers[thread_id])); SB_THREAD_MUTEX_LOCK(); read_ops += local_read_ops; @@ -1413,9 +1407,8 @@ void oltp_print_stats(sb_stat_t type) else if (type != SB_STAT_CUMULATIVE) return; - seconds = NS2SEC(sb_timer_value(&sb_globals.exec_timer)); + seconds = NS2SEC(sb_timer_split(&sb_globals.cumulative_timer1)); - log_text(LOG_NOTICE, "OLTP test statistics:"); log_text(LOG_NOTICE, " queries performed:"); log_text(LOG_NOTICE, " read: %d", @@ -1468,6 +1461,8 @@ void oltp_print_stats(sb_stat_t type) log_text(LOG_DEBUG, " total: %.4fs", NS2SEC(get_sum_time(&fetch_timer))); } + + oltp_reset_stats(); } @@ -2345,3 +2340,30 @@ int get_think_time(void) return t; } + +static void oltp_reset_stats(void) +{ + unsigned int thread_id; + + read_ops = last_read_ops = 0; + write_ops = last_write_ops = 0; + other_ops = 0; + transactions = last_transactions = 0; + deadlocks = 0; + + /* + So that intermediate stats are calculated from the current moment + rather than from the previous intermediate report + */ + if (sb_timer_initialized(&sb_globals.exec_timer)) + sb_timer_split(&sb_globals.exec_timer); + + if (sb_globals.debug) + { + for (thread_id = 0; thread_id < sb_globals.num_threads; thread_id++) + { + sb_timer_init(exec_timers + thread_id); + sb_timer_init(fetch_timers + thread_id); + } + } +}