diff mbox series

[i-g-t,1/7] gem_wsim: Check sleep times

Message ID 20180814150519.20204-2-tvrtko.ursulin@linux.intel.com (mailing list archive)
State New, archived
Headers show
Series gem_wsim fixes and new features | expand

Commit Message

Tvrtko Ursulin Aug. 14, 2018, 3:05 p.m. UTC
From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>

Notice in more places if we are running behind.

Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
---
 benchmarks/gem_wsim.c | 52 ++++++++++++++++++++++++++++++++++++++-----
 1 file changed, 46 insertions(+), 6 deletions(-)

Comments

Chris Wilson Aug. 14, 2018, 3:09 p.m. UTC | #1
Quoting Tvrtko Ursulin (2018-08-14 16:05:13)
> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> 
> Notice in more places if we are running behind.
> 
> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> ---
>  benchmarks/gem_wsim.c | 52 ++++++++++++++++++++++++++++++++++++++-----
>  1 file changed, 46 insertions(+), 6 deletions(-)
> 
> diff --git a/benchmarks/gem_wsim.c b/benchmarks/gem_wsim.c
> index 80f180829241..ead91b0f009b 100644
> --- a/benchmarks/gem_wsim.c
> +++ b/benchmarks/gem_wsim.c
> @@ -1718,6 +1718,21 @@ static bool sync_deps(struct workload *wrk, struct w_step *w)
>         return synced;
>  }
>  
> +static unsigned int measured_usleep(unsigned int usec)
> +{
> +       struct timespec ts = { };
> +       unsigned int slept;
> +
> +       slept = igt_nsec_elapsed(&ts);
> +       igt_assert(slept == 0);
> +       do {
> +               usleep(usec - slept);
> +               slept = igt_nsec_elapsed(&ts) / 1000;
> +       } while (slept < usec);
> +
> +       return igt_nsec_elapsed(&ts);
> +}
> +
>  static void *run_workload(void *data)
>  {
>         struct workload *wrk = (struct workload *)data;
> @@ -1739,7 +1754,7 @@ static void *run_workload(void *data)
>              count++) {
>                 unsigned int cur_seqno = wrk->sync_seqno;
>  
> -               clock_gettime(CLOCK_MONOTONIC, &wrk->repeat_start);
> +               igt_gettime(&wrk->repeat_start);

Were you already linking against libigt?
This code is not set up to hit an igt_assert()...
-Chris
Tvrtko Ursulin Aug. 14, 2018, 3:21 p.m. UTC | #2
On 14/08/2018 16:09, Chris Wilson wrote:
> Quoting Tvrtko Ursulin (2018-08-14 16:05:13)
>> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>>
>> Notice in more places if we are running behind.
>>
>> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>> ---
>>   benchmarks/gem_wsim.c | 52 ++++++++++++++++++++++++++++++++++++++-----
>>   1 file changed, 46 insertions(+), 6 deletions(-)
>>
>> diff --git a/benchmarks/gem_wsim.c b/benchmarks/gem_wsim.c
>> index 80f180829241..ead91b0f009b 100644
>> --- a/benchmarks/gem_wsim.c
>> +++ b/benchmarks/gem_wsim.c
>> @@ -1718,6 +1718,21 @@ static bool sync_deps(struct workload *wrk, struct w_step *w)
>>          return synced;
>>   }
>>   
>> +static unsigned int measured_usleep(unsigned int usec)
>> +{
>> +       struct timespec ts = { };
>> +       unsigned int slept;
>> +
>> +       slept = igt_nsec_elapsed(&ts);
>> +       igt_assert(slept == 0);
>> +       do {
>> +               usleep(usec - slept);
>> +               slept = igt_nsec_elapsed(&ts) / 1000;
>> +       } while (slept < usec);
>> +
>> +       return igt_nsec_elapsed(&ts);
>> +}
>> +
>>   static void *run_workload(void *data)
>>   {
>>          struct workload *wrk = (struct workload *)data;
>> @@ -1739,7 +1754,7 @@ static void *run_workload(void *data)
>>               count++) {
>>                  unsigned int cur_seqno = wrk->sync_seqno;
>>   
>> -               clock_gettime(CLOCK_MONOTONIC, &wrk->repeat_start);
>> +               igt_gettime(&wrk->repeat_start);
> 
> Were you already linking against libigt?
> This code is not set up to hit an igt_assert()...

This code meaning gem_wsim? There's a lot of asserts in it already, and 
when they trigger traceback looks fine. What do you think is missing?

Regards,

Tvrtko
Chris Wilson Aug. 14, 2018, 3:27 p.m. UTC | #3
Quoting Tvrtko Ursulin (2018-08-14 16:21:08)
> 
> On 14/08/2018 16:09, Chris Wilson wrote:
> > Quoting Tvrtko Ursulin (2018-08-14 16:05:13)
> >> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> >>
> >> Notice in more places if we are running behind.
> >>
> >> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
> >> ---
> >>   benchmarks/gem_wsim.c | 52 ++++++++++++++++++++++++++++++++++++++-----
> >>   1 file changed, 46 insertions(+), 6 deletions(-)
> >>
> >> diff --git a/benchmarks/gem_wsim.c b/benchmarks/gem_wsim.c
> >> index 80f180829241..ead91b0f009b 100644
> >> --- a/benchmarks/gem_wsim.c
> >> +++ b/benchmarks/gem_wsim.c
> >> @@ -1718,6 +1718,21 @@ static bool sync_deps(struct workload *wrk, struct w_step *w)
> >>          return synced;
> >>   }
> >>   
> >> +static unsigned int measured_usleep(unsigned int usec)
> >> +{
> >> +       struct timespec ts = { };
> >> +       unsigned int slept;
> >> +
> >> +       slept = igt_nsec_elapsed(&ts);
> >> +       igt_assert(slept == 0);
> >> +       do {
> >> +               usleep(usec - slept);
> >> +               slept = igt_nsec_elapsed(&ts) / 1000;
> >> +       } while (slept < usec);
> >> +
> >> +       return igt_nsec_elapsed(&ts);
> >> +}
> >> +
> >>   static void *run_workload(void *data)
> >>   {
> >>          struct workload *wrk = (struct workload *)data;
> >> @@ -1739,7 +1754,7 @@ static void *run_workload(void *data)
> >>               count++) {
> >>                  unsigned int cur_seqno = wrk->sync_seqno;
> >>   
> >> -               clock_gettime(CLOCK_MONOTONIC, &wrk->repeat_start);
> >> +               igt_gettime(&wrk->repeat_start);
> > 
> > Were you already linking against libigt?
> > This code is not set up to hit an igt_assert()...
> 
> This code meaning gem_wsim? There's a lot of asserts in it already, and 
> when they trigger traceback looks fine. What do you think is missing?

We have different values of fine ;) Looks nothing but a mess for me.
I don't think igt itself has much value outside of being the test
runner, we've baked too much knowledge of it being a test harness into
the code (and in many cases work to reduce those assumptions). I'd
rather libigtcore be distinct and not bring in the interlinked
igt_subtest+igt_assert.
-Chris
Tvrtko Ursulin Aug. 14, 2018, 6:27 p.m. UTC | #4
On 14/08/2018 16:27, Chris Wilson wrote:
> Quoting Tvrtko Ursulin (2018-08-14 16:21:08)
>>
>> On 14/08/2018 16:09, Chris Wilson wrote:
>>> Quoting Tvrtko Ursulin (2018-08-14 16:05:13)
>>>> From: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>>>>
>>>> Notice in more places if we are running behind.
>>>>
>>>> Signed-off-by: Tvrtko Ursulin <tvrtko.ursulin@intel.com>
>>>> ---
>>>>    benchmarks/gem_wsim.c | 52 ++++++++++++++++++++++++++++++++++++++-----
>>>>    1 file changed, 46 insertions(+), 6 deletions(-)
>>>>
>>>> diff --git a/benchmarks/gem_wsim.c b/benchmarks/gem_wsim.c
>>>> index 80f180829241..ead91b0f009b 100644
>>>> --- a/benchmarks/gem_wsim.c
>>>> +++ b/benchmarks/gem_wsim.c
>>>> @@ -1718,6 +1718,21 @@ static bool sync_deps(struct workload *wrk, struct w_step *w)
>>>>           return synced;
>>>>    }
>>>>    
>>>> +static unsigned int measured_usleep(unsigned int usec)
>>>> +{
>>>> +       struct timespec ts = { };
>>>> +       unsigned int slept;
>>>> +
>>>> +       slept = igt_nsec_elapsed(&ts);
>>>> +       igt_assert(slept == 0);
>>>> +       do {
>>>> +               usleep(usec - slept);
>>>> +               slept = igt_nsec_elapsed(&ts) / 1000;
>>>> +       } while (slept < usec);
>>>> +
>>>> +       return igt_nsec_elapsed(&ts);
>>>> +}
>>>> +
>>>>    static void *run_workload(void *data)
>>>>    {
>>>>           struct workload *wrk = (struct workload *)data;
>>>> @@ -1739,7 +1754,7 @@ static void *run_workload(void *data)
>>>>                count++) {
>>>>                   unsigned int cur_seqno = wrk->sync_seqno;
>>>>    
>>>> -               clock_gettime(CLOCK_MONOTONIC, &wrk->repeat_start);
>>>> +               igt_gettime(&wrk->repeat_start);
>>>
>>> Were you already linking against libigt?
>>> This code is not set up to hit an igt_assert()...
>>
>> This code meaning gem_wsim? There's a lot of asserts in it already, and
>> when they trigger traceback looks fine. What do you think is missing?
> 
> We have different values of fine ;) Looks nothing but a mess for me.
> I don't think igt itself has much value outside of being the test
> runner, we've baked too much knowledge of it being a test harness into
> the code (and in many cases work to reduce those assumptions). I'd
> rather libigtcore be distinct and not bring in the interlinked
> igt_subtest+igt_assert.

To not use it is to reimplement existing handy helpers - not ideal.

To split the test bits from useful helpers sounds like quite a task.

To wean gem_wsim off most igt_ stuff needs decision to be made on the 
former - what is core api, and what is test related.

To me problems outweigh the benefit. :( If gem_wsim was under tools, 
like intel_gpu_top, then yeah, it would be justifiable. Since it is in 
benchmarks I don't think we should bother.

Regards,

Tvrtko
Chris Wilson Aug. 14, 2018, 6:34 p.m. UTC | #5
Quoting Tvrtko Ursulin (2018-08-14 19:27:08)
> To not use it is to reimplement existing handy helpers - not ideal.

The problem was that they were overly handy so I tried to avoid them in
benchmarks/ after being burnt too often.
 
> To split the test bits from useful helpers sounds like quite a task.

Nah, it's a drop in the ocean compared to writing the benchmarking
framework / integrating into an existing one like ezbench.
 
> To wean gem_wsim off most igt_ stuff needs decision to be made on the 
> former - what is core api, and what is test related.
> 
> To me problems outweigh the benefit. :( If gem_wsim was under tools, 
> like intel_gpu_top, then yeah, it would be justifiable. Since it is in 
> benchmarks I don't think we should bother.

I dream one day we will get microbenchmarks as part of CI. Not only
would that require a radical overhaul of the benchmarks/ but a
substantial investment of hw & maintenance. In my dream, I also have a
vision of like-for-like comparisons against other drivers.
-Chris
diff mbox series

Patch

diff --git a/benchmarks/gem_wsim.c b/benchmarks/gem_wsim.c
index 80f180829241..ead91b0f009b 100644
--- a/benchmarks/gem_wsim.c
+++ b/benchmarks/gem_wsim.c
@@ -1718,6 +1718,21 @@  static bool sync_deps(struct workload *wrk, struct w_step *w)
 	return synced;
 }
 
+static unsigned int measured_usleep(unsigned int usec)
+{
+	struct timespec ts = { };
+	unsigned int slept;
+
+	slept = igt_nsec_elapsed(&ts);
+	igt_assert(slept == 0);
+	do {
+		usleep(usec - slept);
+		slept = igt_nsec_elapsed(&ts) / 1000;
+	} while (slept < usec);
+
+	return igt_nsec_elapsed(&ts);
+}
+
 static void *run_workload(void *data)
 {
 	struct workload *wrk = (struct workload *)data;
@@ -1739,7 +1754,7 @@  static void *run_workload(void *data)
 	     count++) {
 		unsigned int cur_seqno = wrk->sync_seqno;
 
-		clock_gettime(CLOCK_MONOTONIC, &wrk->repeat_start);
+		igt_gettime(&wrk->repeat_start);
 
 		for (i = 0, w = wrk->steps; wrk->run && (i < wrk->nr_steps);
 		     i++, w++) {
@@ -1751,13 +1766,14 @@  static void *run_workload(void *data)
 			} else if (w->type == PERIOD) {
 				struct timespec now;
 
-				clock_gettime(CLOCK_MONOTONIC, &now);
+				igt_gettime(&now);
 				do_sleep = w->period -
 					   elapsed_us(&wrk->repeat_start, &now);
 				if (do_sleep < 0) {
-					if (verbose > 1)
-						printf("%u: Dropped period @ %u/%u (%dus late)!\n",
-						       wrk->id, count, i, do_sleep);
+					if (verbose > 1 &&
+					    -do_sleep > 10 * w->period / 100)
+						printf("%u: Missed period @ %u/%u (%dus late)!\n",
+						       wrk->id, count, i, -do_sleep);
 					continue;
 				}
 			} else if (w->type == SYNC) {
@@ -1793,7 +1809,31 @@  static void *run_workload(void *data)
 			}
 
 			if (do_sleep || w->type == PERIOD) {
-				usleep(do_sleep);
+				long slept = measured_usleep(do_sleep) / 1000;
+
+				if ( w->type == PERIOD) {
+					struct timespec now;
+
+					igt_gettime(&now);
+
+					slept = elapsed_us(&wrk->repeat_start,
+							   &now);
+
+					if (verbose > 1 &&
+					    slept > (110 * w->period / 100))
+						printf("%u: Overslept period by %ldus @ %u/%u! (%uus)\n",
+						       wrk->id,
+						       -slept, count,
+						       i, w->period);
+				} else {
+					if (verbose > 1 &&
+					    slept > (110 * do_sleep / 100))
+						printf("%u: Overslept by %ldus @ %u/%u! (%uus)\n",
+						       wrk->id,
+						       slept - do_sleep, count,
+						       i, do_sleep);
+				}
+
 				continue;
 			}