From 4b0ea00caf837160b25482d48d1f7a95ba47d318 Mon Sep 17 00:00:00 2001 From: Bryan O'Donoghue Date: Mon, 17 Aug 2015 00:55:07 +0100 Subject: [PATCH] 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 Signed-off-by: Greg Kroah-Hartman --- drivers/staging/greybus/loopback.c | 155 ++++++++++++++++++++++++++--- 1 file changed, 140 insertions(+), 15 deletions(-) diff --git a/drivers/staging/greybus/loopback.c b/drivers/staging/greybus/loopback.c index 39375f1e0d8e..0d2de708ec0b 100644 --- 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); -- 2.20.1