Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

[Shuah Khan]

Hi Greg,

On 08/20/2017 03:56 AM, tip-bot for Greg Hackmann wrote:
> Commit-ID:  a524b1184b8e86141d689fa78ad150fbf2db9b4c
> Gitweb:     http://git.kernel.org/tip/a524b1184b8e86141d689fa78ad150fbf2db9b4c
> Author:     Greg Hackmann <ghackmann@google.com>
> AuthorDate: Tue, 25 Jul 2017 14:36:25 -0700
> Committer:  John Stultz <john.stultz@linaro.org>
> CommitDate: Thu, 17 Aug 2017 12:14:54 -0700
> 
> kselftests: timers: set-timer-lat: Tweak reporting when timer fires early
> 
> Rather than printing an error inside the alarm signal handler, set a
> flag that we check later.  This keeps the test from spamming the console
> every time the alarm fires early.  It also fixes the test exiting with
> error code 0 if this was the only test failure.
> 
> Cc: Thomas Gleixner <tglx@linutronix.de>
> Cc: Ingo Molnar <mingo@kernel.org>
> Cc: Miroslav Lichvar <mlichvar@redhat.com>
> Cc: Richard Cochran <richardcochran@gmail.com>
> Cc: Prarit Bhargava <prarit@redhat.com>
> Cc: Stephen Boyd <stephen.boyd@linaro.org>
> Cc: Shuah Khan <shuah@kernel.org>
> Cc: linux-kselftest@vger.kernel.org
> Signed-off-by: Greg Hackmann <ghackmann@google.com>
> Signed-off-by: John Stultz <john.stultz@linaro.org>

This commit is making the set-timer-lat hang. I reverted this commit
and there is no hang. Could you please take a look and see if this
commit should be reverted.

make kselftest as well as make -C tools/testing/selftests/timers run_tests
hang.

I had to revert the following as well, however a524b1184b8e86141d689fa78ad150fbf2db9b4c
is the suspect.

Commit-ID:  28be3f8f48cfb3cf024860f042d424cd4824f5f7
Gitweb:     http://git.kernel.org/tip/28be3f8f48cfb3cf024860f042d424cd4824f5f7
Author:     Greg Hackmann <ghackmann@google.com>
AuthorDate: Tue, 25 Jul 2017 14:36:26 -0700
Committer:  John Stultz <john.stultz@linaro.org>
CommitDate: Thu, 17 Aug 2017 12:14:58 -0700

kselftests: timers: set-timer-lat: Add one-shot timer test cases

Please let me know how you want to proceed. At the moment kselftest
run hangs due this test hang.

thanks,
-- Shuah

Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

[John Stultz]

On Tue, Sep 19, 2017 at 6:02 PM, Shuah Khan <shuah@kernel.org> wrote:
> Hi Greg,
>
> On 08/20/2017 03:56 AM, tip-bot for Greg Hackmann wrote:
>> Commit-ID:  a524b1184b8e86141d689fa78ad150fbf2db9b4c
>> Gitweb:     http://git.kernel.org/tip/a524b1184b8e86141d689fa78ad150fbf2db9b4c
>> Author:     Greg Hackmann <ghackmann@google.com>
>> AuthorDate: Tue, 25 Jul 2017 14:36:25 -0700
>> Committer:  John Stultz <john.stultz@linaro.org>
>> CommitDate: Thu, 17 Aug 2017 12:14:54 -0700
>>
>> kselftests: timers: set-timer-lat: Tweak reporting when timer fires early
>>
>> Rather than printing an error inside the alarm signal handler, set a
>> flag that we check later.  This keeps the test from spamming the console
>> every time the alarm fires early.  It also fixes the test exiting with
>> error code 0 if this was the only test failure.
>>
>> Cc: Thomas Gleixner <tglx@linutronix.de>
>> Cc: Ingo Molnar <mingo@kernel.org>
>> Cc: Miroslav Lichvar <mlichvar@redhat.com>
>> Cc: Richard Cochran <richardcochran@gmail.com>
>> Cc: Prarit Bhargava <prarit@redhat.com>
>> Cc: Stephen Boyd <stephen.boyd@linaro.org>
>> Cc: Shuah Khan <shuah@kernel.org>
>> Cc: linux-kselftest@vger.kernel.org
>> Signed-off-by: Greg Hackmann <ghackmann@google.com>
>> Signed-off-by: John Stultz <john.stultz@linaro.org>
>
> This commit is making the set-timer-lat hang. I reverted this commit
> and there is no hang. Could you please take a look and see if this
> commit should be reverted.
>
> make kselftest as well as make -C tools/testing/selftests/timers run_tests
> hang.
>
> I had to revert the following as well, however a524b1184b8e86141d689fa78ad150fbf2db9b4c
> is the suspect.
>
> Commit-ID:  28be3f8f48cfb3cf024860f042d424cd4824f5f7
> Gitweb:     http://git.kernel.org/tip/28be3f8f48cfb3cf024860f042d424cd4824f5f7
> Author:     Greg Hackmann <ghackmann@google.com>
> AuthorDate: Tue, 25 Jul 2017 14:36:26 -0700
> Committer:  John Stultz <john.stultz@linaro.org>
> CommitDate: Thu, 17 Aug 2017 12:14:58 -0700
>
> kselftests: timers: set-timer-lat: Add one-shot timer test cases
>
> Please let me know how you want to proceed. At the moment kselftest
> run hangs due this test hang.

Huh. I didn't see such a hang in my testing. Let me try to reproduce
and see if I can figure out whats going on.

thanks
-john

Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

[John Stultz]

On Tue, Sep 19, 2017 at 6:02 PM, Shuah Khan <shuah@kernel.org> wrote:
> Hi Greg,
>
> On 08/20/2017 03:56 AM, tip-bot for Greg Hackmann wrote:
>> Commit-ID:  a524b1184b8e86141d689fa78ad150fbf2db9b4c
>> Gitweb:     http://git.kernel.org/tip/a524b1184b8e86141d689fa78ad150fbf2db9b4c
>> Author:     Greg Hackmann <ghackmann@google.com>
>> AuthorDate: Tue, 25 Jul 2017 14:36:25 -0700
>> Committer:  John Stultz <john.stultz@linaro.org>
>> CommitDate: Thu, 17 Aug 2017 12:14:54 -0700
>>
>> kselftests: timers: set-timer-lat: Tweak reporting when timer fires early
>>
>> Rather than printing an error inside the alarm signal handler, set a
>> flag that we check later.  This keeps the test from spamming the console
>> every time the alarm fires early.  It also fixes the test exiting with
>> error code 0 if this was the only test failure.
>>
>> Cc: Thomas Gleixner <tglx@linutronix.de>
>> Cc: Ingo Molnar <mingo@kernel.org>
>> Cc: Miroslav Lichvar <mlichvar@redhat.com>
>> Cc: Richard Cochran <richardcochran@gmail.com>
>> Cc: Prarit Bhargava <prarit@redhat.com>
>> Cc: Stephen Boyd <stephen.boyd@linaro.org>
>> Cc: Shuah Khan <shuah@kernel.org>
>> Cc: linux-kselftest@vger.kernel.org
>> Signed-off-by: Greg Hackmann <ghackmann@google.com>
>> Signed-off-by: John Stultz <john.stultz@linaro.org>
>
> This commit is making the set-timer-lat hang. I reverted this commit
> and there is no hang. Could you please take a look and see if this
> commit should be reverted.
>
> make kselftest as well as make -C tools/testing/selftests/timers run_tests
> hang.

Do you have any specific details as to how the test hangs? (ie: Log
data, as in where it might be when it hangs? Any details about the
machine?)

I'm not seeing it so far in my testing.

thanks
-john

Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

[Prarit Bhargava]

On 09/19/2017 11:36 PM, John Stultz wrote:
> On Tue, Sep 19, 2017 at 6:02 PM, Shuah Khan <shuah@kernel.org> wrote:
>> Hi Greg,
>>
>> On 08/20/2017 03:56 AM, tip-bot for Greg Hackmann wrote:
>>> Commit-ID:  a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>> Gitweb:     http://git.kernel.org/tip/a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>> Author:     Greg Hackmann <ghackmann@google.com>
>>> AuthorDate: Tue, 25 Jul 2017 14:36:25 -0700
>>> Committer:  John Stultz <john.stultz@linaro.org>
>>> CommitDate: Thu, 17 Aug 2017 12:14:54 -0700
>>>
>>> kselftests: timers: set-timer-lat: Tweak reporting when timer fires early
>>>
>>> Rather than printing an error inside the alarm signal handler, set a
>>> flag that we check later.  This keeps the test from spamming the console
>>> every time the alarm fires early.  It also fixes the test exiting with
>>> error code 0 if this was the only test failure.
>>>
>>> Cc: Thomas Gleixner <tglx@linutronix.de>
>>> Cc: Ingo Molnar <mingo@kernel.org>
>>> Cc: Miroslav Lichvar <mlichvar@redhat.com>
>>> Cc: Richard Cochran <richardcochran@gmail.com>
>>> Cc: Prarit Bhargava <prarit@redhat.com>
>>> Cc: Stephen Boyd <stephen.boyd@linaro.org>
>>> Cc: Shuah Khan <shuah@kernel.org>
>>> Cc: linux-kselftest@vger.kernel.org
>>> Signed-off-by: Greg Hackmann <ghackmann@google.com>
>>> Signed-off-by: John Stultz <john.stultz@linaro.org>
>>
>> This commit is making the set-timer-lat hang. I reverted this commit
>> and there is no hang. Could you please take a look and see if this
>> commit should be reverted.
>>
>> make kselftest as well as make -C tools/testing/selftests/timers run_tests
>> hang.
> 
> Do you have any specific details as to how the test hangs? (ie: Log
> data, as in where it might be when it hangs? Any details about the
> machine?)
> 
> I'm not seeing it so far in my testing.
> 

I just ran it here and don't see any issues.  I'll try on a few other boxes
to make sure.

# make -C tools/testing/selftests/timers run_tests
make: Entering directory `/home/linux/tools/testing/selftests/timers'
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  posix_timers.c  -o
/home/linux/tools/testing/selftests/timers/posix_timers
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  nanosleep.c  -o
/home/linux/tools/testing/selftests/timers/nanosleep
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  nsleep-lat.c  -o
/home/linux/tools/testing/selftests/timers/nsleep-lat
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  set-timer-lat.c  -o
/home/linux/tools/testing/selftests/timers/set-timer-lat
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  mqueue-lat.c  -o
/home/linux/tools/testing/selftests/timers/mqueue-lat
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  inconsistency-check.c  -o
/home/linux/tools/testing/selftests/timers/inconsistency-check
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  raw_skew.c  -o
/home/linux/tools/testing/selftests/timers/raw_skew
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  threadtest.c  -o
/home/linux/tools/testing/selftests/timers/threadtest
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  rtctest.c  -o
/home/linux/tools/testing/selftests/timers/rtctest
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  alarmtimer-suspend.c   -o
alarmtimer-suspend
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  valid-adjtimex.c   -o
valid-adjtimex
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  adjtick.c   -o adjtick
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  change_skew.c   -o change_skew
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  skew_consistency.c   -o
skew_consistency
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  clocksource-switch.c   -o
clocksource-switch
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  freq-step.c   -o freq-step
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  leap-a-day.c   -o leap-a-day
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  leapcrash.c   -o leapcrash
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  set-tai.c   -o set-tai
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  set-2038.c   -o set-2038
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  set-tz.c   -o set-tz
gcc -O3 -Wl,-no-as-needed -Wall  -lrt -lpthread -lm  rtctest_setdate.c   -o
rtctest_setdate
TAP version 13
selftests: posix_timers
========================================
Testing posix timers. False negative may happen on CPU execution
based timers if other threads run on the CPU...
Check itimer virtual... [OK]
Check itimer prof... [OK]
Check itimer real... [OK]
Check timer_create() per thread... [OK]
Check timer_create() per process... [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..1 selftests: posix_timers [PASS]
selftests: nanosleep
========================================
Nanosleep CLOCK_REALTIME                  [OK]
Nanosleep CLOCK_MONOTONIC                 [OK]
Nanosleep CLOCK_MONOTONIC_RAW             [UNSUPPORTED]
Nanosleep CLOCK_REALTIME_COARSE           [UNSUPPORTED]
Nanosleep CLOCK_MONOTONIC_COARSE          [UNSUPPORTED]
Nanosleep CLOCK_BOOTTIME                  [OK]
Nanosleep CLOCK_REALTIME_ALARM            [OK]
Nanosleep CLOCK_BOOTTIME_ALARM            [OK]
Nanosleep CLOCK_TAI                       [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..2 selftests: nanosleep [PASS]
selftests: nsleep-lat
========================================
  nsleep latency CLOCK_REALTIME             [OK]
nsleep latency CLOCK_MONOTONIC            [OK]
nsleep latency CLOCK_MONOTONIC_RAW        [UNSUPPORTED]
nsleep latency CLOCK_REALTIME_COARSE      [UNSUPPORTED]
nsleep latency CLOCK_MONOTONIC_COARSE     [UNSUPPORTED]
nsleep latency CLOCK_BOOTTIME             [OK]
nsleep latency CLOCK_REALTIME_ALARM       [OK]
nsleep latency CLOCK_BOOTTIME_ALARM       [OK]
nsleep latency CLOCK_TAI                  [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..3 selftests: nsleep-lat [PASS]
selftests: set-timer-lat
========================================
Setting timers for every 1 seconds
CLOCK_REALTIME         ABSTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_REALTIME         ABSTIME PERIODIC max latency:     100795 ns : [OK]
CLOCK_REALTIME         RELTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_REALTIME         RELTIME PERIODIC max latency:     103484 ns : [OK]
CLOCK_REALTIME         ABSTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_REALTIME         ABSTIME ONE-SHOT max latency:      78764 ns : [OK]
CLOCK_REALTIME         ABSTIME ONE-SHOT count:                   1 : [OK]
CLOCK_REALTIME         RELTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_REALTIME         RELTIME ONE-SHOT max latency:     107690 ns : [OK]
CLOCK_REALTIME         RELTIME ONE-SHOT count:                   1 : [OK]
CLOCK_MONOTONIC        ABSTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_MONOTONIC        ABSTIME PERIODIC max latency:      97220 ns : [OK]
CLOCK_MONOTONIC        RELTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_MONOTONIC        RELTIME PERIODIC max latency:      99225 ns : [OK]
CLOCK_MONOTONIC        ABSTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_MONOTONIC        ABSTIME ONE-SHOT max latency:      74499 ns : [OK]
CLOCK_MONOTONIC        ABSTIME ONE-SHOT count:                   1 : [OK]
CLOCK_MONOTONIC        RELTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_MONOTONIC        RELTIME ONE-SHOT max latency:      98656 ns : [OK]
CLOCK_MONOTONIC        RELTIME ONE-SHOT count:                   1 : [OK]
CLOCK_BOOTTIME         ABSTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_BOOTTIME         ABSTIME PERIODIC max latency:     107843 ns : [OK]
CLOCK_BOOTTIME         RELTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_BOOTTIME         RELTIME PERIODIC max latency:     110695 ns : [OK]
CLOCK_BOOTTIME         ABSTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_BOOTTIME         ABSTIME ONE-SHOT max latency:      73135 ns : [OK]
CLOCK_BOOTTIME         ABSTIME ONE-SHOT count:                   1 : [OK]
CLOCK_BOOTTIME         RELTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_BOOTTIME         RELTIME ONE-SHOT max latency:      94899 ns : [OK]
CLOCK_BOOTTIME         RELTIME ONE-SHOT count:                   1 : [OK]
CLOCK_REALTIME_ALARM   ABSTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_REALTIME_ALARM   ABSTIME PERIODIC max latency:      96219 ns : [OK]
CLOCK_REALTIME_ALARM   RELTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_REALTIME_ALARM   RELTIME PERIODIC max latency:     104495 ns : [OK]
CLOCK_REALTIME_ALARM   ABSTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_REALTIME_ALARM   ABSTIME ONE-SHOT max latency:      76691 ns : [OK]
CLOCK_REALTIME_ALARM   ABSTIME ONE-SHOT count:                   1 : [OK]
CLOCK_REALTIME_ALARM   RELTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_REALTIME_ALARM   RELTIME ONE-SHOT max latency:     101372 ns : [OK]
CLOCK_REALTIME_ALARM   RELTIME ONE-SHOT count:                   1 : [OK]
CLOCK_BOOTTIME_ALARM   ABSTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_BOOTTIME_ALARM   ABSTIME PERIODIC max latency:      98144 ns : [OK]
CLOCK_BOOTTIME_ALARM   RELTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_BOOTTIME_ALARM   RELTIME PERIODIC max latency:     104286 ns : [OK]
CLOCK_BOOTTIME_ALARM   ABSTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_BOOTTIME_ALARM   ABSTIME ONE-SHOT max latency:      72154 ns : [OK]
CLOCK_BOOTTIME_ALARM   ABSTIME ONE-SHOT count:                   1 : [OK]
CLOCK_BOOTTIME_ALARM   RELTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_BOOTTIME_ALARM   RELTIME ONE-SHOT max latency:      81766 ns : [OK]
CLOCK_BOOTTIME_ALARM   RELTIME ONE-SHOT count:                   1 : [OK]
CLOCK_TAI              ABSTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_TAI              ABSTIME PERIODIC max latency:     100615 ns : [OK]
CLOCK_TAI              RELTIME PERIODIC timer fired early:       0 : [OK]
CLOCK_TAI              RELTIME PERIODIC max latency:     101477 ns : [OK]
CLOCK_TAI              ABSTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_TAI              ABSTIME ONE-SHOT max latency:      73973 ns : [OK]
CLOCK_TAI              ABSTIME ONE-SHOT count:                   1 : [OK]
CLOCK_TAI              RELTIME ONE-SHOT timer fired early:       0 : [OK]
CLOCK_TAI              RELTIME ONE-SHOT max latency:      98194 ns : [OK]
CLOCK_TAI              RELTIME ONE-SHOT count:                   1 : [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..4 selftests: set-timer-lat [PASS]
selftests: mqueue-lat
========================================
Mqueue latency :                          [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..5 selftests: mqueue-lat [PASS]
selftests: inconsistency-check
========================================
Consistent CLOCK_REALTIME                 [OK]
Consistent CLOCK_MONOTONIC                [OK]
Consistent CLOCK_PROCESS_CPUTIME_ID       [OK]
Consistent CLOCK_THREAD_CPUTIME_ID        [OK]
Consistent CLOCK_MONOTONIC_RAW            [OK]
Consistent CLOCK_REALTIME_COARSE          [OK]
Consistent CLOCK_MONOTONIC_COARSE         [OK]
Consistent CLOCK_BOOTTIME                 [OK]
Consistent CLOCK_REALTIME_ALARM           [OK]
Consistent CLOCK_BOOTTIME_ALARM           [OK]
Consistent CLOCK_TAI                      [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..6 selftests: inconsistency-check [PASS]
selftests: raw_skew
========================================
Estimating clock drift: 41.659(est) 40.697(act) [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..7 selftests: raw_skew [PASS]
selftests: threadtest
========================================
Wed, 20 Sep 2017 08:17:18 -0400
Testing consistency with 8 threads for 30 seconds: [OK]
Pass 0 Fail 0 Xfail 0 Xpass 0 Skip 0 Error 0
1..0
ok 1..8 selftests: threadtest [PASS]
selftests: rtctest
========================================

                        RTC Driver Test Example.

Counting 5 update (1/sec) interrupts from reading /dev/rtc0: 1 2 3 4 5
Again, from using select(2) on /dev/rtc: 1 2 3 4 5

Current RTC date/time is 20-9-2017, 08:17:58.
Alarm time now set to 08:18:03.
Waiting 5 seconds for alarm... okay. Alarm rang.

Periodic IRQ rate is 1024Hz.
Counting 20 interrupts at:
2Hz:     1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20
4Hz:     1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20
8Hz:     1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20
16Hz:    1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20
32Hz:    1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20
64Hz:    1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20

                         *** Test complete ***
ok 1..9 selftests: rtctest [PASS]
make: Leaving directory `/home/linux/tools/testing/selftests/timers'

P.

Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

[Shuah Khan]

On 09/20/2017 06:31 AM, Prarit Bhargava wrote:
> On 09/19/2017 11:36 PM, John Stultz wrote:
>> On Tue, Sep 19, 2017 at 6:02 PM, Shuah Khan <shuah@kernel.org> wrote:
>>> Hi Greg,
>>>
>>> On 08/20/2017 03:56 AM, tip-bot for Greg Hackmann wrote:
>>>> Commit-ID:  a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>>> Gitweb:     http://git.kernel.org/tip/a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>>> Author:     Greg Hackmann <ghackmann@google.com>
>>>> AuthorDate: Tue, 25 Jul 2017 14:36:25 -0700
>>>> Committer:  John Stultz <john.stultz@linaro.org>
>>>> CommitDate: Thu, 17 Aug 2017 12:14:54 -0700
>>>>
>>>> kselftests: timers: set-timer-lat: Tweak reporting when timer fires early
>>>>
>>>> Rather than printing an error inside the alarm signal handler, set a
>>>> flag that we check later.  This keeps the test from spamming the console
>>>> every time the alarm fires early.  It also fixes the test exiting with
>>>> error code 0 if this was the only test failure.
>>>>
>>>> Cc: Thomas Gleixner <tglx@linutronix.de>
>>>> Cc: Ingo Molnar <mingo@kernel.org>
>>>> Cc: Miroslav Lichvar <mlichvar@redhat.com>
>>>> Cc: Richard Cochran <richardcochran@gmail.com>
>>>> Cc: Prarit Bhargava <prarit@redhat.com>
>>>> Cc: Stephen Boyd <stephen.boyd@linaro.org>
>>>> Cc: Shuah Khan <shuah@kernel.org>
>>>> Cc: linux-kselftest@vger.kernel.org
>>>> Signed-off-by: Greg Hackmann <ghackmann@google.com>
>>>> Signed-off-by: John Stultz <john.stultz@linaro.org>
>>>
>>> This commit is making the set-timer-lat hang. I reverted this commit
>>> and there is no hang. Could you please take a look and see if this
>>> commit should be reverted.
>>>
>>> make kselftest as well as make -C tools/testing/selftests/timers run_tests
>>> hang.
>>
>> Do you have any specific details as to how the test hangs? (ie: Log
>> data, as in where it might be when it hangs? Any details about the
>> machine?)
>>
>> I'm not seeing it so far in my testing.
>>
> 
> I just ran it here and don't see any issues.  I'll try on a few other boxes
> to make sure.
> 
> # make -C tools/testing/selftests/timers run_tests

John/Prarit,

Thanks for getting back to me. I isolated the problem to redirecting
test output. If I redirect the output it hangs.

./set-timer-lat > /tmp/set-timer-lat 2>&1

it hangs. The reason I am seeing this is because there is a patch
that came in recently to redirect individual test output to a separate
file to make it easier to understand the test results.

Looks like Commits 28be3f8f48cfb3cf024860f042d424cd4824f5f7 and/or
a524b1184b8e86141d689fa78ad150fbf2db9b4c add dependency on stdin/out/err
to the test.

Anyway just an update. It can be reproduced easily. If we have tests
that can't tolerate redirecting output, I might end up dropping the
patch that is in linux-kselftest fixes

fbcab13d2e2511a858590846ac2e2d7cbd830591

So fat set-timer-lat is the only one I found.

thanks,
-- Shuah

Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

[Greg Hackmann]

On 09/20/2017 04:38 PM, Shuah Khan wrote:
> On 09/20/2017 06:31 AM, Prarit Bhargava wrote:
>> On 09/19/2017 11:36 PM, John Stultz wrote:
>>> On Tue, Sep 19, 2017 at 6:02 PM, Shuah Khan <shuah@kernel.org> wrote:
>>>> Hi Greg,
>>>>
>>>> On 08/20/2017 03:56 AM, tip-bot for Greg Hackmann wrote:
>>>>> Commit-ID:  a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>>>> Gitweb:     http://git.kernel.org/tip/a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>>>> Author:     Greg Hackmann <ghackmann@google.com>
>>>>> AuthorDate: Tue, 25 Jul 2017 14:36:25 -0700
>>>>> Committer:  John Stultz <john.stultz@linaro.org>
>>>>> CommitDate: Thu, 17 Aug 2017 12:14:54 -0700
>>>>>
>>>>> kselftests: timers: set-timer-lat: Tweak reporting when timer fires early
>>>>>
>>>>> Rather than printing an error inside the alarm signal handler, set a
>>>>> flag that we check later.  This keeps the test from spamming the console
>>>>> every time the alarm fires early.  It also fixes the test exiting with
>>>>> error code 0 if this was the only test failure.
>>>>>
>>>>> Cc: Thomas Gleixner <tglx@linutronix.de>
>>>>> Cc: Ingo Molnar <mingo@kernel.org>
>>>>> Cc: Miroslav Lichvar <mlichvar@redhat.com>
>>>>> Cc: Richard Cochran <richardcochran@gmail.com>
>>>>> Cc: Prarit Bhargava <prarit@redhat.com>
>>>>> Cc: Stephen Boyd <stephen.boyd@linaro.org>
>>>>> Cc: Shuah Khan <shuah@kernel.org>
>>>>> Cc: linux-kselftest@vger.kernel.org
>>>>> Signed-off-by: Greg Hackmann <ghackmann@google.com>
>>>>> Signed-off-by: John Stultz <john.stultz@linaro.org>
>>>>
>>>> This commit is making the set-timer-lat hang. I reverted this commit
>>>> and there is no hang. Could you please take a look and see if this
>>>> commit should be reverted.
>>>>
>>>> make kselftest as well as make -C tools/testing/selftests/timers run_tests
>>>> hang.
>>>
>>> Do you have any specific details as to how the test hangs? (ie: Log
>>> data, as in where it might be when it hangs? Any details about the
>>> machine?)
>>>
>>> I'm not seeing it so far in my testing.
>>>
>>
>> I just ran it here and don't see any issues.  I'll try on a few other boxes
>> to make sure.
>>
>> # make -C tools/testing/selftests/timers run_tests
> 
> John/Prarit,
> 
> Thanks for getting back to me. I isolated the problem to redirecting
> test output. If I redirect the output it hangs.
> 
> ./set-timer-lat > /tmp/set-timer-lat 2>&1
> 
> it hangs. The reason I am seeing this is because there is a patch
> that came in recently to redirect individual test output to a separate
> file to make it easier to understand the test results.
> 
> Looks like Commits 28be3f8f48cfb3cf024860f042d424cd4824f5f7 and/or
> a524b1184b8e86141d689fa78ad150fbf2db9b4c add dependency on stdin/out/err
> to the test.
> 
> Anyway just an update. It can be reproduced easily. If we have tests
> that can't tolerate redirecting output, I might end up dropping the
> patch that is in linux-kselftest fixes
> 
> fbcab13d2e2511a858590846ac2e2d7cbd830591
> 
> So fat set-timer-lat is the only one I found.
> 
> thanks,
> -- Shuah
> 
I'm able to reproduce this locally, though I'm not sure it's a 
redirection issue.  28be3f8f48cf ("kselftests: timers: set-timer-lat: 
Add one-shot timer test cases") appears to have a regression where if 
timer_create() fails due to missing CAP_WAKE_ALARM, do_timer() will 
still try to run the test anyway.

Please revert 28be3f8f48cf and verify whether this fixes the problem for 
you.  If so, I'll send a V2 as soon as possible that fixes the issue. 
(Basically, setup_timer() needs a discrete return value for unsupported 
test cases.)

Sorry for the confusion.

Re: [tip:timers/core] kselftests: timers: set-timer-lat: Tweak reporting when timer fires early

[Shuah Khan]

On 09/21/2017 01:40 PM, Greg Hackmann wrote:
> On 09/20/2017 04:38 PM, Shuah Khan wrote:
>> On 09/20/2017 06:31 AM, Prarit Bhargava wrote:
>>> On 09/19/2017 11:36 PM, John Stultz wrote:
>>>> On Tue, Sep 19, 2017 at 6:02 PM, Shuah Khan <shuah@kernel.org> wrote:
>>>>> Hi Greg,
>>>>>
>>>>> On 08/20/2017 03:56 AM, tip-bot for Greg Hackmann wrote:
>>>>>> Commit-ID:  a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>>>>> Gitweb:     http://git.kernel.org/tip/a524b1184b8e86141d689fa78ad150fbf2db9b4c
>>>>>> Author:     Greg Hackmann <ghackmann@google.com>
>>>>>> AuthorDate: Tue, 25 Jul 2017 14:36:25 -0700
>>>>>> Committer:  John Stultz <john.stultz@linaro.org>
>>>>>> CommitDate: Thu, 17 Aug 2017 12:14:54 -0700
>>>>>>
>>>>>> kselftests: timers: set-timer-lat: Tweak reporting when timer fires early
>>>>>>
>>>>>> Rather than printing an error inside the alarm signal handler, set a
>>>>>> flag that we check later.  This keeps the test from spamming the console
>>>>>> every time the alarm fires early.  It also fixes the test exiting with
>>>>>> error code 0 if this was the only test failure.
>>>>>>
>>>>>> Cc: Thomas Gleixner <tglx@linutronix.de>
>>>>>> Cc: Ingo Molnar <mingo@kernel.org>
>>>>>> Cc: Miroslav Lichvar <mlichvar@redhat.com>
>>>>>> Cc: Richard Cochran <richardcochran@gmail.com>
>>>>>> Cc: Prarit Bhargava <prarit@redhat.com>
>>>>>> Cc: Stephen Boyd <stephen.boyd@linaro.org>
>>>>>> Cc: Shuah Khan <shuah@kernel.org>
>>>>>> Cc: linux-kselftest@vger.kernel.org
>>>>>> Signed-off-by: Greg Hackmann <ghackmann@google.com>
>>>>>> Signed-off-by: John Stultz <john.stultz@linaro.org>
>>>>>
>>>>> This commit is making the set-timer-lat hang. I reverted this commit
>>>>> and there is no hang. Could you please take a look and see if this
>>>>> commit should be reverted.
>>>>>
>>>>> make kselftest as well as make -C tools/testing/selftests/timers run_tests
>>>>> hang.
>>>>
>>>> Do you have any specific details as to how the test hangs? (ie: Log
>>>> data, as in where it might be when it hangs? Any details about the
>>>> machine?)
>>>>
>>>> I'm not seeing it so far in my testing.
>>>>
>>>
>>> I just ran it here and don't see any issues.  I'll try on a few other boxes
>>> to make sure.
>>>
>>> # make -C tools/testing/selftests/timers run_tests
>>
>> John/Prarit,
>>
>> Thanks for getting back to me. I isolated the problem to redirecting
>> test output. If I redirect the output it hangs.
>>
>> ./set-timer-lat > /tmp/set-timer-lat 2>&1
>>
>> it hangs. The reason I am seeing this is because there is a patch
>> that came in recently to redirect individual test output to a separate
>> file to make it easier to understand the test results.
>>
>> Looks like Commits 28be3f8f48cfb3cf024860f042d424cd4824f5f7 and/or
>> a524b1184b8e86141d689fa78ad150fbf2db9b4c add dependency on stdin/out/err
>> to the test.
>>
>> Anyway just an update. It can be reproduced easily. If we have tests
>> that can't tolerate redirecting output, I might end up dropping the
>> patch that is in linux-kselftest fixes
>>
>> fbcab13d2e2511a858590846ac2e2d7cbd830591
>>
>> So fat set-timer-lat is the only one I found.
>>
>> thanks,
>> -- Shuah
>>
> I'm able to reproduce this locally, though I'm not sure it's a redirection issue.  28be3f8f48cf ("kselftests: timers: set-timer-lat: Add one-shot timer test cases") appears to have a regression where if timer_create() fails due to missing CAP_WAKE_ALARM, do_timer() will still try to run the test anyway.

Yeah I found two problems - patches on their way. The first one returning 0 for unsupported
alarm cases and a second in select. Just about to send patches. Will cc on those.

thanks,
-- Shuah