| Re: [chrony-dev] macOS 13: suspicious jumps while sleeping |
[ Thread Index |
Date Index
| More chrony.tuxfamily.org/chrony-dev Archives
]
William G. Unruh __| Canadian Institute for|____ Tel: +1(604)822-3273
Physics&Astronomy _|___ Advanced Research _|____ Fax: +1(604)822-5324
UBC, Vancouver,BC _|_ Program in Cosmology |____ unruh@xxxxxxxxxxxxxx
Canada V6T 1Z1 ____|____ and Gravity ______|_ www.theory.physics.ubc.ca/
On Wed, 22 Nov 2017, Gerriet M. Denkmann wrote:
On 22 Nov 2017, at 15:42, Bryan Christianson <bryan@xxxxxxxxxxxxx> wrote:
On 22/11/2017, at 9:15 PM, Miroslav Lichvar <mlichvar@xxxxxxxxxx> wrote:
On Wed, Nov 22, 2017 at 02:03:17PM +0700, Gerriet M. Denkmann wrote:
macOS 13.1, chrony 3.2.
I modified check_current_time() in sched.c:
LOG(LOGS_WARN, "Forward time jump detected! %4ld sec”, raw->tv_sec - (prev_raw->tv_sec + elapsed_max.tv_sec) );
After the computer has been sleeping for some time (since about 10:10), I saw:
The computer has woken up only once and there are multiple messages
saying the clock jumped forward? That is weird. Any chance the new
timed daemon is interfering with the clock? There was a post on the
-users list how it can be disabled.
This looks like the 'timed' problem. Here is what I posted to the users list.
There is a bug in High Sierra (macOS 10.13) that leaves Apple's timed daemon active after it has been disabled in the System Settings 'Date and Time' preferences
timed continues to send NTP packets to the server specified in the System Preferences and then adjusts the system clock. This of course has a terrible effect on chronyd, with frequency and offsets jumping all over the place.
I have reported the bug to Apple so hopefully it will be fixed in some forthcoming patch release of macOS 10.13
I wrote a small program to see what my MacBook is doing when it thinks that no-one is looking (e.g. when the lid is closed).
Here is the output with comments and lines from chrony added:
First the poor MacBook has terrible problems falling asleep: repeatedly sleeping for less than 3 seconds and waking again for 45 seconds:
2017-11-22 18:59:33.314973 -[AppDelegate receiveSleepNote:]: awake for 106.3 sec; start sleep
2017-11-22 18:59:35.468490 -[AppDelegate receiveWakeNote:]: sleeping for 2.2 sec; now awake
2017-11-22 19:00:20.474175 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:00:23.001654 -[AppDelegate receiveWakeNote:]: sleeping for 2.5 sec; now awake
2017-11-22 19:01:08.000719 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:01:10.553012 -[AppDelegate receiveWakeNote:]: sleeping for 2.6 sec; now awake
2017-11-22 19:01:55.557896 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:01:58.086610 -[AppDelegate receiveWakeNote:]: sleeping for 2.5 sec; now awake
2017-11-22 19:02:43.089206 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:02:45.639407 -[AppDelegate receiveWakeNote:]: sleeping for 2.6 sec; now awake
2017-11-22 19:03:30.644818 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:03:33.196194 -[AppDelegate receiveWakeNote:]: sleeping for 2.6 sec; now awake
2017-11-22 19:04:18.201862 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:04:20.747223 -[AppDelegate receiveWakeNote:]: sleeping for 2.5 sec; now awake
2017-11-22 19:05:05.750811 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:05:08.296899 -[AppDelegate receiveWakeNote:]: sleeping for 2.5 sec; now awake
2017-11-22 19:05:53.302906 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
2017-11-22 19:05:55.841995 -[AppDelegate receiveWakeNote:]: sleeping for 2.5 sec; now awake
2017-11-22 19:06:40.846943 -[AppDelegate receiveSleepNote:]: awake for 45.0 sec; start sleep
DErtainly if it keeps waking up, chrony will be confused. Since the system
clock clearly is not running when it is asleep, the system time will be out
when it wakes up and when chrony tries to figure out the time, it will be
confused. I am not at all sure I believe that "sleeping for 2.5 sec" since the
clock is not running.
I am not sure what is run when you put it to sleep but perhaps you can disable
chrony when it goes to sleep and reawakens it when you come out of sleep.
chrony itself of course has no idea that the computer has gone to sleep under
it-- it is not running during that time-- so you need something from the
outside to put chrony to sleep.
But even when it finally manages to sleep it will from time to time become active (while still asleep) and stay active for about 40 seconds:
On each of these occasions chrony will see a jump comparable to the time spend inactive.
All of this happens when it is supposed to be asleep.
2017-11-22 19:36:59.183870 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping active since Wed Nov 22 18:57:25 2017 for 570.0 sec
2017-11-22 19:36:59.184052 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping inactive for 1803.2 sec
default 19:36:59.679124 +0700 chronyd Forward time jump detected! 1794 sec
2017-11-22 19:46:12.739923 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping active since Wed Nov 22 19:36:59 2017 for 40.0 sec
2017-11-22 19:46:12.740084 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping inactive for 513.6 sec
default 19:46:37.786756 +0700 chronyd Forward time jump detected! 504 sec
2017-11-22 20:11:19.325330 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping active since Wed Nov 22 19:46:12 2017 for 40.0 sec
2017-11-22 20:11:19.325525 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping inactive for 1466.6 sec
default 20:11:59.634231 +0700 chronyd Forward time jump detected! 1457 sec
2017-11-22 20:19:34.860451 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping active since Wed Nov 22 20:11:19 2017 for 40.0 sec
2017-11-22 20:19:34.860603 -[AppDelegate applicationDidFinishLaunching:]_block_invoke sleeping inactive for 455.5 sec
default 20:19:27.018218 +0700 chronyd Forward time jump detected! 447 sec
2017-11-22 20:29:38.999731 -[AppDelegate receiveWakeNote:]: sleeping for 4978.2 sec; now awake
2017-11-22 20:29:48.913202 -[AppDelegate applicationDidFinishLaunching:]_block_invoke awake active since Wed Nov 22 20:19:34 2017 for 40.0 sec
2017-11-22 20:29:48.913376 -[AppDelegate applicationDidFinishLaunching:]_block_invoke awake inactive for 574.1 sec
default 20:29:54.537872 +0700 chronyd Forward time jump detected! 564 sec
I do not know anything about the internal workings of chrony, but wouldn’t it be possible to block all activity when the computer is supposed to be asleep?
The problem is that chrony has no idea that the computer has gone to sleep
under it. You could simply kill chrony before sleeping and restart it when it
finally comes out of sleep.
While listening for NSWorkspaceWillSleepNotification probably will not be suitable for chrony, there should be an IOKit way of determining sleep status.
How? Nothing is running.