Add raw data mode to store every possible latency measurement result. 27/268727/2
authorAdam Michalski <a.michalski2@partner.samsung.com>
Thu, 30 Dec 2021 11:22:29 +0000 (12:22 +0100)
committerAdam Michalski <a.michalski2@partner.samsung.com>
Thu, 30 Dec 2021 15:55:10 +0000 (16:55 +0100)
Facilitates the creation of histograms from a large number of samples.
Latencies are saved in a simple CSV file.

Change-Id: I5d98289787a6f352f4998d421e87164e2145c901

benchmark/gdbus.c
benchmark/libdbus-p2p-server.cpp
benchmark/libdbus.c
benchmark/p2p-gdbus.c
benchmark/pipe.c
benchmark/sharedmem.c
benchmark/socket.c

index f1abff90e9c175d86feb1ddabb294ca91656406e..c4df6ab049f82c03b9d5fe3056f6bc4ee351e5a4 100644 (file)
@@ -21,6 +21,9 @@ unsigned long long bw;
 
 bool lt_on, bw_on;
 
+bool raw_data_on;               /* dump raw data (every possible result) */
+FILE *raw_data_fd;
+
 static void server_name_acquired_handler (GDBusConnection *conn, const gchar *name, gpointer user_data)
 { }
 
@@ -86,6 +89,8 @@ static void handle_method_call (GDBusConnection       *connection,
 #ifdef DEBUG_ON
                        printf("latency: %0.4f\n", lt);
 #endif
+                       if (raw_data_on)
+                               fprintf(raw_data_fd, "%0.4f\n", lt);
 
                        if(lt > 0) {
                                lt_cnt++;
@@ -380,10 +385,21 @@ void Measure_latency(void)
                        perror("fork");
                        return;
                default:
+                       if (raw_data_on) {
+                               raw_data_fd = fopen("gdbus-latency.csv", "w");
+                               if (raw_data_fd == NULL) {
+                                       perror("fopen");
+                                       return;
+                               }
+                               fprintf(raw_data_fd, "Latency\n");
+                       }
+
                        Receive(msize, "org.gdbus.server", "/org/gdbus/server", true);
                        printf("min: %0.4f(us), max: %0.4f(us), avg: %0.4f(us)\n", min, max, total/lt_cnt);
 
                        waitpid(pid, NULL, 0);
+                       if (raw_data_on)
+                               fclose(raw_data_fd);
                        return;
        }
 }
@@ -401,7 +417,7 @@ main(int argc, char **argv)
 
        msize = 3;
        lt_on = bw_on = false;
-       while((opt = getopt(argc, argv, "m:p:blh")) != -1) {
+       while((opt = getopt(argc, argv, "m:p:blhr")) != -1) {
                switch(opt) {
                case 'm':
                        msize = atoi(optarg);
@@ -423,6 +439,9 @@ main(int argc, char **argv)
                case 'l':
                        lt_on = true;
                        break;
+               case 'r':
+                       raw_data_on = true;     /* dump raw data */
+                       break;
                case 'h':
                        print_help(argv);
                        exit(0);
index 44cf3077cbcf11a256829ace1482e967d96f5a0f..05d2e2936620730b6bde07b9b11bc422be7df21e 100644 (file)
@@ -31,6 +31,8 @@
 #include <csignal>
 #include <functional>
 #include <iostream>
+#include <fstream>
+#include <iomanip>
 #include <limits>
 #include <memory>
 #include <tuple>
@@ -84,6 +86,10 @@ struct run_opts {
         *
         * Good for %-based comparisons, but avoid for time measurements. */
        bool busy_wait = false;
+
+       /* When enabled, the server collects all method call times and
+        * writes them out to a CSV file. Useful for distribution charts. */
+       bool raw_data_on = false;
 };
 
 run_opts get_opt (int argc, char ** argv)
@@ -91,7 +97,7 @@ run_opts get_opt (int argc, char ** argv)
        run_opts ret;
 
        int opt;
-       while ((opt = getopt(argc, argv, "wit:p:h")) != -1)
+       while ((opt = getopt(argc, argv, "wit:p:rh")) != -1)
        switch (opt) {
 
        case 't':
@@ -106,6 +112,9 @@ run_opts get_opt (int argc, char ** argv)
        case 'p':
                ret.sock_path = optarg;
                break;
+       case 'r':
+               ret.raw_data_on = true;
+               break;
        case 'h':
        default:
                ret.show_help = true;
@@ -132,18 +141,24 @@ struct conn_with_metadata {
 
        size_t warmup_tries;
 
+       bool raw_data_on;
+
+       std::ofstream &raw_data_out_file;
+
        std::unique_ptr <DBusConnection, DBusConnection_destructor> conn;
 
        bool finished;
 
        static DBusObjectPathVTable vtable;
 
-       conn_with_metadata (const run_opts & ro, DBusConnection * c)
+       conn_with_metadata (const run_opts & ro, DBusConnection * c, std::ofstream & rdof)
                : total_time (0)
                , total_count (0)
                , min_time (std::numeric_limits <uint64_t> :: max ())
                , max_time (std::numeric_limits <uint64_t> :: min ())
                , warmup_tries (ro.warmup_tries)
+               , raw_data_on(ro.raw_data_on)
+               , raw_data_out_file(rdof)
                , conn (c)
                , finished (false)
        {
@@ -163,6 +178,8 @@ struct conn_with_metadata {
                , min_time     (std::move(x.min_time))
                , max_time     (std::move(x.max_time))
                , warmup_tries (std::move(x.warmup_tries))
+               , raw_data_on  (std::move(x.raw_data_on))
+               , raw_data_out_file (x.raw_data_out_file)
                , conn         (std::move(x.conn))
                , finished     (std::move(x.finished))
        {
@@ -192,6 +209,8 @@ struct conn_with_metadata {
                min_time     = std::move(x.min_time);
                max_time     = std::move(x.max_time);
                warmup_tries = std::move(x.warmup_tries);
+               raw_data_on  = std::move(x.raw_data_on);
+               raw_data_out_file = std::move(x.raw_data_out_file);
                conn         = std::move(x.conn);
                finished     = std::move(x.finished);
 
@@ -250,6 +269,11 @@ DBusObjectPathVTable conn_with_metadata::vtable =
 
                        THIS->min_time = std::min (THIS->min_time, diff);
                        THIS->max_time = std::max (THIS->max_time, diff);
+
+                       if (THIS->raw_data_on) {
+                               THIS->raw_data_out_file << std::setprecision(4);
+                               THIS->raw_data_out_file << (double)diff << std::endl;
+                       }
                } else {
                        -- THIS->warmup_tries;
                }
@@ -266,6 +290,7 @@ void show_help (const char * argv0)
                << " [-p sock_path] "
                << " [-i (infinite listening)] "
                << " [-w (busy wait)] "
+               << " [-r (raw data dump)] "
                << std::endl
        ;
 }
@@ -303,6 +328,7 @@ void read_from_watch (DBusWatch * watch, bool wait_infinitely)
 int main (int argc, char ** argv)
 {
        run_opts opt = get_opt (argc, argv);
+       std::ofstream raw_data_out_file;
 
        if (opt.show_help) {
                show_help (argv[0]);
@@ -315,17 +341,27 @@ int main (int argc, char ** argv)
                return EXIT_FAILURE;
        }
 
+       if (opt.raw_data_on) {
+               raw_data_out_file.open("libdbus-p2p-latency.csv");
+               if (!raw_data_out_file.is_open()) {
+                       std::cerr << "cannot create raw data output file" << std::endl;
+                       return EXIT_FAILURE;
+               }
+               raw_data_out_file << "Latency" << std::endl;
+               raw_data_out_file << std::fixed;
+       }
+
        // Set up cleanup functions for `server`
        std::atexit (exit_func);
        std::signal (SIGINT , sig_handler);
        std::signal (SIGTERM, sig_handler);
 
        std::vector <conn_with_metadata> conns;
-       auto ud = std::make_pair (std::ref(opt), std::ref (conns));
+       auto ud = std::make_tuple (std::ref(opt), std::ref (conns), std::ref(raw_data_out_file));
        dbus_server_set_new_connection_function (server
                , [] (DBusServer * s, DBusConnection * c, void * data) {
-                       auto [opts, connz] = *(reinterpret_cast <decltype (&ud)> (data));
-                       connz.emplace_back (opts, c);
+                       auto [opts, connz, rdof] = *(reinterpret_cast <decltype (&ud)> (data));
+                       connz.emplace_back (opts, c, rdof);
                }
                , & ud // userdata
                , nullptr // userdata free func
index de4a44566c7e9bc1caab6716447bd3f3f04a6e36..de38164eb1768239ca3f23e9d711782f5ea1cc25 100644 (file)
@@ -21,6 +21,9 @@ unsigned long long bw;
 bool lt_on, bw_on;
 bool stop;
 
+bool raw_data_on;               /* dump raw data (every possible result) */
+FILE *raw_data_fd;
+
 static void unregistered_func (DBusConnection *connection, void *user_data)
 { }
 
@@ -48,6 +51,9 @@ static DBusHandlerResult message_func (DBusConnection *connection,
 
                        double lt = (double)(end - start) / 1000;
 
+                       if (raw_data_on)
+                               fprintf(raw_data_fd, "%0.4f\n", lt);
+
                        if(lt) {
                                lt_cnt++;
                                total += lt;
@@ -344,9 +350,21 @@ void Measure_latency(void)
                        perror("fork");
                        return;
                default:
+                       if (raw_data_on) {
+                               raw_data_fd = fopen("libdbus-latency.csv", "w");
+                               if (raw_data_fd == NULL) {
+                                       perror("fopen");
+                                       return;
+                               }
+                               fprintf(raw_data_fd, "Latency\n");
+                       }
+
                        Receive(msize, "org.libdbus.server", "/org/libdbus/server", true);
                        printf("min: %0.4f(us), max: %0.4f(us), avg: %0.4f(us)\n", min, max, total/lt_cnt);
                        waitpid(pid, NULL, 0);
+
+                       if (raw_data_on)
+                               fclose(raw_data_fd);
                        return;
        }
 }
@@ -364,7 +382,7 @@ main(int argc, char **argv)
 
        msize = 3;
        lt_on = bw_on = false;
-       while((opt = getopt(argc, argv, "m:p:blh")) != -1) {
+       while((opt = getopt(argc, argv, "m:p:blhr")) != -1) {
                switch(opt) {
                case 'm':
                        msize = atoi(optarg);
@@ -386,6 +404,9 @@ main(int argc, char **argv)
                case 'l':
                        lt_on = true;
                        break;
+               case 'r':
+                       raw_data_on = true;     /* dump raw data */
+                       break;
                case 'h':
                        print_help(argv);
                        exit(0);
index 8a38e936dabc04ea0c8bfa041b7acaa3a4b1aff7..fb63e8c78108bcd29b1488c7704cf68fbfb40699 100644 (file)
@@ -20,6 +20,9 @@ bool cpu_pin_to_same_core;          /* specifies, whether client & server proces
 bool lt_on,                         /* latency test */
      bw_on;                         /* bandwidth test */
 
+bool raw_data_on;                   /* dump raw data (every possible result) */
+FILE *raw_data_fd;
+
 static GDBusNodeInfo *introspection_data = NULL;
 
 typedef struct _state {
@@ -78,6 +81,8 @@ static void handle_method_call(GDBusConnection *connection,
                double lt = (double)(end - start) / 1000;
                if (state->verbose)
                        g_print("latency: %0.4f\n", lt);
+               if (raw_data_on)
+                       fprintf(raw_data_fd, "%0.4f\n", lt);
                if (lt > 0) {           /* latency */
                        lt_cnt++;
                        total += lt;
@@ -425,9 +430,19 @@ void Measure_latency(bool verbose)
                Send(msize, "org.gtk.GDBus.TestPeerInterface", "/org/gtk/GDBus/TestObject", "0", true, verbose);
                exit(0);
        default:                /* parent process */
+               if (raw_data_on) {
+                       raw_data_fd = fopen("p2pgdbus-latency.csv", "w");
+                       if (raw_data_fd == NULL) {
+                               perror("fopen");
+                               return;
+                       }
+                       fprintf(raw_data_fd, "Latency\n");
+               }
                Receive(msize, "org.gtk.GDBus.TestPeerInterface", "/org/gtk/GDBus/TestObject", "0", true, verbose);
                g_print("min: %0.4f(us), max: %0.4f(us), avg: %0.4f(us)\n", min, max, total/lt_cnt);
                waitpid(pid, NULL, 0);    /* wait for the child */
+               if (raw_data_on)
+                       fclose(raw_data_fd);
        }
 }
 
@@ -570,7 +585,7 @@ int main(int argc, char *argv[])
        n_real_tries = REAL_TRY;
        cpu_pin_to_same_core = false;
 
-       while ((opt = getopt(argc, argv, "m:p:blht:cv")) != -1) {
+       while ((opt = getopt(argc, argv, "m:p:blhrt:cv")) != -1) {
                switch(opt) {
                case 'm':
                        msize = atoi(optarg);
@@ -605,6 +620,9 @@ int main(int argc, char *argv[])
                case 'v':
                        verbose = true;
                        break;
+               case 'r':
+                       raw_data_on = true;     /* dump raw data */
+                       break;
                case 'h':
                        print_help(argv);
                        exit(0);
index 5d31e6e065ab791081bbe9c0bd23f69e5d87580f..0b649cb2359e2973ad129267ba8fc10652215566 100644 (file)
@@ -13,6 +13,9 @@ unsigned long long bw;
 
 bool lt_on, bw_on;
 
+bool raw_data_on;               /* dump raw data (every possible result) */
+FILE *raw_data_fd;
+
 void Receive(int rfd1, int rfd2, register int size, bool is_lt)
 {
        static int bw_cnt = 0;
@@ -44,7 +47,8 @@ void Receive(int rfd1, int rfd2, register int size, bool is_lt)
 #ifdef DEBUG_ON
                                printf("latency: %0.4f\n", lt);
 #endif
-
+                               if (raw_data_on)
+                                       fprintf(raw_data_fd, "%0.4f\n", lt);
                                if(lt > 0) {
                                        lt_cnt++;
                                        total += lt;
@@ -295,6 +299,14 @@ void Measure_latency(void)
                        perror("fork");
                        return;
                default:
+                       if (raw_data_on) {
+                               raw_data_fd = fopen("pipe-latency.csv", "w");
+                               if (raw_data_fd == NULL) {
+                                       perror("fopen");
+                                       return;
+                               }
+                               fprintf(raw_data_fd, "Latency\n");
+                       }
                        close(p1[1]);
                        close(p2[1]);
                        Receive(p1[0], p2[0], msize, true);
@@ -302,6 +314,8 @@ void Measure_latency(void)
                        close(p2[0]);
                        printf("min: %0.4f(us), max: %0.4f(us), avg: %0.4f(us)\n", min, max, total/lt_cnt);
                        waitpid(pid, NULL, 0);
+                       if (raw_data_on)
+                               fclose(raw_data_fd);
                        return;
        }
 }
@@ -319,7 +333,7 @@ main(int argc, char **argv)
 
        msize = 3;
        lt_on = bw_on = false;
-       while((opt = getopt(argc, argv, "m:p:blh")) != -1) {
+       while((opt = getopt(argc, argv, "m:p:blhr")) != -1) {
                switch(opt) {
                case 'm':
                        msize = atoi(optarg);
@@ -341,6 +355,9 @@ main(int argc, char **argv)
                case 'l':
                        lt_on = true;
                        break;
+               case 'r':
+                       raw_data_on = true;     /* dump raw data */
+                       break;
                case 'h':
                        print_help(argv);
                        exit(0);
index 66a6644629bb6505d8afb48b995b09975d5f4808..ccfe4cc9ad055af28a6c20b40d9d4e8d26ec2695 100644 (file)
@@ -19,6 +19,9 @@ unsigned long long bw;
 
 bool lt_on, bw_on;
 
+bool raw_data_on;               /* dump raw data (every possible result) */
+FILE *raw_data_fd;
+
 void Receive(void *r1, register char *r2, register int size, bool is_lt)
 {
        static int bw_cnt = 0;
@@ -50,7 +53,8 @@ repeat:
 #ifdef DEBUG_ON
                        printf("latency: %0.4f\n", lt);
 #endif
-
+                       if (raw_data_on)
+                               fprintf(raw_data_fd, "%0.4f\n", lt);
                        if(lt > 0) {
                                lt_cnt++;
                                total += lt;
@@ -367,9 +371,19 @@ void Measure_latency(void)
                        perror("fork");
                        return;
                default:
+                       if (raw_data_on) {
+                               raw_data_fd = fopen("sharedmem-latency.csv", "w");
+                               if (raw_data_fd == NULL) {
+                                       perror("fopen");
+                                       return;
+                               }
+                               fprintf(raw_data_fd, "Latency\n");
+                       }
                        Receive(shm_ptr[SHM1], shm_ptr[SHM2], msize, true);
                        printf("min: %0.4f(us), max: %0.4f(us), avg: %0.4f(us)\n", min, max, total/lt_cnt);
                        waitpid(pid, NULL, 0);
+                       if (raw_data_on)
+                               fclose(raw_data_fd);
                        ret = munmap(shm_ptr[SHM1], sizeof(unsigned long long));
                        if (ret != 0) {
                                perror("munmap");
@@ -410,7 +424,7 @@ main(int argc, char **argv)
 
        msize = 3;
        lt_on = bw_on = false;
-       while((opt = getopt(argc, argv, "m:p:blh")) != -1) {
+       while((opt = getopt(argc, argv, "m:p:blrh")) != -1) {
                switch(opt) {
                case 'm':
                        msize = atoi(optarg);
@@ -432,6 +446,9 @@ main(int argc, char **argv)
                case 'l':
                        lt_on = true;
                        break;
+               case 'r':
+                       raw_data_on = true;     /* dump raw data */
+                       break;
                case 'h':
                        print_help(argv);
                        exit(0);
index b9c7f3ccfbf80d3f553047b588fefa6d3e94e320..7541689bd4b9bb3861699aca61accd8f8f82f6fc 100644 (file)
@@ -13,6 +13,9 @@ unsigned long long bw;
 
 bool lt_on, bw_on;
 
+bool raw_data_on;               /* dump raw data (every possible result) */
+FILE *raw_data_fd;
+
 void Receive(int rfd1, int rfd2, register int size, bool is_lt)
 {
        static int bw_cnt = 0;
@@ -44,7 +47,8 @@ void Receive(int rfd1, int rfd2, register int size, bool is_lt)
 #ifdef DEBUG_ON
                                printf("latency: %0.4f\n", lt);
 #endif
-
+                               if (raw_data_on)
+                                       fprintf(raw_data_fd, "%0.4f\n", lt);
                                if(lt > 0) {
                                        lt_cnt++;
                                        total += lt;
@@ -294,11 +298,21 @@ void Measure_latency(void)
                        perror("fork");
                        return;
                default:
+                       if (raw_data_on) {
+                               raw_data_fd = fopen("socket-latency.csv", "w");
+                               if (raw_data_fd == NULL) {
+                                       perror("fopen");
+                                       return;
+                               }
+                               fprintf(raw_data_fd, "Latency\n");
+                       }
                        Receive(fd1[1], fd2[1], msize, true);
                        close(fd1[1]);
                        close(fd2[1]);
                        printf("min: %0.4f(us), max: %0.4f(us), avg: %0.4f(us)\n", min, max, total/lt_cnt);
                        waitpid(pid, NULL, 0);
+                       if (raw_data_on)
+                               fclose(raw_data_fd);
                        return;
        }
 }
@@ -316,7 +330,7 @@ main(int argc, char **argv)
 
        msize = 3;
        lt_on = bw_on = false;
-       while((opt = getopt(argc, argv, "m:p:blh")) != -1) {
+       while((opt = getopt(argc, argv, "m:p:blrh")) != -1) {
                switch(opt) {
                case 'm':
                        msize = atoi(optarg);
@@ -338,6 +352,9 @@ main(int argc, char **argv)
                case 'l':
                        lt_on = true;
                        break;
+               case 'r':
+                       raw_data_on = true;     /* dump raw data */
+                       break;
                case 'h':
                        print_help(argv);
                        exit(0);