greybus: loopback: graph round-trip time for all threads

This patch adds the ability to time the delta between all threads like this

t1 = timestmap();
thread1:gb_operation_sync();
thread2:gb_operation_sync();
t2 = timestamp();

In order to enable that behaviour without forcing an undesirable
checkpointing scheme this patch introduces a kfifo for each thread to store
the raw timestamps and calculate a time difference.

Signed-off-by: Bryan O'Donoghue <bryan.odonoghue@linaro.org>
Signed-off-by: Greg Kroah-Hartman <gregkh@google.com>

diff --git a/drivers/staging/greybus/loopback.c b/drivers/staging/greybus/loopback.c
index 39375f1e0d8ef888cae275456340b1c00f43860c..0d2de708ec0b0b67c74250ee7d27e9effb02b78e 100644 (file)
--- a/drivers/staging/greybus/loopback.c
+++ b/drivers/staging/greybus/loopback.c
@@ -36,6 +36,7 @@ struct gb_loopback_device {
        struct dentry *root;
        u32 count;
 
+       struct kfifo kfifo;
        struct mutex mutex;
        struct list_head list;
        wait_queue_head_t wq;
@@ -64,7 +65,8 @@ struct gb_loopback {
        struct gb_connection *connection;
 
        struct dentry *file;
-       struct kfifo kfifo;
+       struct kfifo kfifo_lat;
+       struct kfifo kfifo_ts;
        struct mutex mutex;
        struct task_struct *task;
        struct list_head entry;
@@ -75,6 +77,7 @@ struct gb_loopback {
        struct gb_loopback_stats throughput;
        struct gb_loopback_stats requests_per_second;
 
+       u32 lbid;
        u32 iteration_count;
        u64 elapsed_nsecs;
        u64 elapsed_nsecs_gb;
@@ -217,7 +220,8 @@ static void gb_loopback_check_attr(struct gb_loopback_device *gb_dev,
                                 "cannot log bytes %u kfifo_depth %u\n",
                                 gb_dev->iteration_max, kfifo_depth);
                }
-               kfifo_reset_out(&gb->kfifo);
+               kfifo_reset_out(&gb->kfifo_lat);
+               kfifo_reset_out(&gb->kfifo_ts);
                mutex_unlock(&gb->mutex);
        }
 
@@ -225,6 +229,7 @@ static void gb_loopback_check_attr(struct gb_loopback_device *gb_dev,
        case GB_LOOPBACK_TYPE_PING:
        case GB_LOOPBACK_TYPE_TRANSFER:
        case GB_LOOPBACK_TYPE_SINK:
+               kfifo_reset_out(&gb_dev->kfifo);
                gb_loopback_reset_stats(gb_dev);
                wake_up(&gb_dev->wq);
                break;
@@ -310,6 +315,13 @@ static u64 gb_loopback_calc_latency(struct timeval *ts, struct timeval *te)
        return __gb_loopback_calc_latency(t1, t2);
 }
 
+static void gb_loopback_push_latency_ts(struct gb_loopback *gb,
+                                       struct timeval *ts, struct timeval *te)
+{
+       kfifo_in(&gb->kfifo_ts, (unsigned char *)ts, sizeof(*ts));
+       kfifo_in(&gb->kfifo_ts, (unsigned char *)te, sizeof(*te));
+}
+
 static int gb_loopback_sink(struct gb_loopback *gb, u32 len)
 {
        struct timeval ts, te;
@@ -329,6 +341,7 @@ static int gb_loopback_sink(struct gb_loopback *gb, u32 len)
        do_gettimeofday(&te);
 
        /* Calculate the total time the message took */
+       gb_loopback_push_latency_ts(gb, &ts, &te);
        gb->elapsed_nsecs = gb_loopback_calc_latency(&ts, &te);
 
        /* Calculate non-greybus related component of the latency */
@@ -368,6 +381,7 @@ static int gb_loopback_transfer(struct gb_loopback *gb, u32 len)
        do_gettimeofday(&te);
 
        /* Calculate the total time the message took */
+       gb_loopback_push_latency_ts(gb, &ts, &te);
        gb->elapsed_nsecs = gb_loopback_calc_latency(&ts, &te);
 
        /* Calculate non-greybus related component of the latency */
@@ -401,6 +415,7 @@ static int gb_loopback_ping(struct gb_loopback *gb)
        do_gettimeofday(&te);
 
        /* Calculate the total time the message took */
+       gb_loopback_push_latency_ts(gb, &ts, &te);
        gb->elapsed_nsecs = gb_loopback_calc_latency(&ts, &te);
 
        /* Calculate non-greybus related component of the latency */
@@ -541,6 +556,59 @@ static void gb_loopback_throughput_update(struct gb_loopback *gb, u32 latency)
        gb_loopback_update_stats(&gb->throughput, throughput);
 }
 
+static int gb_loopback_calculate_aggregate_stats(void)
+{
+       struct gb_loopback *gb;
+       struct timeval ts;
+       struct timeval te;
+       u64 t1, t2;
+       u64 ts_min;
+       u64 te_max;
+       u64 elapsed_nsecs;
+       u32 lat;
+       int i, latched;
+       int rollover = 0;
+
+       for (i = 0; i < gb_dev.iteration_max; i++) {
+               latched = 0;
+               ts_min = 0;
+               te_max = 0;
+               list_for_each_entry(gb, &gb_dev.list, entry) {
+                       if (kfifo_out(&gb->kfifo_ts, &ts, sizeof(ts)) < sizeof(ts))
+                               goto error;
+                       if (kfifo_out(&gb->kfifo_ts, &te, sizeof(te)) < sizeof(te))
+                               goto error;
+                       t1 = timeval_to_ns(&ts);
+                       t2 = timeval_to_ns(&te);
+
+                       /* minimum timestamp is always what we want */
+                       if (latched == 0 || t1 < ts_min)
+                               ts_min = t1;
+
+                       /* maximum timestamp needs to handle rollover */
+                       if (t2 > t1) {
+                               if (latched == 0 || t2 > te_max)
+                                       te_max = t2;
+                       } else {
+                               if (latched == 0 || rollover == 0)
+                                       te_max = t2;
+                               if (rollover == 1 && t2 > te_max)
+                                       te_max = t2;
+                               rollover = 1;
+                       }
+                       latched = 1;
+               }
+               /* Calculate the aggregate timestamp */
+               elapsed_nsecs = __gb_loopback_calc_latency(ts_min, te_max);
+               lat = gb_loopback_nsec_to_usec_latency(elapsed_nsecs);
+               kfifo_in(&gb_dev.kfifo, (unsigned char *)&lat, sizeof(lat));
+       }
+       return 0;
+error:
+       kfifo_reset_out(&gb_dev.kfifo);
+       return -ENOMEM;
+}
+
 static void gb_loopback_calculate_stats(struct gb_loopback *gb)
 {
        u32 lat;
@@ -554,7 +622,7 @@ static void gb_loopback_calculate_stats(struct gb_loopback *gb)
        gb_loopback_update_stats(&gb->latency, lat);
 
        /* Raw latency log on a per thread basis */
-       kfifo_in(&gb->kfifo, (unsigned char *)&lat, sizeof(lat));
+       kfifo_in(&gb->kfifo_lat, (unsigned char *)&lat, sizeof(lat));
 
        /* Log throughput and requests using latency as benchmark */
        gb_loopback_throughput_update(gb, lat);
@@ -600,6 +668,7 @@ static int gb_loopback_fn(void *data)
                        }
                        /* Optionally terminate */
                        if (gb_dev.iteration_count == gb_dev.iteration_max) {
+                               gb_loopback_calculate_aggregate_stats();
                                gb_dev.type = 0;
                                mutex_unlock(&gb_dev.mutex);
                                continue;
@@ -645,28 +714,37 @@ sleep:
        return 0;
 }
 
-static int gb_loopback_dbgfs_latency_show(struct seq_file *s, void *unused)
+static int gb_loopback_dbgfs_latency_show_common(struct seq_file *s,
+                                                struct kfifo *kfifo,
+                                                struct mutex *mutex)
 {
-       struct gb_loopback *gb = s->private;
        u32 latency;
        int retval;
 
-       if (kfifo_len(&gb->kfifo) == 0) {
+       if (kfifo_len(kfifo) == 0) {
                retval = -EAGAIN;
                goto done;
        }
 
-       mutex_lock(&gb->mutex);
-       retval = kfifo_out(&gb->kfifo, &latency, sizeof(latency));
+       mutex_lock(mutex);
+       retval = kfifo_out(kfifo, &latency, sizeof(latency));
        if (retval > 0) {
                seq_printf(s, "%u", latency);
                retval = 0;
        }
-       mutex_unlock(&gb->mutex);
+       mutex_unlock(mutex);
 done:
        return retval;
 }
 
+static int gb_loopback_dbgfs_latency_show(struct seq_file *s, void *unused)
+{
+       struct gb_loopback *gb = s->private;
+
+       return gb_loopback_dbgfs_latency_show_common(s, &gb->kfifo_lat,
+                                                    &gb->mutex);
+}
+
 static int gb_loopback_latency_open(struct inode *inode, struct file *file)
 {
        return single_open(file, gb_loopback_dbgfs_latency_show,
@@ -717,18 +795,24 @@ static int gb_loopback_connection_init(struct gb_connection *connection)
        mutex_unlock(&gb_dev.mutex);
 
        /* Allocate kfifo */
-       if (kfifo_alloc(&gb->kfifo, kfifo_depth * sizeof(u32),
+       if (kfifo_alloc(&gb->kfifo_lat, kfifo_depth * sizeof(u32),
                          GFP_KERNEL)) {
                retval = -ENOMEM;
                goto out_sysfs;
        }
+       if (kfifo_alloc(&gb->kfifo_ts, kfifo_depth * sizeof(struct timeval) * 2,
+                         GFP_KERNEL)) {
+               retval = -ENOMEM;
+               goto out_kfifo0;
+       }
 
        /* Fork worker thread */
        mutex_init(&gb->mutex);
+       gb->lbid = 1 << gb_dev.count;
        gb->task = kthread_run(gb_loopback_fn, gb, "gb_loopback");
        if (IS_ERR(gb->task)) {
                retval = PTR_ERR(gb->task);
-               goto out_kfifo;
+               goto out_kfifo1;
        }
 
        mutex_lock(&gb_dev.mutex);
@@ -737,8 +821,10 @@ static int gb_loopback_connection_init(struct gb_connection *connection)
        gb_dev.count++;
        return 0;
 
-out_kfifo:
-       kfifo_free(&gb->kfifo);
+out_kfifo1:
+       kfifo_free(&gb->kfifo_ts);
+out_kfifo0:
+       kfifo_free(&gb->kfifo_lat);
 out_sysfs:
        sysfs_remove_groups(&connection->dev.kobj, loopback_groups);
 out_debugfs:
@@ -758,7 +844,8 @@ static void gb_loopback_connection_exit(struct gb_connection *connection)
        if (!IS_ERR_OR_NULL(gb->task))
                kthread_stop(gb->task);
 
-       kfifo_free(&gb->kfifo);
+       kfifo_free(&gb->kfifo_lat);
+       kfifo_free(&gb->kfifo_ts);
        sysfs_remove_groups(&connection->dev.kobj, loopback_groups);
        debugfs_remove(gb->file);
        kfree(gb);
@@ -774,20 +861,58 @@ static struct gb_protocol loopback_protocol = {
        .request_recv           = gb_loopback_request_recv,
 };
 
+static int gb_loopback_dbgfs_dev_latency_show(struct seq_file *s, void *unused)
+{
+       struct gb_loopback_device *gb_dev = s->private;
+
+       return gb_loopback_dbgfs_latency_show_common(s, &gb_dev->kfifo,
+                                                    &gb_dev->mutex);
+}
+
+static int gb_loopback_dev_latency_open(struct inode *inode, struct file *file)
+{
+       return single_open(file, gb_loopback_dbgfs_dev_latency_show,
+                          inode->i_private);
+}
+
+static const struct file_operations gb_loopback_debugfs_dev_latency_ops = {
+       .open           = gb_loopback_dev_latency_open,
+       .read           = seq_read,
+       .llseek         = seq_lseek,
+       .release        = single_release,
+};
+
 static int loopback_init(void)
 {
+       int retval;
+
        init_waitqueue_head(&gb_dev.wq);
        INIT_LIST_HEAD(&gb_dev.list);
        mutex_init(&gb_dev.mutex);
        gb_dev.root = debugfs_create_dir("gb_loopback", NULL);
 
-       return gb_protocol_register(&loopback_protocol);
+       if (kfifo_alloc(&gb_dev.kfifo, kfifo_depth * sizeof(u32), GFP_KERNEL)) {
+               retval = -ENOMEM;
+               goto error_debugfs;
+       }
+
+       debugfs_create_file("aggregate_latency", S_IFREG | S_IRUGO,
+                           gb_dev.root, &gb_dev,
+                           &gb_loopback_debugfs_dev_latency_ops);
+       retval = gb_protocol_register(&loopback_protocol);
+       if (!retval)
+               return retval;
+
+error_debugfs:
+       debugfs_remove_recursive(gb_dev.root);
+       return retval;
 }
 module_init(loopback_init);
 
 static void __exit loopback_exit(void)
 {
        debugfs_remove_recursive(gb_dev.root);
+       kfifo_free(&gb_dev.kfifo);
        gb_protocol_deregister(&loopback_protocol);
 }
 module_exit(loopback_exit);