[PATCH 1/2] dma-buf/fence-chain: Report time spent in wait_* test cases

[Janusz Krzysztofik]

CI results indicate excessive time spent on processing of wait_backward
selftest.  For easy comparison, report processing time of each wait_* test
case.

Suggested-by: Chris Wilson <chris.p.wilson at linux.intel.com>
Signed-off-by: Janusz Krzysztofik <janusz.krzysztofik at linux.intel.com>
---
 drivers/dma-buf/st-dma-fence-chain.c | 15 +++++++++++++++
 1 file changed, 15 insertions(+)

diff --git a/drivers/dma-buf/st-dma-fence-chain.c b/drivers/dma-buf/st-dma-fence-chain.c
index ed4b323886e43..80598da9237af 100644
--- a/drivers/dma-buf/st-dma-fence-chain.c
+++ b/drivers/dma-buf/st-dma-fence-chain.c
@@ -572,6 +572,7 @@ static int wait_forward(void *arg)
 {
 	struct fence_chains fc;
 	struct task_struct *tsk;
+	ktime_t dt;
 	int err;
 	int i;
 
@@ -587,8 +588,12 @@ static int wait_forward(void *arg)
 	get_task_struct(tsk);
 	yield_to(tsk, true);
 
+	dt = -ktime_get();
 	for (i = 0; i < fc.chain_length; i++)
 		dma_fence_signal(fc.fences[i]);
+	dt += ktime_get();
+
+	pr_info("%s: %d signals in %llu ns\n", __func__, fc.chain_length, ktime_to_ns(dt));
 
 	err = kthread_stop_put(tsk);
 
@@ -601,6 +606,7 @@ static int wait_backward(void *arg)
 {
 	struct fence_chains fc;
 	struct task_struct *tsk;
+	ktime_t dt;
 	int err;
 	int i;
 
@@ -616,8 +622,12 @@ static int wait_backward(void *arg)
 	get_task_struct(tsk);
 	yield_to(tsk, true);
 
+	dt = -ktime_get();
 	for (i = fc.chain_length; i--; )
 		dma_fence_signal(fc.fences[i]);
+	dt += ktime_get();
+
+	pr_info("%s: %d signals in %llu ns\n", __func__, fc.chain_length, ktime_to_ns(dt));
 
 	err = kthread_stop_put(tsk);
 
@@ -646,6 +656,7 @@ static int wait_random(void *arg)
 {
 	struct fence_chains fc;
 	struct task_struct *tsk;
+	ktime_t dt;
 	int err;
 	int i;
 
@@ -663,8 +674,12 @@ static int wait_random(void *arg)
 	get_task_struct(tsk);
 	yield_to(tsk, true);
 
+	dt = -ktime_get();
 	for (i = 0; i < fc.chain_length; i++)
 		dma_fence_signal(fc.fences[i]);
+	dt += ktime_get();
+
+	pr_info("%s: %d signals in %llu ns\n", __func__, fc.chain_length, ktime_to_ns(dt));
 
 	err = kthread_stop_put(tsk);
 
-- 
2.50.1