Re: [PATCH v3 0/4] sched_clock: Optimize and avoid deadlock during read from NMI

[Daniel Thompson <daniel.thompson@linaro.org>]

On 05/02/15 00:50, Stephen Boyd wrote:
> On 01/30, Daniel Thompson wrote:
>> This patchset optimizes the generic sched_clock implementation to
>> significantly reduce the data cache profile. It also makes it safe to call
>> sched_clock() from NMI (or FIQ on ARM).
>>
>> The data cache profile of sched_clock() in both the original code and
>> my previous patch was somewhere between 2 and 3 (64-byte) cache lines,
>> depending on alignment of struct clock_data. After patching, the cache
>> profile for the normal case should be a single cacheline.
>>
>> NMI safety was tested on i.MX6 with perf drowning the system in FIQs and
>> using the perf handler to check that sched_clock() returned monotonic
>> values. At the same time I forcefully reduced kt_wrap so that
>> update_sched_clock() is being called at >1000Hz.
>>
>> Without the patches the above system is grossly unstable, surviving
>> [9K,115K,25K] perf event cycles during three separate runs. With the
>> patch I ran for over 9M perf event cycles before getting bored.
> 
> I wanted to see if there was any speedup from these changes so I
> made a tight loop around sched_clock() that ran for 10 seconds
> and I ran it 10 times before and after this patch series:
> 
>         unsigned long long clock, start_clock;
>         int count = 0; 
> 
>         clock = start_clock = sched_clock();
>         while ((clock - start_clock) < 10ULL * NSEC_PER_SEC) {
>                 clock = sched_clock();
>                 count++;
>         }
> 
>         pr_info("Made %d calls in %llu ns\n", count, clock - start_clock);
> 
> Before
> ------
>  Made 19218953 calls in 10000000439 ns
>  Made 19212790 calls in 10000000438 ns
>  Made 19217121 calls in 10000000142 ns
>  Made 19227304 calls in 10000000142 ns
>  Made 19217559 calls in 10000000142 ns
>  Made 19230193 calls in 10000000290 ns
>  Made 19212715 calls in 10000000290 ns
>  Made 19234446 calls in 10000000438 ns
>  Made 19226274 calls in 10000000439 ns
>  Made 19236118 calls in 10000000143 ns
>  
> After
> -----
>  Made 19434797 calls in 10000000438 ns
>  Made 19435733 calls in 10000000439 ns
>  Made 19434499 calls in 10000000438 ns
>  Made 19438482 calls in 10000000438 ns
>  Made 19435604 calls in 10000000142 ns
>  Made 19438551 calls in 10000000438 ns
>  Made 19444550 calls in 10000000290 ns
>  Made 19437580 calls in 10000000290 ns
>  Made 19439429 calls in 10000048142 ns
>  Made 19439493 calls in 10000000438 ns
> 
> So it seems to be a small improvement.
> 

Awesome!

I guess this is mostly the effect of simplifying the suspend logic since
the changes to the cache profile probably wouldn't reveal much in such a
tight loop.

I will re-run this after acting on your other review comments. BTW what
device did you run on?


Daniel.