1:21 a.m.
When testing throughput, we care about the time spent sending requests.
Measure and log the time spent in the request loop. This remove the time
to start the threads and connect to the nbd server from the results, and
it ensure that all threads run the same amount of time, even if they do
not start exactly at the same time.
Running the tests multiple times show that threads run random time
between 10 to 11 seconds, but we compute the throughput assuming run
time of 10 seconds.
Example runs:
$ ./synch-parallel.sh
thread 5: finished OK in 10.054800 seconds
thread 1: finished OK in 10.054912 seconds
thread 2: finished OK in 10.055090 seconds
thread 0: finished OK in 10.055246 seconds
thread 6: finished OK in 10.055210 seconds
thread 7: finished OK in 10.055042 seconds
thread 3: finished OK in 10.055282 seconds
thread 4: finished OK in 10.055420 seconds
TLS: disabled
bytes sent: 6190678016 (619.068 Mbytes/s)
bytes received: 6183370752 (618.337 Mbytes/s)
I/O requests: 755252 (75525.2 IOPS)
$ ./synch-parallel.sh
thread 0: finished OK in 10.982875 seconds
thread 6: finished OK in 10.982651 seconds
thread 4: finished OK in 10.981958 seconds
thread 5: finished OK in 10.982700 seconds
thread 2: finished OK in 10.982774 seconds
thread 1: finished OK in 10.982976 seconds
thread 3: finished OK in 10.982834 seconds
thread 7: finished OK in 10.982610 seconds
TLS: disabled
bytes sent: 6646644736 (664.664 Mbytes/s)
bytes received: 6632275968 (663.228 Mbytes/s)
I/O requests: 810481 (81048.1 IOPS)
If we use the average thread runtime to calculate the stats, the results
would be:
Run 1:
run time: 10.054
bytes sent: 6190678016 (615.742 Mbytes/s)
bytes received: 6183370752 (615.015 Mbytes/s)
I/O requests: 755252 (75119.5 IOPS)
Run 2:
run time: 10.982
bytes sent: 6646644736 (605.230 Mbytes/s)
bytes received: 6632275968 (603.922 Mbytes/s)
I/O requests: 810481 (73800.8 IOPS)
Run 2 results are off by ~10%.
Signed-off-by: Nir Soffer <nsoffer(a)redhat.com>
---
tests/synch-parallel.c | 20 +++++++++++++++++++-
1 file changed, 19 insertions(+), 1 deletion(-)
diff --git a/tests/synch-parallel.c b/tests/synch-parallel.c
index d5efa3f..686e406 100644
--- a/tests/synch-parallel.c
+++ b/tests/synch-parallel.c
@@ -16,73 +16,85 @@
* Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
*/
/* Test synchronous parallel high level API requests on different
* handles. There should be no shared state between the handles so
* this should run at full speed (albeit with us only having a single
* command per thread in flight).
*/
#include <config.h>
#include <stdio.h>
#include <stdlib.h>
#include <stdbool.h>
#include <stdint.h>
#include <inttypes.h>
#include <string.h>
#include <unistd.h>
#include <errno.h>
#include <assert.h>
+#include <sys/time.h>
#include <pthread.h>
#include <libnbd.h>
#include "byte-swapping.h"
/* We keep a shadow of the RAM disk so we can check integrity of the data. */
static char *ramdisk;
/* This is also defined in synch-parallel.sh and checked here. */
#define EXPORTSIZE (8*1024*1024)
/* How long (seconds) that the test will run for. */
#define RUN_TIME 10
/* Number of threads. */
#define NR_THREADS 8
+#define MICROSECONDS 1000000
+
/* Unix socket. */
static const char *unixsocket;
struct thread_status {
size_t i; /* Thread index, 0 .. NR_THREADS-1 */
time_t end_time; /* Threads run until this end time. */
uint64_t offset, length; /* Area assigned to this thread. */
int status; /* Return status. */
unsigned requests; /* Total number of requests made. */
uint64_t bytes_sent, bytes_received; /* Bytes sent and received by thread. */
};
static void *start_thread (void *arg);
+static inline int64_t
+microtime (void)
+{
+ struct timeval tv;
+
+ gettimeofday(&tv, NULL);
+ return tv.tv_sec * MICROSECONDS + tv.tv_usec;
+}
+
int
main (int argc, char *argv[])
{
pthread_t threads[NR_THREADS];
struct thread_status status[NR_THREADS];
size_t i;
time_t t;
int err;
unsigned requests, errors;
uint64_t bytes_sent, bytes_received;
if (argc != 2) {
fprintf (stderr, "%s socket\n", argv[0]);
exit (EXIT_FAILURE);
}
unixsocket = argv[1];
/* Get the current time and the end time. */
time (&t);
t += RUN_TIME;
@@ -156,40 +168,41 @@ main (int argc, char *argv[])
printf ("bytes received: %" PRIu64 " (%g Mbytes/s)\n",
bytes_received, (double) bytes_received / RUN_TIME / 1000000);
printf ("I/O requests: %u (%g IOPS)\n",
requests, (double) requests / RUN_TIME);
exit (errors == 0 ? EXIT_SUCCESS : EXIT_FAILURE);
}
#define BUFFER_SIZE 16384
static void *
start_thread (void *arg)
{
struct thread_status *status = arg;
struct nbd_handle *nbd;
char *buf;
int cmd;
uint64_t offset;
time_t t;
+ int64_t start_usec, run_usec;
buf = calloc (BUFFER_SIZE, 1);
if (buf == NULL) {
perror ("calloc");
exit (EXIT_FAILURE);
}
nbd = nbd_create ();
if (nbd == NULL) {
fprintf (stderr, "%s\n", nbd_get_error ());
exit (EXIT_FAILURE);
}
#ifdef TLS
/* Require TLS on the handle and fail if not available or if the
* handshake fails.
*/
if (nbd_set_tls (nbd, LIBNBD_TLS_REQUIRE) == -1) {
fprintf (stderr, "%s\n", nbd_get_error ());
exit (EXIT_FAILURE);
@@ -199,73 +212,78 @@ start_thread (void *arg)
fprintf (stderr, "%s\n", nbd_get_error ());
exit (EXIT_FAILURE);
}
if (nbd_set_tls_psk_file (nbd, "keys.psk") == -1) {
fprintf (stderr, "%s\n", nbd_get_error ());
exit (EXIT_FAILURE);
}
#endif
/* Connect to nbdkit. */
if (nbd_connect_unix (nbd, unixsocket) == -1) {
fprintf (stderr, "%s\n", nbd_get_error ());
exit (EXIT_FAILURE);
}
assert (nbd_get_size (nbd) == EXPORTSIZE);
assert (nbd_can_multi_conn (nbd) > 0);
assert (nbd_is_read_only (nbd) == 0);
+ start_usec = microtime ();
+
/* Issue commands. */
while (1) {
/* Run until the timer expires. */
time (&t);
if (t > status->end_time)
break;
/* Issue a synchronous read or write command. */
offset = status->offset + (rand () % (status->length - BUFFER_SIZE));
cmd = rand () & 1;
if (cmd == 0) {
if (nbd_pwrite (nbd, buf, BUFFER_SIZE, offset, 0) == -1) {
fprintf (stderr, "%s\n", nbd_get_error ());
goto error;
}
status->bytes_sent += BUFFER_SIZE;
memcpy (&ramdisk[offset], buf, BUFFER_SIZE);
}
else {
if (nbd_pread (nbd, buf, BUFFER_SIZE, offset, 0) == -1) {
fprintf (stderr, "%s\n", nbd_get_error ());
goto error;
}
status->bytes_received += BUFFER_SIZE;
if (memcmp (&ramdisk[offset], buf, BUFFER_SIZE) != 0) {
fprintf (stderr, "thread %zu: DATA INTEGRITY ERROR!\n", status->i);
goto error;
}
}
status->requests++;
}
- printf ("thread %zu: finished OK\n", status->i);
+ run_usec = microtime () - start_usec;
+
+ printf ("thread %zu: finished OK in %.6f seconds\n",
+ status->i, (double) run_usec / MICROSECONDS);
if (nbd_shutdown (nbd, 0) == -1) {
fprintf (stderr, "%s\n", nbd_get_error ());
goto error;
}
nbd_close (nbd);
free (buf);
status->status = 0;
pthread_exit (status);
error:
free (buf);
fprintf (stderr, "thread %zu: failed\n", status->i);
status->status = -1;
pthread_exit (status);
}
--
2.31.1