Spring Forward: how the log copes with summer time clock change

Last year, I reported how the macOS unified log experienced issues when clocks were put back from Summer (Daylight Savings) to regular time. That’s the more difficult change, as it results in one hour appearing to be duplicated, first in Summer time, then in regular time. Last weekend, the UK put its clocks forward from GMT/UTC to British Summer Time, which provided a perfect opportunity to see whether that works any better.

Interface quirks

If you study this using my log browser Ulbow, you’ll experience something very odd when trying to set the time. The hours you can set in Ulbow’s date picker exclude 01. Start with the hour set at 00, use the stepper to increment that to 01, and you’ll see it go straight to 02. Similar happens if you try typing in 01 instead. This is because the time set there is in the current time zone, now +0100, even when it refers to times before the clock change, when they’re on the day that the clock change took place. Change the date to an earlier or later day, and the date picker works entirely in the time zone applicable to that day.

bst01

bst02

As the UK changed its clocks on 29 March, that means that all times set for that day are considered to be in +0100. All times set for 28 March are in +0000, though.

Datestamps

Datestamps given in log extracts are shown in the time zone set in the Mac at the time they were collected. Browse your log across the moment of time change and you’ll see the datestamps change thus:
2020-03-29 01:09:22.489149+0000 361080253974026
2020-03-29 01:09:22.489160+0000 361080253985232
2020-03-29 02:09:22.522734+0100 361080253990360 === system wallclock time adjusted
2020-03-29 02:09:22.522749+0100 361080254005593
2020-03-29 02:09:22.522913+0100 361080254170158

which gives the date, time with timezone, and the Mach ticks. The latter demonstrate that these entries are consecutive, in case you’re in any doubt. It’s only when you display the whole datestamp that this becomes clear.

bst03

According to convention across Europe, Summer time adjustments are made at 01:00:00 +0000 (UTC). So in the Spring, the clocks are put forward from 01:00:00 regular time to 02:00:00 Summer time. In North America, changes are made at 02:00:00 local, and usually on different days. It wouldn’t be hard to do the same thing on the same day around the world, but we don’t. Because of the way that macOS manages time, changes to the system clock will inevitably occur shortly after the officially set time, in this case nearly ten minutes later.

How macOS changes time

The first sign that a clock change is about to take place is DAS (Duet Activity Scheduler) starting an ‘activity’ for NTP, the network time protocol, as com.apple.timed.ntp.wanted. This is run as an XPC activity, completes, and may need to be run a second time, which fires up the macOS time service com.apple.timed. As the time returned by the remote NTP service now gives a local time one hour ahead of the Mac’s clock, two time adjustments are likely: the first is the small correction to synchronise the seconds with the server, and the other is to advance the clock by an hour. These result in the announcement of
2020-03-29 02:09:22.522734+0100 === system wallclock time adjusted
which is the first log entry to use the new timezone.

This time change propagates to different systems, the first of which is part of com.apple.ipTelephony with the internal name of Bambi, something that I hadn’t come across before, but which is common to iOS. Other subsystems which report the change include, in order of appearance:

  • com.apple.loginwindow.logging
  • com.apple.CommCenter
  • com.apple.dmd
  • com.apple.calendar
  • com.apple.duetknowledged, which re-evaluates sunrise and sunset times
  • com.apple.locationd.Core

There are a lot of adjustments and changes made to Calendar resources as a result.

I aim to revisit this topic when we put our clocks back in the autumn/fall.