Re: [RFC][PATCH 0/4] Fixes for leapsecond expiring early ABS_TIME CLOCK_REALTIME timers

[Daniel Bristot de Oliveira]

Il 29/05/2015 17:24, John Stultz ha scritto:
> Thus this patch series tries to address this isssue, including
> extending the leap-a-day test to catch this problem, as well
> as other relevant fixups I found while working on the code.
> 
> This series has only had limited testing, so I wanted to send
> it out for initial review and comment. Folks can grab this tree
> via git for testing here:
> https://git.linaro.org/people/john.stultz/linux.git dev/early-leap-timer

John,

I saw two failures while testing the patched kernel
using the patched leap-a-day.

On both cases the leap second was not inserted, and
then the timer fired at the second edge (as expected?).

Here is the output of both leap-a-day and dmesg for
both errors:

===== Error 1 =====
[root@vostro timers]# ./leap-a-day -s
[...many lines...]
Setting time to Wed Sep  9 20:59:50 2015
Scheduling leap second for Wed Sep  9 21:00:00 2015
Setting timer for Wed Sep  9 21:00:00 2015
Wed Sep  9 20:59:57 2015 +    147 us (0)	TIME_INS
Wed Sep  9 20:59:57 2015 + 500352 us (0)	TIME_INS
Wed Sep  9 20:59:58 2015 +    558 us (0)	TIME_INS
Wed Sep  9 20:59:58 2015 + 500767 us (0)	TIME_INS
Wed Sep  9 20:59:59 2015 +    975 us (0)	TIME_INS
Wed Sep  9 20:59:59 2015 + 501181 us (0)	TIME_INS
Wed Sep  9 20:59:59 2015 +   1442 us (1)	TIME_OOP
Wed Sep  9 20:59:59 2015 + 501670 us (1)	TIME_OOP
Wed Sep  9 21:00:00 2015 +    110 us (1)	TIME_WAIT - TIMER FIRED
Wed Sep  9 21:00:00 2015 +    179 us (1)	TIME_WAIT
Wed Sep  9 21:00:00 2015 + 500340 us (1)	TIME_WAIT
Wed Sep  9 21:00:01 2015 +    548 us (1)	TIME_WAIT
Wed Sep  9 21:00:01 2015 + 500768 us (1)	TIME_WAIT
Wed Sep  9 21:00:02 2015 +    976 us (1)	TIME_WAIT
Leap complete

Setting time to Thu Sep 10 20:59:50 2015
Scheduling leap second for Thu Sep 10 21:00:00 2015
Setting timer for Thu Sep 10 21:00:00 2015
Thu Sep 10 20:59:57 2015 +    209 us (1)	TIME_DEL
Thu Sep 10 20:59:57 2015 + 500410 us (1)	TIME_DEL
Thu Sep 10 20:59:58 2015 +    646 us (1)	TIME_DEL
Thu Sep 10 20:59:58 2015 + 500881 us (1)	TIME_DEL
Thu Sep 10 21:00:00 2015 +   1182 us (0)	TIME_WAIT - TIMER FIRED
Thu Sep 10 21:00:00 2015 +   1283 us (0)	TIME_WAIT
Thu Sep 10 21:00:00 2015 + 501475 us (0)	TIME_WAIT
Thu Sep 10 21:00:01 2015 +   1654 us (0)	TIME_WAIT
Thu Sep 10 21:00:01 2015 + 501856 us (0)	TIME_WAIT
Thu Sep 10 21:00:02 2015 +   2032 us (0)	TIME_WAIT
Leap complete

Setting time to Fri Sep 11 20:59:50 2015
Scheduling leap second for Fri Sep 11 21:00:00 2015
Setting timer for Fri Sep 11 21:00:00 2015
Fri Sep 11 20:59:57 2015 +    139 us (0)	TIME_INS
Fri Sep 11 20:59:57 2015 + 500347 us (0)	TIME_INS
Fri Sep 11 20:59:58 2015 +    527 us (0)	TIME_INS
Fri Sep 11 20:59:58 2015 + 500751 us (0)	TIME_INS
Fri Sep 11 20:59:59 2015 +    987 us (0)	TIME_INS
Fri Sep 11 20:59:59 2015 + 501203 us (0)	TIME_INS
Fri Sep 11 21:00:00 2015 +    100 us (0)	TIME_INS - TIMER FIRED
Error: Incorrect NTP state?
Fri Sep 11 21:00:00 2015 +    173 us (0)	TIME_INS
Fri Sep 11 21:00:00 2015 + 500353 us (0)	TIME_OK
Fri Sep 11 21:00:01 2015 +    583 us (0)	TIME_OK
Fri Sep 11 21:00:01 2015 + 500799 us (0)	TIME_OK
Fri Sep 11 21:00:02 2015 +   1021 us (0)	TIME_OK
Leap complete
Errors observed

[root@vostro timers]# dmesg  | tail
[ 1451.279313] Clock: deleting leap second 23:59:59 UTC
[ 1464.296724] Clock: inserting leap second 23:59:60 UTC
[ 1477.312373] Clock: deleting leap second 23:59:59 UTC
[ 1490.329740] Clock: inserting leap second 23:59:60 UTC
[ 1503.345402] Clock: deleting leap second 23:59:59 UTC
[ 1516.362841] Clock: inserting leap second 23:59:60 UTC
[ 1529.378466] Clock: deleting leap second 23:59:59 UTC
[ 1542.395826] Clock: inserting leap second 23:59:60 UTC
[ 1555.411551] Clock: deleting leap second 23:59:59 UTC
[ 1697.998312] Adjusting tsc more than 11% (5677670 vs 7466007) <-- ???
---> did not insert the leap second <---
## did not insert the leap second

===== Error 2 =====
[root@vostro timers]# ./leap-a-day -s
[...many lines...]
Setting time to Wed Aug 19 20:59:50 2015
Scheduling leap second for Wed Aug 19 21:00:00 2015
Setting timer for Wed Aug 19 21:00:00 2015
Something cleared STA_INS/STA_DEL, setting it again.
Wed Aug 19 20:59:57 2015 +    181 us (0)	TIME_OK
Wed Aug 19 20:59:57 2015 + 500357 us (0)	TIME_INS
Wed Aug 19 20:59:58 2015 +    559 us (0)	TIME_INS
Wed Aug 19 20:59:58 2015 + 500761 us (0)	TIME_INS
Wed Aug 19 20:59:59 2015 +    967 us (0)	TIME_INS
Wed Aug 19 20:59:59 2015 + 501177 us (0)	TIME_INS
Wed Aug 19 20:59:59 2015 +   1318 us (1)	TIME_OOP
Wed Aug 19 20:59:59 2015 + 501508 us (1)	TIME_OOP
Wed Aug 19 21:00:00 2015 +     99 us (1)	TIME_WAIT - TIMER FIRED
Wed Aug 19 21:00:00 2015 +    161 us (1)	TIME_WAIT
Wed Aug 19 21:00:00 2015 + 500320 us (1)	TIME_WAIT
Wed Aug 19 21:00:01 2015 +    523 us (1)	TIME_WAIT
Wed Aug 19 21:00:01 2015 + 500735 us (1)	TIME_WAIT
Wed Aug 19 21:00:02 2015 +    937 us (1)	TIME_WAIT
Leap complete

Setting time to Thu Aug 20 20:59:50 2015
Scheduling leap second for Thu Aug 20 21:00:00 2015
Setting timer for Thu Aug 20 21:00:00 2015
Thu Aug 20 20:59:57 2015 +    144 us (1)	TIME_DEL
Thu Aug 20 20:59:57 2015 + 500351 us (1)	TIME_DEL
Thu Aug 20 20:59:58 2015 +    552 us (1)	TIME_DEL
Thu Aug 20 20:59:58 2015 + 500752 us (1)	TIME_DEL
Thu Aug 20 21:00:00 2015 +   1021 us (0)	TIME_WAIT - TIMER FIRED
Thu Aug 20 21:00:00 2015 +   1096 us (0)	TIME_WAIT
Thu Aug 20 21:00:00 2015 + 501267 us (0)	TIME_WAIT
Thu Aug 20 21:00:01 2015 +   1470 us (0)	TIME_WAIT
Thu Aug 20 21:00:01 2015 + 501677 us (0)	TIME_WAIT
Thu Aug 20 21:00:02 2015 +   1886 us (0)	TIME_WAIT
Leap complete

Setting time to Fri Aug 21 20:59:50 2015
Scheduling leap second for Fri Aug 21 21:00:00 2015
Setting timer for Fri Aug 21 21:00:00 2015
Fri Aug 21 20:59:57 2015 +    153 us (0)	TIME_INS
Fri Aug 21 20:59:57 2015 + 500354 us (0)	TIME_INS
Fri Aug 21 20:59:58 2015 +    562 us (0)	TIME_INS
Fri Aug 21 20:59:58 2015 + 500815 us (0)	TIME_INS
Fri Aug 21 20:59:59 2015 +   1000 us (0)	TIME_INS
Fri Aug 21 20:59:59 2015 + 501207 us (0)	TIME_INS
Fri Aug 21 21:00:00 2015 +    109 us (0)	TIME_INS - TIMER FIRED
Error: Incorrect NTP state?
Fri Aug 21 21:00:00 2015 +    173 us (0)	TIME_INS
Fri Aug 21 21:00:00 2015 + 500331 us (0)	TIME_OK
Fri Aug 21 21:00:01 2015 +    540 us (0)	TIME_OK
Fri Aug 21 21:00:01 2015 + 500791 us (0)	TIME_OK
Fri Aug 21 21:00:02 2015 +   1046 us (0)	TIME_OK
Leap complete
Errors observed

[root@vostro timers]# dmesg  | tail
[ 1283.857902] Clock: inserting leap second 23:59:60 UTC
[ 1296.873600] Clock: deleting leap second 23:59:59 UTC
[ 1309.891049] Clock: inserting leap second 23:59:60 UTC
[ 1322.906709] Clock: deleting leap second 23:59:59 UTC
[ 1335.924154] Clock: inserting leap second 23:59:60 UTC
[ 1348.939824] Clock: deleting leap second 23:59:59 UTC
[ 1361.957267] Clock: inserting leap second 23:59:60 UTC
[ 1374.972919] Clock: deleting leap second 23:59:59 UTC
[ 1387.989238] Clock: inserting leap second 23:59:60 UTC
[ 1401.005877] Clock: deleting leap second 23:59:59 UTC
---> did not insert the leap second <---

Both cases occurred in the same physical machine.
AFAICS, it does not occur in the unpatched
kernel/leap-a-day in the same machine.

-- Daniel
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/