diff --git a/.bzrignore b/.bzrignore
index 8a5c253..1917288 100644
--- a/.bzrignore
+++ b/.bzrignore
@@ -28,3 +28,13 @@ autom4te.cache
./config/config.guess
./config/config.h.in
./config/config.sub
+./sysbench/TAGS
+./sysbench/drivers/TAGS
+./sysbench/drivers/mysql/TAGS
+./sysbench/tests/TAGS
+./sysbench/tests/cpu/TAGS
+./sysbench/tests/fileio/TAGS
+./sysbench/tests/memory/TAGS
+./sysbench/tests/mutex/TAGS
+./sysbench/tests/oltp/TAGS
+./sysbench/tests/threads/TAGS
diff --git a/doc/manual.xml b/doc/manual.xml
index 166498b..d5e3755 100644
--- a/doc/manual.xml
+++ b/doc/manual.xml
@@ -197,7 +197,7 @@
- Common command line options
+ General command line options
The table below lists the supported common options, their descriptions and default values:
@@ -219,6 +219,7 @@
off
Size of stack for each thread32K
Specifies if random numbers generator should be initialized from timer before the test startoff
+ Periodically report intermediate statistics with a specified interval in seconds. 0 disables intermediate reports0
Name of the test mode to runRequired
Print more debug infooff
Perform
@@ -241,8 +242,6 @@
95
- Dump current results periodically (see )off
- Delay between batch dumps in secods (see )300
Perform validation of test results where possibleoff
@@ -254,21 +253,6 @@
kilobytes, M for megabytes, G for gigabytes and T for terabytes).
-
- Batch mode
- In some cases it is useful to have not only the final benchmarks
- statistics, but also periodical dumps of current stats to see how they
- change over the test run. For this purpose SysBench has a batch
- execution mode which is turned on by the
- option. You may specify the delay in seconds between the consequent dumps with
- the option. Example:
-
- sysbench --batch --batch-delay=5 --test=threads run
-
- This will run SysBench in a threads test mode, with the current values
- of minimum, average, maximum and percentile for request execution
- times printed every 5 seconds.
-
diff --git a/sysbench/db_driver.h b/sysbench/db_driver.h
index 04b6397..dcd177c 100644
--- a/sysbench/db_driver.h
+++ b/sysbench/db_driver.h
@@ -165,8 +165,8 @@ typedef struct
typedef struct
{
- char *sname; /* short name */
- char *lname; /* long name */
+ const char *sname; /* short name */
+ const char *lname; /* long name */
sb_arg_t *args; /* driver command line arguments */
drv_ops_t ops; /* driver operations */
diff --git a/sysbench/drivers/mysql/drv_mysql.c b/sysbench/drivers/mysql/drv_mysql.c
index a48e6f6..47487bf 100644
--- a/sysbench/drivers/mysql/drv_mysql.c
+++ b/sysbench/drivers/mysql/drv_mysql.c
@@ -91,7 +91,7 @@ typedef struct
unsigned int myisam_max_rows;
mysql_drv_trx_t engine_trx;
unsigned int use_ssl;
- char *create_options;
+ const char *create_options;
} mysql_drv_args_t;
#ifdef HAVE_PS
@@ -359,9 +359,9 @@ int mysql_drv_connect(db_conn_t *sb_conn)
{
MYSQL *con;
char *host;
- char *ssl_key;
- char *ssl_cert;
- char *ssl_ca;
+ const char *ssl_key;
+ const char *ssl_cert;
+ const char *ssl_ca;
con = (MYSQL *)malloc(sizeof(MYSQL));
if (con == NULL)
diff --git a/sysbench/sb_logger.c b/sysbench/sb_logger.c
index 8973575..b2ece07 100644
--- a/sysbench/sb_logger.c
+++ b/sysbench/sb_logger.c
@@ -38,9 +38,6 @@
#include "sb_list.h"
#include "sb_logger.h"
-/* Format of the timestamp string */
-#define TIMESTAMP_FMT "[%s] "
-
#define TEXT_BUFFER_SIZE 4096
#define ERROR_BUFFER_SIZE 256
@@ -48,11 +45,6 @@
#define OPER_LOG_MIN_VALUE 1
#define OPER_LOG_MAX_VALUE 1E13
-typedef enum {
- BATCH_STATUS_START,
- BATCH_STATUS_STOP
-} batch_status_t;
-
/* Array of message handlers (one chain per message type) */
static sb_list_t handlers[LOG_MSG_TYPE_MAX];
@@ -63,15 +55,6 @@ static unsigned char initialized;
/* verbosity of messages */
static unsigned char verbosity;
-/* whether each message must be timestamped */
-static unsigned char log_timestamp;
-
-/* whether batch mode must be used */
-static unsigned char batch_mode;
-
-/* delay in seconds between statistics dumps in batch mode */
-static unsigned int batch_delay;
-
/*
gettimeofday() is over-optimized on some architectures what results in excessive warning message
This flag is required to issue a warning only once
@@ -84,10 +67,6 @@ static double oper_log_deduct;
static double oper_log_mult;
static unsigned int oper_percentile;
static pthread_mutex_t oper_mutex; /* used to sync access to operations array */
-static pthread_mutex_t batch_mutex; /* used to sync batch operations */
-static pthread_cond_t batch_cond;
-static pthread_t batch_thread;
-static batch_status_t batch_status;
static pthread_mutex_t text_mutex;
static unsigned int text_cnt;
@@ -128,10 +107,6 @@ static sb_arg_t oper_handler_args[] =
{
{"percentile", "percentile rank of query response times to count",
SB_ARG_TYPE_INT, "95"},
- {"batch", "dump current stats periodically instead of final ones",
- SB_ARG_TYPE_FLAG, "off"},
- {"batch-delay", "delay between batch dumps in seconds",
- SB_ARG_TYPE_INT, "300"},
{NULL, NULL, SB_ARG_TYPE_NULL, NULL}
};
@@ -147,10 +122,6 @@ static log_handler_t oper_handler = {
};
-/* Start routine for the batch thread */
-void *batch_runner_proc(void *);
-
-
/* Register logger and all handlers */
@@ -168,6 +139,27 @@ int log_register(void)
}
+/* Display command line options for registered log handlers */
+
+
+void log_usage(void)
+{
+ unsigned int i;
+ sb_list_item_t *pos;
+ log_handler_t *handler;
+
+ for (i = 0; i < LOG_MSG_TYPE_MAX; i++)
+ {
+ SB_LIST_FOR_EACH(pos, handlers + i)
+ {
+ handler = SB_LIST_ENTRY(pos, log_handler_t, listitem);
+ if (handler->args != NULL)
+ sb_print_options(handler->args);
+ }
+ }
+}
+
+
/* Initialize logger and all handlers */
@@ -261,21 +253,10 @@ void log_text(log_msg_priority_t priority, const char *fmt, ...)
char buf[TEXT_BUFFER_SIZE];
va_list ap;
int n, clen, maxlen;
- struct tm tm_now;
- time_t t_now;
maxlen = TEXT_BUFFER_SIZE;
clen = 0;
-
- if (log_timestamp)
- {
- time(&t_now);
- gmtime_r((const time_t *)&t_now, &tm_now);
- n = strftime(buf, maxlen, TIMESTAMP_FMT, &tm_now);
- clen += n;
- maxlen -= n;
- }
-
+
va_start(ap, fmt);
n = vsnprintf(buf + clen, maxlen, fmt, ap);
va_end(ap);
@@ -300,6 +281,60 @@ void log_text(log_msg_priority_t priority, const char *fmt, ...)
msg.data = (void *)&text_msg;
text_msg.priority = priority;
text_msg.text = buf;
+ text_msg.flags = 0;
+
+ log_msg(&msg);
+}
+
+
+/*
+ variant of log_text() which prepends log lines with the elapsed time of a
+ specified timer.
+*/
+
+
+void log_timestamp(log_msg_priority_t priority, const sb_timer_t *timer,
+ const char *fmt, ...)
+{
+ log_msg_t msg;
+ log_msg_text_t text_msg;
+ char buf[TEXT_BUFFER_SIZE];
+ va_list ap;
+ int n, clen, maxlen;
+
+ maxlen = TEXT_BUFFER_SIZE;
+ clen = 0;
+
+ n = snprintf(buf, maxlen, "[%4.0fs] ", NS2SEC(timer->elapsed));
+ clen += n;
+ maxlen -= n;
+
+ va_start(ap, fmt);
+ n = vsnprintf(buf + clen, maxlen, fmt, ap);
+ va_end(ap);
+ if (n < 0 || n >= maxlen)
+ n = maxlen;
+ clen += n;
+ maxlen -= n;
+ snprintf(buf + clen, maxlen, "\n");
+
+ /*
+ No race condition here because log_init() is supposed to be called
+ in a single-threaded stage
+ */
+ if (!initialized)
+ {
+ printf("%s", buf);
+
+ return;
+ }
+
+ msg.type = LOG_MSG_TYPE_TEXT;
+ msg.data = (void *)&text_msg;
+ text_msg.priority = priority;
+ text_msg.text = buf;
+ /* Skip duplicate checks */
+ text_msg.flags = LOG_MSG_TEXT_ALLOW_DUPLICATES;
log_msg(&msg);
}
@@ -394,24 +429,27 @@ int text_handler_process(log_msg_t *msg)
if (text_msg->priority > verbosity)
return 0;
-
- pthread_mutex_lock(&text_mutex);
- if (!strcmp(text_buf, text_msg->text))
+
+ if (!text_msg->flags & LOG_MSG_TEXT_ALLOW_DUPLICATES)
{
- text_cnt++;
+ pthread_mutex_lock(&text_mutex);
+ if (!strcmp(text_buf, text_msg->text))
+ {
+ text_cnt++;
+ pthread_mutex_unlock(&text_mutex);
+
+ return 0;
+ }
+ else
+ {
+ if (text_cnt > 0)
+ printf("(last message repeated %u times)\n", text_cnt);
+
+ text_cnt = 0;
+ strncpy(text_buf, text_msg->text, TEXT_BUFFER_SIZE);
+ }
pthread_mutex_unlock(&text_mutex);
-
- return 0;
}
- else
- {
- if (text_cnt > 0)
- printf("(last message repeated %u times)\n", text_cnt);
-
- text_cnt = 0;
- strncpy(text_buf, text_msg->text, TEXT_BUFFER_SIZE);
- }
- pthread_mutex_unlock(&text_mutex);
switch (text_msg->priority) {
case LOG_FATAL:
@@ -443,8 +481,6 @@ int text_handler_process(log_msg_t *msg)
int oper_handler_init(void)
{
- pthread_attr_t batch_attr;
-
oper_percentile = sb_get_value_int("percentile");
if (oper_percentile < 1 || oper_percentile > 100)
{
@@ -456,31 +492,8 @@ int oper_handler_init(void)
oper_log_deduct = log(OPER_LOG_MIN_VALUE);
oper_log_mult = (OPER_LOG_GRANULARITY - 1) / (log(OPER_LOG_MAX_VALUE) - oper_log_deduct);
- batch_mode = sb_get_value_flag("batch");
- if (batch_mode)
- log_timestamp = 1;
- batch_delay = sb_get_value_int("batch-delay");
-
pthread_mutex_init(&oper_mutex, NULL);
- if (batch_mode)
- {
- int err;
- pthread_mutex_init(&batch_mutex, NULL);
- pthread_cond_init(&batch_cond, NULL);
-
- /* Create batch thread */
- pthread_attr_init(&batch_attr);
- if ((err = pthread_create(&batch_thread, &batch_attr, &batch_runner_proc, NULL))
- != 0)
- {
- log_text(LOG_FATAL, "Batch thread creation failed, errno = %d (%s)",
- err, strerror(err));
- return 1;
- }
- batch_status = BATCH_STATUS_STOP;
- }
-
return 0;
}
@@ -494,18 +507,6 @@ int oper_handler_process(log_msg_t *msg)
unsigned int ncell;
log_msg_oper_t *oper_msg = (log_msg_oper_t *)msg->data;
- if (batch_mode)
- {
- pthread_mutex_lock(&batch_mutex);
- if (batch_status != BATCH_STATUS_START)
- {
- /* Wake up the batch thread */
- batch_status = BATCH_STATUS_START;
- pthread_cond_signal(&batch_cond);
- }
- pthread_mutex_unlock(&batch_mutex);
- }
-
if (oper_msg->action == LOG_MSG_OPER_START)
{
sb_timer_init(&oper_msg->timer);
@@ -513,7 +514,7 @@ int oper_handler_process(log_msg_t *msg)
return 0;
}
- optime = sb_timer_current(&oper_msg->timer);
+ optime = sb_timer_value(&oper_msg->timer);
if (optime < OPER_LOG_MIN_VALUE)
{
/* Warn only once */
@@ -565,26 +566,6 @@ int oper_handler_done(void)
double time_avg;
double time_stddev;
- if (batch_mode)
- {
- int err;
- /* Stop the batch thread */
- pthread_mutex_lock(&batch_mutex);
- batch_status = BATCH_STATUS_STOP;
- pthread_cond_signal(&batch_cond);
- pthread_mutex_unlock(&batch_mutex);
-
- if ((err = pthread_join(batch_thread, NULL)))
- {
- log_text(LOG_FATAL, "Batch thread join failed, errno = %d (%s)",
- err, strerror(err));
- return 1;
- }
-
- pthread_mutex_destroy(&batch_mutex);
- pthread_cond_destroy(&batch_cond);
- }
-
sb_timer_init(&t);
nthreads = sb_globals.num_threads;
for(i = 0; i < nthreads; i++)
@@ -683,88 +664,3 @@ int oper_handler_done(void)
return 0;
}
-
-
-/* Worker thread to periodically dump stats in batch mode */
-
-
-void *batch_runner_proc(void *arg)
-{
- sb_timer_t t;
- struct timespec delay;
-#ifndef HAVE_CLOCK_GETTIME
- struct timeval tv;
-#endif
- int rc;
- unsigned int i, noper;
- double diff, pdiff, p, percent, optime;
-
- (void)arg; /* unused */
-
- /* Wait for the test to start */
- pthread_mutex_lock(&batch_mutex);
- pthread_cond_wait(&batch_cond, &batch_mutex);
- pthread_mutex_unlock(&batch_mutex);
-
- /* Main batch loop */
- while(batch_status != BATCH_STATUS_STOP)
- {
- /* Wait for batch_delay seconds */
- pthread_mutex_lock(&batch_mutex);
-
-#ifdef HAVE_CLOCK_GETTIME
- clock_gettime(CLOCK_REALTIME, &delay);
- delay.tv_sec += batch_delay;
-#else
- gettimeofday(&tv, NULL);
- delay.tv_sec = tv.tv_sec + batch_delay;
- delay.tv_nsec = tv.tv_usec * 1000;
-#endif
- rc = pthread_cond_timedwait(&batch_cond, &batch_mutex, &delay);
- pthread_mutex_unlock(&batch_mutex);
-
- /* Status changed? */
- if (rc != ETIMEDOUT)
- continue;
-
- /* Dump current statistics */
-
- /* Calculate min/avg/max values for the last period */
- sb_timer_init(&t);
- for(i = 0; i < sb_globals.num_threads; i++)
- t = merge_timers(&t,&(sb_globals.op_timers[i]));
-
- /* Do we have any events to measure? */
- if (t.events == 0)
- continue;
-
- /* Calculate percentile value for the last period */
- percent = 0;
- pthread_mutex_lock(&oper_mutex);
-
- /* Calculate element with a given percentile rank */
- pdiff = oper_percentile;
- noper = 0;
- for (i = 0; i < OPER_LOG_GRANULARITY; i++)
- {
- noper += operations[i];
- p = (double)noper / t.events * 100;
- diff = fabs(p - oper_percentile);
- if (diff > pdiff || fabs(diff) < 1e-6)
- break;
- pdiff = diff;
- }
- if (i > 0)
- i--;
-
- /* Calculate response time corresponding to this element */
- optime = exp((double)i / oper_log_mult + oper_log_deduct);
- pthread_mutex_unlock(&oper_mutex);
-
- log_text(LOG_NOTICE, "min: %.4f avg: %.4f max: %.4f percentile: %.4f",
- NS2SEC(get_min_time(&t)), NS2SEC(get_avg_time(&t)),
- NS2SEC(get_max_time(&t)), NS2SEC(optime));
- }
-
- return NULL;
-}
diff --git a/sysbench/sb_logger.h b/sysbench/sb_logger.h
index aeec9f2..96f6c43 100644
--- a/sysbench/sb_logger.h
+++ b/sysbench/sb_logger.h
@@ -25,6 +25,10 @@
#include "sb_options.h"
#include "sb_timer.h"
+/* Text message flags (used in the 'flags' field of log_text_msg_t) */
+
+#define LOG_MSG_TEXT_ALLOW_DUPLICATES 1
+
/* Macros to log per-request execution statistics */
#define LOG_EVENT_START(msg, thread_id) \
@@ -68,7 +72,8 @@ typedef enum {
typedef struct {
log_msg_priority_t priority;
- char *text;
+ char *text;
+ unsigned int flags;
} log_msg_text_t;
/* Operation start/stop message definition */
@@ -110,7 +115,6 @@ typedef struct {
typedef struct {
log_handler_ops_t ops; /* handler operations */
sb_arg_t *args; /* handler arguments */
-
sb_list_item_t listitem; /* can be linked in a list */
} log_handler_t;
@@ -118,6 +122,10 @@ typedef struct {
int log_register(void);
+/* Display command line options for all register log handlers */
+
+void log_usage(void);
+
/* Initialize logger */
int log_init(void);
@@ -134,6 +142,14 @@ void log_msg(log_msg_t *);
void log_text(log_msg_priority_t priority, const char *fmt, ...);
+/*
+ variant of log_text() which prepends log lines with a elapsed time of the
+ specified timer.
+*/
+
+void log_timestamp(log_msg_priority_t priority, const sb_timer_t *timer,
+ const char *fmt, ...);
+
/* printf-like wrapper to log system error messages */
void log_errno(log_msg_priority_t priority, const char *fmt, ...);
diff --git a/sysbench/sb_options.c b/sysbench/sb_options.c
index a057fa0..25840f8 100644
--- a/sysbench/sb_options.c
+++ b/sysbench/sb_options.c
@@ -73,7 +73,7 @@ option_t *sb_find_option(char *name)
return find_option(&options, name);
}
-int set_option(char *name, char *value, sb_arg_type_t type)
+int set_option(const char *name, const char *value, sb_arg_type_t type)
{
option_t *opt;
char *tmp;
@@ -160,7 +160,7 @@ void sb_print_options(sb_arg_t *opts)
}
-int sb_get_value_flag(char *name)
+int sb_get_value_flag(const char *name)
{
option_t *opt;
@@ -172,7 +172,7 @@ int sb_get_value_flag(char *name)
}
-int sb_get_value_int(char *name)
+int sb_get_value_int(const char *name)
{
option_t *opt;
value_t *val;
@@ -192,7 +192,7 @@ int sb_get_value_int(char *name)
}
-unsigned long long sb_get_value_size(char *name)
+unsigned long long sb_get_value_size(const char *name)
{
option_t *opt;
value_t *val;
@@ -249,7 +249,7 @@ unsigned long long sb_get_value_size(char *name)
}
-float sb_get_value_float(char *name)
+float sb_get_value_float(const char *name)
{
option_t *opt;
value_t *val;
@@ -271,7 +271,7 @@ float sb_get_value_float(char *name)
}
-char *sb_get_value_string(char *name)
+char *sb_get_value_string(const char *name)
{
option_t *opt;
value_t *val;
@@ -291,7 +291,7 @@ char *sb_get_value_string(char *name)
}
-sb_list_t *sb_get_value_list(char *name)
+sb_list_t *sb_get_value_list(const char *name)
{
option_t *opt;
@@ -425,7 +425,7 @@ int remove_option(sb_list_t * options, char * optname)
}
-value_t *add_value(sb_list_t *values, char *data)
+value_t *add_value(sb_list_t *values, const char *data)
{
value_t *newval;
@@ -446,7 +446,7 @@ value_t *add_value(sb_list_t *values, char *data)
}
-value_t *find_value(sb_list_t *values, char *data)
+value_t *find_value(sb_list_t *values, const char *data)
{
sb_list_item_t *pos;
value_t *value;
@@ -465,7 +465,7 @@ value_t *find_value(sb_list_t *values, char *data)
}
-option_t *add_option(sb_list_t *options, char *name)
+option_t *add_option(sb_list_t *options, const char *name)
{
option_t *option;
@@ -486,7 +486,7 @@ option_t *add_option(sb_list_t *options, char *name)
}
-option_t *find_option(sb_list_t *options, char *name)
+option_t *find_option(sb_list_t *options, const char *name)
{
sb_list_item_t *pos;
option_t *opt;
diff --git a/sysbench/sb_options.h b/sysbench/sb_options.h
index 6dd3574..cc392b4 100644
--- a/sysbench/sb_options.h
+++ b/sysbench/sb_options.h
@@ -43,10 +43,10 @@ typedef enum
/* Test option definition */
typedef struct
{
- char *name;
- char *desc;
+ const char *name;
+ const char *desc;
sb_arg_type_t type;
- char * value;
+ const char *value;
} sb_arg_t;
typedef struct
@@ -74,7 +74,7 @@ int sb_options_init(void);
int sb_register_arg_set(sb_arg_t *set);
/* Set value 'value' of type 'type' for option 'name' */
-int set_option(char *name, char *value, sb_arg_type_t type);
+int set_option(const char *name, const char *value, sb_arg_type_t type);
/* Find option specified by 'name' */
option_t *sb_find_option(char *name);
@@ -82,20 +82,20 @@ option_t *sb_find_option(char *name);
/* Print list of options specified by 'opts' */
void sb_print_options(sb_arg_t *opts);
-int sb_get_value_flag(char *name);
+int sb_get_value_flag(const char *name);
-int sb_get_value_int(char *name);
+int sb_get_value_int(const char *name);
-unsigned long long sb_get_value_size(char *name);
+unsigned long long sb_get_value_size(const char *name);
-float sb_get_value_float(char *name);
+float sb_get_value_float(const char *name);
-char *sb_get_value_string(char *name);
+char *sb_get_value_string(const char *name);
+
+sb_list_t *sb_get_value_list(const char *name);
char *sb_print_value_size(char *buf, unsigned int buflen, double value);
-sb_list_t *sb_get_value_list(char *name);
-
value_t *new_value(void);
option_t *new_option(void);
@@ -104,13 +104,13 @@ void free_values(sb_list_t *);
void free_options(sb_list_t *);
-value_t *add_value(sb_list_t *, char *);
+value_t *add_value(sb_list_t *, const char *);
-value_t *find_value(sb_list_t *, char *);
+value_t *find_value(sb_list_t *, const char *);
-option_t *add_option(sb_list_t *, char *);
+option_t *add_option(sb_list_t *, const char *);
-option_t *find_option(sb_list_t *, char *);
+option_t *find_option(sb_list_t *, const char *);
int remove_value(sb_list_t *, char *);
diff --git a/sysbench/sb_timer.c b/sysbench/sb_timer.c
index 21054f8..9dde842 100644
--- a/sysbench/sb_timer.c
+++ b/sysbench/sb_timer.c
@@ -28,6 +28,14 @@
/* Some functions for simple time operations */
+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);
+}
+
/* initialize timer */
@@ -59,6 +67,7 @@ void sb_timer_start(sb_timer_t *t)
}
SB_GETTIME(&t->time_start);
+ t->time_split = t->time_start;
t->state = TIMER_RUNNING;
}
@@ -82,55 +91,78 @@ void sb_timer_stop(sb_timer_t *t)
abort();
}
- SB_GETTIME(&t->time_end);
- t->my_time = SEC2NS(t->time_end.tv_sec - t->time_start.tv_sec) +
- (t->time_end.tv_nsec - t->time_start.tv_nsec);
+ sb_timer_update(t);
t->events++;
- t->sum_time += t->my_time;
- if (t->my_time < t->min_time)
- t->min_time = t->my_time;
- if (t->my_time > t->max_time)
- t->max_time = t->my_time;
+ t->sum_time += t->elapsed;
+ if (t->elapsed < t->min_time)
+ t->min_time = t->elapsed;
+ if (t->elapsed > t->max_time)
+ t->max_time = t->elapsed;
t->state = TIMER_STOPPED;
}
-/* get timer's value in nanoseconds */
+/* get the current timer value in nanoseconds */
unsigned long long sb_timer_value(sb_timer_t *t)
-{
- return t->my_time;
-}
-
-
-/* get current time without stopping timer */
-
-
-unsigned long long sb_timer_current(sb_timer_t *t)
{
struct timespec time_end;
switch (t->state) {
case TIMER_INITIALIZED:
+ log_text(LOG_WARNING, "timer was never started");
return 0;
case TIMER_STOPPED:
- return t->my_time;
+ return t->elapsed;
case TIMER_RUNNING:
break;
default:
- log_text(LOG_FATAL, "uninitialized timer examined");
+ log_text(LOG_FATAL, "uninitialized timer queried");
abort();
}
-
- SB_GETTIME(&time_end);
- return SEC2NS(time_end.tv_sec - t->time_start.tv_sec) +
- (time_end.tv_nsec - t->time_start.tv_nsec);
+ sb_timer_update(t);
+
+ return t->elapsed;
}
+/*
+ get time elapsed since the previos call to sb_timer_split() for the specified
+ timer without stopping it. The first call returns time elapsed since the
+ timer was started.
+*/
+
+
+unsigned long long sb_timer_split(sb_timer_t *t)
+{
+ struct timespec tmp;
+ unsigned long long res;
+
+ switch (t->state) {
+ case TIMER_INITIALIZED:
+ log_text(LOG_WARNING, "timer was never started");
+ return 0;
+ case TIMER_STOPPED:
+ log_text(LOG_WARNING, "timer was already stopped");
+ return 0;;
+ case TIMER_RUNNING:
+ break;
+ default:
+ log_text(LOG_FATAL, "uninitialized timer queried");
+ abort();
+ }
+
+ SB_GETTIME(&tmp);
+ t->elapsed = TIMESPEC_DIFF(tmp, t->time_start);
+ res = TIMESPEC_DIFF(tmp, t->time_split);
+ t->time_split = tmp;
+
+ return res;
+}
+
/* get average time per event */
@@ -176,7 +208,7 @@ sb_timer_t merge_timers(sb_timer_t *t1, sb_timer_t *t2)
{
sb_timer_t t;
- t.my_time = t1->my_time+t2->my_time;
+ t.elapsed = t1->elapsed + t2->elapsed;
t.sum_time = t1->sum_time+t2->sum_time;
t.events = t1->events+t2->events;
@@ -194,18 +226,6 @@ sb_timer_t merge_timers(sb_timer_t *t1, sb_timer_t *t2)
}
-/* Subtract *before from *after. Result given via pointer *diff. */
-
-
-void diff_tv(long long *diff, struct timespec *before, struct timespec *after)
-{
- time_t sec;
-
- sec = after->tv_sec - before->tv_sec;
- *diff = sec * 1000000000LL + after->tv_nsec - before->tv_nsec;
-}
-
-
/* Add a number of nanoseconds to a struct timespec */
diff --git a/sysbench/sb_timer.h b/sysbench/sb_timer.h
index 3d4e1c2..10ac905 100644
--- a/sysbench/sb_timer.h
+++ b/sysbench/sb_timer.h
@@ -44,15 +44,19 @@
#define NS2MS(nsec) ((nsec)/1000000.)
#define MS2NS(msec) ((msec)*1000000ULL)
+/* Difference between two 'timespec' values in nanoseconds */
+#define TIMESPEC_DIFF(a,b) (SEC2NS(a.tv_sec - b.tv_sec) + \
+ (a.tv_nsec - b.tv_nsec))
+
/* Wrapper over various *gettime* functions */
#ifdef HAVE_CLOCK_GETTIME
# define SB_GETTIME(tsp) clock_gettime(CLOCK_REALTIME, tsp)
#else
-# define SB_GETTIME(tsp) \
- do { \
- struct timeval tv; \
- gettimeofday(&tv, NULL); \
- (tsp)->tv_sec = tv.tv_sec; \
+# define SB_GETTIME(tsp) \
+ do { \
+ struct timeval tv; \
+ gettimeofday(&tv, NULL); \
+ (tsp)->tv_sec = tv.tv_sec; \
(tsp)->tv_nsec = tv.tv_usec * 1000; \
} while (0)
#endif
@@ -65,8 +69,8 @@ typedef enum {TIMER_UNINITIALIZED, TIMER_INITIALIZED, TIMER_STOPPED, \
typedef struct
{
struct timespec time_start;
- struct timespec time_end;
- unsigned long long my_time;
+ struct timespec time_split;
+ unsigned long long elapsed;
unsigned long long min_time;
unsigned long long max_time;
unsigned long long sum_time;
@@ -86,11 +90,15 @@ void sb_timer_start(sb_timer_t *);
/* stop timer */
void sb_timer_stop(sb_timer_t *);
-/* get timer's value in microseconds */
+/* get the current timer value in nanoseconds */
unsigned long long sb_timer_value(sb_timer_t *);
-/* get current time without stopping timer */
-unsigned long long sb_timer_current(sb_timer_t *);
+/*
+ get time elapsed since the previos call to sb_timer_split() for the specified
+ timer without stopping it. The first call returns time elapsed since the
+ timer was started.
+*/
+unsigned long long sb_timer_split(sb_timer_t *);
/* get average time per event */
unsigned long long get_avg_time(sb_timer_t *);
@@ -107,9 +115,6 @@ unsigned long long get_max_time(sb_timer_t *);
/* sum data from two timers. used in summing data from multiple threads */
sb_timer_t merge_timers(sb_timer_t *, sb_timer_t *);
-/* subtract *after from *before */
-void diff_tv(long long *diff, struct timespec *before, struct timespec *after);
-
/* add a number of nanoseconds to a struct timespec */
void add_ns_to_timespec(struct timespec *dest, long long delta);
diff --git a/sysbench/sb_win.c b/sysbench/sb_win.c
index cf3c62b..ad8afa8 100644
--- a/sysbench/sb_win.c
+++ b/sysbench/sb_win.c
@@ -196,6 +196,11 @@ int pthread_create(pthread_t *thread, const pthread_attr_t *attr,
return -1;
}
+int pthread_cancel(pthread_t thread)
+{
+ return !TerminateThread(thread, 0);
+}
+
/* Minimal size of thread stack on Windows*/
#define PTHREAD_STACK_MIN 65536*2
diff --git a/sysbench/sb_win.h b/sysbench/sb_win.h
index c807c3e..e41c389 100644
--- a/sysbench/sb_win.h
+++ b/sysbench/sb_win.h
@@ -97,6 +97,7 @@ extern int pthread_mutex_unlock(pthread_mutex_t *mutex);
extern int pthread_mutex_init(pthread_mutex_t *mutex, const pthread_mutexattr_t *attr);
extern int pthread_mutex_destroy(pthread_mutex_t *mutex);
extern int pthread_create(pthread_t *thread, const pthread_attr_t *attr, void *(*start_routine)(void*), void *arg);
+extern int pthread_cancel(pthread_t thread);
extern int pthread_attr_setstacksize( pthread_attr_t *attr, size_t stacksize);
extern int pthread_join(pthread_t thread, void **value_ptr);
extern int gettimeofday(struct timeval * tp, void * tzp);
diff --git a/sysbench/sysbench.c b/sysbench/sysbench.c
index 05a286b..d5b2d3b 100644
--- a/sysbench/sysbench.c
+++ b/sysbench/sysbench.c
@@ -88,6 +88,9 @@ sb_arg_t general_args[] =
{"tx-rate", "target transaction rate (tps)", SB_ARG_TYPE_INT, "0"},
{"tx-jitter", "target transaction variation, in microseconds",
SB_ARG_TYPE_INT, "0"},
+ {"report-interval", "periodically report intermediate statistics "
+ "with a specified interval in seconds. 0 disables intermediate reports",
+ SB_ARG_TYPE_INT, "0"},
{"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,7 +128,7 @@ static void sigalrm_handler(int sig)
log_text(LOG_FATAL,
"The --max-time limit has expired, forcing shutdown...");
if (current_test && current_test->ops.print_stats)
- current_test->ops.print_stats();
+ current_test->ops.print_stats(SB_STAT_CUMULATIVE);
log_done();
exit(2);
}
@@ -217,6 +220,10 @@ void print_usage(void)
"[test-options]... command\n\n");
printf("General options:\n");
sb_print_options(general_args);
+
+ printf("Log options:\n");
+ log_usage();
+
printf("Compiled-in tests:\n");
SB_LIST_FOR_EACH(pos, &tests)
{
@@ -347,6 +354,12 @@ void print_run_mode(sb_test_t *test)
sb_globals.tx_rate, sb_globals.tx_jitter);
}
+ if (sb_globals.report_interval)
+ {
+ log_text(LOG_NOTICE, "Report intermediate results every %d second(s)",
+ sb_globals.report_interval);
+ }
+
if (sb_globals.debug)
log_text(LOG_NOTICE, "Debug mode enabled.\n");
@@ -418,6 +431,7 @@ void *runner_thread(void *arg)
about the same time
*/
pthread_mutex_lock(&thread_start_mutex);
+ sb_globals.num_running++;
pthread_mutex_unlock(&thread_start_mutex);
if (sb_globals.tx_rate > 0)
@@ -441,8 +455,7 @@ void *runner_thread(void *arg)
}
/* Check if we have a time limit */
if (sb_globals.max_time != 0 &&
- NS2SEC(sb_timer_current(&sb_globals.exec_timer))
- >= sb_globals.max_time)
+ sb_timer_value(&sb_globals.exec_timer) >= SEC2NS(sb_globals.max_time))
{
log_text(LOG_INFO, "Time limit exceeded, exiting...");
break;
@@ -453,8 +466,8 @@ void *runner_thread(void *arg)
{
add_ns_to_timespec(&target_tv, period_ns);
SB_GETTIME(&now_tv);
- diff_tv(&pause_ns, &now_tv, &target_tv);
- pause_ns = pause_ns - (jitter_ns / 2) + (sb_rnd() % jitter_ns);
+ pause_ns = TIMESPEC_DIFF(target_tv, now_tv) - (jitter_ns / 2) +
+ (sb_rnd() % jitter_ns);
if (pause_ns > 5000)
usleep(pause_ns / 1000);
}
@@ -463,11 +476,58 @@ void *runner_thread(void *arg)
if (test->ops.thread_done != NULL)
test->ops.thread_done(thread_id);
-
+
+ pthread_mutex_lock(&thread_start_mutex);
+ sb_globals.num_running--;
+ pthread_mutex_unlock(&thread_start_mutex);
+
return NULL;
}
+/* Intermediate reports thread */
+
+void *report_thread_proc(void *arg)
+{
+ unsigned long long pause_ns;
+ unsigned long long prev_ns;
+ unsigned long long next_ns;
+ unsigned long long curr_ns;
+ const unsigned long long interval_ns = SEC2NS(sb_globals.report_interval);
+
+ (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, "Reporting thread started");
+
+ pthread_mutex_lock(&thread_start_mutex);
+ pthread_mutex_unlock(&thread_start_mutex);
+
+ pause_ns = interval_ns;
+ prev_ns = sb_timer_value(&sb_globals.exec_timer) + interval_ns;
+ for (;;)
+ {
+ usleep(pause_ns / 1000);
+ current_test->ops.print_stats(SB_STAT_INTERMEDIATE);
+ curr_ns = sb_timer_value(&sb_globals.exec_timer);
+ do
+ {
+ next_ns = prev_ns + interval_ns;
+ prev_ns = next_ns;
+ } while (curr_ns >= next_ns);
+ pause_ns = next_ns - curr_ns;
+ }
+
+ return NULL;
+}
+
+
/*
Main test function. Start threads.
Wait for them to complete and measure time
@@ -476,7 +536,8 @@ void *runner_thread(void *arg)
int run_test(sb_test_t *test)
{
unsigned int i;
- int err;
+ int err;
+ pthread_t report_thread;
/* initialize test */
if (test->ops.init != NULL && test->ops.init() != 0)
@@ -493,7 +554,6 @@ int run_test(sb_test_t *test)
threads[i].id = i;
threads[i].test = test;
}
- sb_timer_start(&sb_globals.exec_timer);
/* prepare test */
if (test->ops.prepare != NULL && test->ops.prepare() != 0)
@@ -503,8 +563,9 @@ int run_test(sb_test_t *test)
/* start mutex used for barrier */
pthread_mutex_init(&thread_start_mutex,NULL);
- pthread_mutex_lock(&thread_start_mutex);
-
+ pthread_mutex_lock(&thread_start_mutex);
+ sb_globals.num_running = 0;
+
/* initialize attr */
pthread_attr_init(&thread_attr);
#ifdef PTHREAD_SCOPE_SYSTEM
@@ -516,23 +577,35 @@ int run_test(sb_test_t *test)
/* Set thread concurrency (required on Solaris) */
thr_setconcurrency(sb_globals.num_threads);
#endif
-
+
+ if (sb_globals.report_interval > 0)
+ {
+ /* Create a thread for intermediate statistic reports */
+ if ((err = pthread_create(&report_thread, &thread_attr, &report_thread_proc,
+ NULL)) != 0)
+ {
+ log_errno(LOG_FATAL, "pthread_create() for the reporting thread failed.");
+ return 1;
+ }
+ }
+
/* Starting the test threads */
for(i = 0; i < sb_globals.num_threads; i++)
{
if (sb_globals.error)
return 1;
- if ((err = pthread_create(&(threads[i].thread), &thread_attr, &runner_thread,
- (void*)(threads + i))) != 0)
+ if ((err = pthread_create(&(threads[i].thread), &thread_attr,
+ &runner_thread, (void*)(threads + i))) != 0)
{
- log_text(LOG_FATAL, "Thread #%d creation failed, errno = %d (%s)",
- i, err, strerror(err));
+ log_errno(LOG_FATAL, "pthread_create() for thread #%d failed.", i);
return 1;
}
}
- /* Set the alarm to force shutdown */
+ sb_timer_start(&sb_globals.exec_timer); /* Start benchmark timer */
+
#ifdef HAVE_ALARM
+ /* Set the alarm to force shutdown */
if (sb_globals.force_shutdown)
alarm(sb_globals.max_time + sb_globals.timeout);
#endif
@@ -544,26 +617,30 @@ int run_test(sb_test_t *test)
for(i = 0; i < sb_globals.num_threads; i++)
{
if((err = pthread_join(threads[i].thread, NULL)) != 0)
- {
- log_text(LOG_FATAL, "Thread #%d join failed, errno = %d (%s)",
- i, err, strerror(err));
- return 1;
- }
+ log_errno(LOG_FATAL, "pthread_join() for thread #%d failed.", i);
}
+
+ sb_timer_stop(&sb_globals.exec_timer);
+
+ if (sb_globals.report_interval > 0)
+ {
+ if (pthread_cancel(report_thread) || pthread_join(report_thread, NULL))
+ log_errno(LOG_FATAL, "Terminating the reporting thread failed.");
+ }
+
#ifdef HAVE_ALARM
alarm(0);
#endif
+
log_text(LOG_INFO, "Done.\n");
/* cleanup test */
if (test->ops.cleanup != NULL && test->ops.cleanup() != 0)
return 1;
- sb_timer_stop(&sb_globals.exec_timer);
-
/* print test-specific stats */
if (test->ops.print_stats != NULL && !sb_globals.error)
- test->ops.print_stats();
+ test->ops.print_stats(SB_STAT_CUMULATIVE);
pthread_mutex_destroy(&sb_globals.exec_mutex);
@@ -668,11 +745,13 @@ int init(void)
seed_rng = sb_get_value_int("seed-rng");
if (init_rng && seed_rng)
{
- log_text(LOG_FATAL, "Cannot set both --init_rng and --seed_rng\n");
+ log_text(LOG_FATAL, "Cannot set both --init-rng and --seed-rng\n");
return 1;
}
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");
return 0;
}
diff --git a/sysbench/sysbench.h b/sysbench/sysbench.h
index 243e931..692a217 100644
--- a/sysbench/sysbench.h
+++ b/sysbench/sysbench.h
@@ -106,6 +106,12 @@ typedef struct
} u;
} sb_request_t;
+typedef enum
+{
+ SB_STAT_INTERMEDIATE,
+ SB_STAT_CUMULATIVE
+} sb_stat_t;
+
/* Test commands definition */
typedef int sb_cmd_help(void);
@@ -122,7 +128,7 @@ typedef int sb_op_thread_init(int);
typedef void sb_op_print_mode(void);
typedef sb_request_t sb_op_get_request(int);
typedef int sb_op_execute_request(sb_request_t *, int);
-typedef void sb_op_print_stats(void);
+typedef void sb_op_print_stats(sb_stat_t);
typedef int sb_op_thread_done(int);
typedef int sb_op_cleanup(void);
typedef int sb_op_done(void);
@@ -160,8 +166,8 @@ typedef struct
typedef struct sb_test
{
- char *sname;
- char *lname;
+ const char *sname;
+ const char *lname;
sb_operations_t ops;
sb_commands_t cmds;
sb_arg_t *args;
@@ -189,6 +195,8 @@ typedef struct
sb_timer_t *op_timers; /* timers to measure each thread's run time */
sb_timer_t exec_timer; /* total execution timer */
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 */
unsigned int tx_rate; /* target transaction rate */
unsigned int tx_jitter; /* target transaction variation (us) */
unsigned int max_requests; /* maximum number of requests */
@@ -201,12 +209,4 @@ typedef struct
extern sb_globals_t sb_globals;
-/* used to get options passed from command line */
-
-int sb_get_value_flag(char *);
-int sb_get_value_int(char *);
-unsigned long long sb_get_value_size(char *);
-float sb_get_value_float(char *);
-char *sb_get_value_string(char *);
-
#endif
diff --git a/sysbench/tests/cpu/sb_cpu.c b/sysbench/tests/cpu/sb_cpu.c
index 9c9ca0c..01207ae 100644
--- a/sysbench/tests/cpu/sb_cpu.c
+++ b/sysbench/tests/cpu/sb_cpu.c
@@ -40,7 +40,6 @@ static int cpu_init(void);
static void cpu_print_mode(void);
static sb_request_t cpu_get_request(int);
static int cpu_execute_request(sb_request_t *, int);
-static void cpu_print_stats(void);
static int cpu_done(void);
static sb_test_t cpu_test =
@@ -54,7 +53,7 @@ static sb_test_t cpu_test =
cpu_print_mode,
cpu_get_request,
cpu_execute_request,
- cpu_print_stats,
+ NULL,
NULL,
NULL,
cpu_done
@@ -154,12 +153,7 @@ int cpu_execute_request(sb_request_t *r, int thread_id)
void cpu_print_mode(void)
{
log_text(LOG_INFO, "Doing CPU performance benchmark\n");
-}
-
-void cpu_print_stats(void)
-{
- log_text(LOG_NOTICE, "Maximum prime number checked in CPU test: %d\n",
- max_prime);
+ log_text(LOG_NOTICE, "Primer numbers limit: %d\n", max_prime);
}
int cpu_done(void)
diff --git a/sysbench/tests/fileio/sb_fileio.c b/sysbench/tests/fileio/sb_fileio.c
index b9e09d4..caa45a3 100644
--- a/sysbench/tests/fileio/sb_fileio.c
+++ b/sysbench/tests/fileio/sb_fileio.c
@@ -161,9 +161,12 @@ static int real_read_ops;
static int write_ops;
static int real_write_ops;
static int other_ops;
+static int last_other_ops;
static unsigned int req_performed; /* number of requests done */
static unsigned long long bytes_read;
-static unsigned long long bytes_written;
+static unsigned long long last_bytes_read;
+static unsigned long long bytes_written;
+static unsigned long long last_bytes_written;
#ifdef HAVE_MMAP
/* Array of file mappings */
@@ -222,7 +225,7 @@ static int file_execute_request(sb_request_t *, int);
static int file_thread_done(int);
#endif
static int file_done(void);
-static void file_print_stats(void);
+static void file_print_stats(sb_stat_t);
static sb_test_t fileio_test =
{
@@ -762,25 +765,50 @@ void file_print_mode(void)
/* Print test statistics */
-void file_print_stats(void)
+void file_print_stats(sb_stat_t type)
{
- double total_time;
+ double seconds;
char s1[16], s2[16], s3[16], s4[16];
- total_time = NS2SEC(sb_timer_value(&sb_globals.exec_timer));
-
- log_text(LOG_NOTICE,
- "Operations performed: %d Read, %d Write, %d Other = %d Total",
- read_ops, write_ops, other_ops, read_ops + write_ops + other_ops);
- log_text(LOG_NOTICE, "Read %sb Written %sb Total transferred %sb "
- "(%sb/sec)",
- sb_print_value_size(s1, sizeof(s1), bytes_read),
- sb_print_value_size(s2, sizeof(s2), bytes_written),
- sb_print_value_size(s3, sizeof(s3), bytes_read + bytes_written),
- sb_print_value_size(s4, sizeof(s4),
- (bytes_read + bytes_written) / total_time));
- log_text(LOG_NOTICE, "%8.2f Requests/sec executed",
- (read_ops + write_ops) / total_time);
+ switch (type) {
+ case SB_STAT_INTERMEDIATE:
+ {
+ const double megabyte = 1024.0 * 1024.0;
+
+ SB_THREAD_MUTEX_LOCK();
+
+ seconds = NS2SEC(sb_timer_split(&sb_globals.exec_timer));
+ log_timestamp(LOG_NOTICE, &sb_globals.exec_timer,
+ "reads: %4.2f MB/s writes: %4.2f MB/s fsyncs: %4.2f/s",
+ (bytes_read - last_bytes_read) / megabyte / seconds,
+ (bytes_written - last_bytes_written) / megabyte / seconds,
+ (other_ops - last_other_ops) / seconds);
+ last_bytes_read = bytes_read;
+ last_bytes_written = bytes_written;
+ last_other_ops = other_ops;
+
+ SB_THREAD_MUTEX_UNLOCK();
+
+ break;
+ }
+
+ case SB_STAT_CUMULATIVE:
+ seconds = NS2SEC(sb_timer_value(&sb_globals.exec_timer));
+
+ log_text(LOG_NOTICE,
+ "Operations performed: %d reads, %d writes, %d Other = %d Total",
+ read_ops, write_ops, other_ops, read_ops + write_ops + other_ops);
+ log_text(LOG_NOTICE, "Read %sb Written %sb Total transferred %sb "
+ "(%sb/sec)",
+ sb_print_value_size(s1, sizeof(s1), bytes_read),
+ sb_print_value_size(s2, sizeof(s2), bytes_written),
+ sb_print_value_size(s3, sizeof(s3), bytes_read + bytes_written),
+ sb_print_value_size(s4, sizeof(s4),
+ (bytes_read + bytes_written) / seconds));
+ log_text(LOG_NOTICE, "%8.2f Requests/sec executed",
+ (read_ops + write_ops) / seconds);
+ break;
+ }
}
@@ -951,8 +979,11 @@ void clear_stats(void)
write_ops = 0;
real_write_ops = 0;
other_ops = 0;
+ last_other_ops = 0;
bytes_read = 0;
+ last_bytes_read = 0;
bytes_written = 0;
+ last_bytes_written = 0;
req_performed = 0;
is_dirty = 0;
if (sb_globals.validate)
@@ -1827,7 +1858,7 @@ void file_fill_buffer(char *buf, unsigned int len, size_t offset)
buf[i] = sb_rnd() & 0xFF;
/* Store the checksum */
- *(int *)(buf + i) = (int)crc32(0, buf, len -
+ *(int *)(buf + i) = (int)crc32(0, (unsigned char *)buf, len -
(FILE_CHECKSUM_LENGTH + FILE_OFFSET_LENGTH));
/* Store the offset */
*(long *)(buf + i + FILE_CHECKSUM_LENGTH) = offset;
@@ -1844,7 +1875,7 @@ int file_validate_buffer(char *buf, unsigned int len, size_t offset)
cs_offset = len - (FILE_CHECKSUM_LENGTH + FILE_OFFSET_LENGTH);
- checksum = (unsigned int)crc32(0, buf, cs_offset);
+ checksum = (unsigned int)crc32(0, (unsigned char *)buf, cs_offset);
if (checksum != *(unsigned int *)(buf + cs_offset))
{
diff --git a/sysbench/tests/memory/sb_memory.c b/sysbench/tests/memory/sb_memory.c
index 2e8998f..cc43b00 100644
--- a/sysbench/tests/memory/sb_memory.c
+++ b/sysbench/tests/memory/sb_memory.c
@@ -57,7 +57,7 @@ static int memory_init(void);
static void memory_print_mode(void);
static sb_request_t memory_get_request(int);
static int memory_execute_request(sb_request_t *, int);
-static void memory_print_stats(void);
+static void memory_print_stats(sb_stat_t type);
static sb_test_t memory_test =
{
@@ -88,7 +88,7 @@ static sb_test_t memory_test =
/* Test arguments */
static ssize_t memory_block_size;
-static size_t memory_total_size;
+static off_t memory_total_size;
static unsigned int memory_scope;
static unsigned int memory_oper;
static unsigned int memory_access_rnd;
@@ -98,7 +98,8 @@ static unsigned int memory_hugetlb;
/* Statistics */
static unsigned int total_ops;
-static size_t total_bytes;
+static off_t total_bytes;
+static off_t last_bytes;
/* Array of per-thread buffers */
static int **buffers;
@@ -359,18 +360,36 @@ void memory_print_mode(void)
}
-void memory_print_stats(void)
+void memory_print_stats(sb_stat_t type)
{
- double total_time;
+ double seconds;
+ const double megabyte = 1024.0 * 1024.0;
- total_time = NS2SEC(sb_timer_value(&sb_globals.exec_timer));
-
- log_text(LOG_NOTICE, "Operations performed: %d (%8.2f ops/sec)\n", total_ops,
- total_ops / total_time);
- if (memory_oper != SB_MEM_OP_NONE)
- log_text(LOG_NOTICE, "%4.2f MB transferred (%4.2f MB/sec)\n",
- (double)total_bytes / (1024 * 1024),
- (double)total_bytes / (1024 * 1024) / total_time);
+ switch (type) {
+ case SB_STAT_INTERMEDIATE:
+ SB_THREAD_MUTEX_LOCK();
+ seconds = NS2SEC(sb_timer_split(&sb_globals.exec_timer));
+
+ log_timestamp(LOG_NOTICE, &sb_globals.exec_timer,
+ "%4.2f MB/sec,",
+ (double)(total_bytes - last_bytes) / megabyte / seconds);
+ last_bytes = total_bytes;
+ SB_THREAD_MUTEX_UNLOCK();
+
+ break;
+
+ case SB_STAT_CUMULATIVE:
+ seconds = NS2SEC(sb_timer_value(&sb_globals.exec_timer));
+
+ log_text(LOG_NOTICE, "Operations performed: %d (%8.2f ops/sec)\n",
+ total_ops, total_ops / seconds);
+ if (memory_oper != SB_MEM_OP_NONE)
+ log_text(LOG_NOTICE, "%4.2f MB transferred (%4.2f MB/sec)\n",
+ total_bytes / megabyte,
+ total_bytes / megabyte / seconds);
+
+ break;
+ }
}
#ifdef HAVE_LARGE_PAGES
diff --git a/sysbench/tests/oltp/sb_oltp.c b/sysbench/tests/oltp/sb_oltp.c
index 7457608..f98ed6b 100644
--- a/sysbench/tests/oltp/sb_oltp.c
+++ b/sysbench/tests/oltp/sb_oltp.c
@@ -199,7 +199,7 @@ static int oltp_init(void);
static void oltp_print_mode(void);
static sb_request_t oltp_get_request(int);
static int oltp_execute_request(sb_request_t *, int);
-static void oltp_print_stats(void);
+static void oltp_print_stats(sb_stat_t type);
static db_conn_t *oltp_connect(void);
static int oltp_disconnect(db_conn_t *);
static int oltp_reconnect(int thread_id);
@@ -247,6 +247,7 @@ static int read_ops;
static int write_ops;
static int other_ops;
static int transactions;
+static int last_transactions;
static int deadlocks;
static sb_timer_t *exec_timers;
@@ -498,7 +499,13 @@ int oltp_cmd_prepare(void)
}
oltp_disconnect(con);
-
+
+ read_ops = 0;
+ write_ops = 0;
+ other_ops = 0;
+ transactions = last_transactions = 0;
+ deadlocks = 0;
+
return 0;
error:
@@ -1349,14 +1356,36 @@ int oltp_execute_request(sb_request_t *sb_req, int thread_id)
}
-void oltp_print_stats(void)
+void oltp_print_stats(sb_stat_t type)
{
- double total_time;
+ double seconds;
unsigned int i;
sb_timer_t exec_timer;
sb_timer_t fetch_timer;
+ int curr_transactions, num_transactions;
+
+ if (type == SB_STAT_INTERMEDIATE)
+ {
+ SB_THREAD_MUTEX_LOCK();
+
+ seconds = NS2SEC(sb_timer_split(&sb_globals.exec_timer));
+ curr_transactions = transactions;
+ num_transactions = curr_transactions - last_transactions;
+ last_transactions = curr_transactions;
+
+ SB_THREAD_MUTEX_UNLOCK();
+
+ log_timestamp(LOG_NOTICE, &sb_globals.exec_timer,
+ "threads: %d, tps: %4.2f",
+ sb_globals.num_threads, num_transactions / seconds);
+
+ return;
+ }
+ else if (type != SB_STAT_CUMULATIVE)
+ return;
+
+ seconds = NS2SEC(sb_timer_value(&sb_globals.exec_timer));
- total_time = NS2SEC(sb_timer_value(&sb_globals.exec_timer));
log_text(LOG_NOTICE, "OLTP test statistics:");
log_text(LOG_NOTICE, " queries performed:");
@@ -1369,14 +1398,14 @@ void oltp_print_stats(void)
log_text(LOG_NOTICE, " total: %d",
read_ops + write_ops + other_ops);
log_text(LOG_NOTICE, " transactions: %-6d"
- " (%.2f per sec.)", transactions, transactions / total_time);
+ " (%.2f per sec.)", transactions, transactions / seconds);
log_text(LOG_NOTICE, " deadlocks: %-6d"
- " (%.2f per sec.)", deadlocks, deadlocks / total_time);
+ " (%.2f per sec.)", deadlocks, deadlocks / seconds);
log_text(LOG_NOTICE, " read/write requests: %-6d"
" (%.2f per sec.)", read_ops + write_ops,
- (read_ops + write_ops) / total_time);
+ (read_ops + write_ops) / seconds);
log_text(LOG_NOTICE, " other operations: %-6d"
- " (%.2f per sec.)", other_ops, other_ops / total_time);
+ " (%.2f per sec.)", other_ops, other_ops / seconds);
if (sb_globals.debug)
{