macos-12: timestamps differ by 182 seconds - check your system clock #2996

tresf · 2023-11-20T21:20:01Z

UPDATE: Potential workaround:

Support got back to me privately, this is what they recommend as a workaround while engineering investigates:
steps:
  - name: Sync clock
    run: sudo sntp -sS time.windows.com
Surprisingly, the command succeeds. I asked why, and they said that time.windows.com is permitted in Azure -- where the runners live -- whereas time.apple.com is not currently permitted in Azure.
Since the issue is sporadic, I haven't had enough builds yet to know if it fixes the problem.

Original post:

There is a private support ticket (2444231) open for this issue, but I wanted to file a public report incase this problem is affecting others.

Quoting:

"So when looking at the last 16 builds, that's about one in every four jobs or every other build (2 macOS jobs per build / workflow run) showing this clock problem, with one out of eight builds failing because of it."

Describe the bug
Intermittent signing failures calling |xargs codesign --force -s P5DXXXXXXX --timestamp --options runtime on 33 files.

- 2023-11-20T15:02:25.6218970Z      [exec] ./Contents/Frameworks/myfile.dylib: timestamps differ by 182 seconds - check your system clock

To Reproduce
Unsure how to reproduce.

I've tried calling sudo sntp -sS time.apple.com to force synchronization, but the command fails on mac-12
The issue only occurs when the time has drifted over a certain threshold.
I'm happy to share the actions file, but it references some scripts, so if this issue is related to something in the build, it will be some minor trimming to narrow it down

Quoting my colleague:

"with every step except for the first two showing times that are several minutes longer than they could be, even skipped steps. It can't be a coincidence that that difference in time is almost exactly the same as the one in the timestamps differ error message. Other instance of the same problem (not all failing):"
https://github.com/<repo>/<project>/actions/runs/6931808026/job/18854361938
https://github.com/<repo>/<project>/actions/runs/6822493602/job/18554615759
https://github.com/<repo>/<project>/actions/runs/6748369490/job/18346546669
https://github.com/<repo>/<project>/actions/runs/6741334623/job/18325763976
https://github.com/<repo>/<project>/actions/runs/6733880279/job/18303537472
https://github.com/<repo>/<project>/actions/runs/6728235436/job/18287265472
https://github.com/<repo>/<project>/actions/runs/6728003702/job/18286649495
https://github.com/<repo>/<project>/actions/runs/6728003702/job/18286649495
"So when looking at the last 16 builds, that's about one in every four jobs or every other build (2 macOS jobs per build / workflow run) showing this clock problem, with one out of eight builds failing because of it."

Expected behavior

Runner Version and Platform

GitHub Actions 6 (hosted)
Current runner version: '2.311.0'

OS of the machine running the runner? OSX/Windows/Linux/...

macos-12

What's not working?

The codesign command, intermittently

Workaround

No workaround at this time, resubmitting the job generally fixes it.

Job Log Output

Runner and Worker's Diagnostic Logs

If applicable, add relevant diagnostic log information. Logs are located in the runner's _diag folder. The runner logs are prefixed with Runner_ and the worker logs are prefixed with Worker_. Each job run correlates to a worker log. All sensitive information should already be masked out, but please double-check before pasting here.

I'm unable to locate the _diag folder. I'm happy to provide more information.

2023-11-20T15:02:17.3898910Z      [copy] Copying 1 file to /Users/runner/work/<repo>/<project>/tray/out/build
2023-11-20T15:02:17.3924940Z      [echo] Signing /Users/runner/work/<repo>/<project>/tray/out/build/scripts/payload/MyApp.app using P5DXXXXXXX
2023-11-20T15:02:22.4369960Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/bin/java: replacing existing signature
2023-11-20T15:02:22.8144560Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libnet.dylib: replacing existing signature
2023-11-20T15:02:22.8146460Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libnio.dylib: replacing existing signature
2023-11-20T15:02:23.0571980Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libzip.dylib: replacing existing signature
2023-11-20T15:02:23.0574000Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libfreetype.dylib: replacing existing signature
2023-11-20T15:02:23.0576250Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libsplashscreen.dylib: replacing existing signature
2023-11-20T15:02:23.1737660Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libjimage.dylib: replacing existing signature
2023-11-20T15:02:23.2744790Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/jli/libjli.dylib: replacing existing signature
2023-11-20T15:02:23.2747460Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libosxkrb5.dylib: replacing existing signature
2023-11-20T15:02:23.4048170Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libosxui.dylib: replacing existing signature
2023-11-20T15:02:23.5190210Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/librmi.dylib: replacing existing signature
2023-11-20T15:02:23.5192710Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libsunec.dylib: replacing existing signature
2023-11-20T15:02:23.6289500Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libawt_lwawt.dylib: replacing existing signature
2023-11-20T15:02:23.8059100Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/server/libjvm.dylib: replacing existing signature
2023-11-20T15:02:23.8062430Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/server/libjsig.dylib: replacing existing signature
2023-11-20T15:02:23.9066490Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libjavajpeg.dylib: replacing existing signature
2023-11-20T15:02:24.1304900Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libmlib_image.dylib: replacing existing signature
2023-11-20T15:02:24.1307550Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libmanagement.dylib: replacing existing signature
2023-11-20T15:02:24.1309810Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libjsound.dylib: replacing existing signature
2023-11-20T15:02:24.2925070Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libjsig.dylib: replacing existing signature
2023-11-20T15:02:24.5226360Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libprefs.dylib: replacing existing signature
2023-11-20T15:02:24.5230470Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libjawt.dylib: replacing existing signature
2023-11-20T15:02:24.5235700Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libfontmanager.dylib: replacing existing signature
2023-11-20T15:02:24.6234830Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/jspawnhelper: replacing existing signature
2023-11-20T15:02:24.7255850Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libosxsecurity.dylib: replacing existing signature
2023-11-20T15:02:24.7262360Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/liblcms.dylib: replacing existing signature
2023-11-20T15:02:24.8568230Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libverify.dylib: replacing existing signature
2023-11-20T15:02:25.0567620Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libj2gss.dylib: replacing existing signature
2023-11-20T15:02:25.0570830Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libjava.dylib: replacing existing signature
2023-11-20T15:02:25.1786290Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/client/libjvm.dylib: replacing existing signature
2023-11-20T15:02:25.2909500Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/client/libjsig.dylib: replacing existing signature
2023-11-20T15:02:25.4907470Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libawt.dylib: replacing existing signature
2023-11-20T15:02:25.4912150Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libosx.dylib: replacing existing signature
2023-11-20T15:02:25.4914400Z      [exec] ./Contents/PlugIns/Java.runtime/Contents/Home/lib/libosxapp.dylib: replacing existing signature
2023-11-20T15:02:25.6218970Z      [exec] ./Contents/Frameworks/libusb4java.dylib: timestamps differ by 182 seconds - check your system clock
2023-11-20T15:02:25.6763520Z 
2023-11-20T15:02:25.6765420Z BUILD FAILED
2023-11-20T15:02:25.6769160Z /Users/runner/work/<repo>/<project>/tray/ant/apple/installer.xml:30: The following error occurred while executing this line:
2023-11-20T15:02:25.6774120Z /Users/runner/work/<repo>/<project>/tray/ant/apple/installer.xml:232: exec returned: 1

The text was updated successfully, but these errors were encountered:

grzegorzkrukowski · 2023-11-28T14:07:19Z

We are experiencing the same issue on macOS-13 runners.
Running sudo sntp -sS time.apple.com gives an error:
sntp: Exchange failed: Timeout

Simple re-running fixes the problem, but it occurs occasionally.

nbolton · 2023-11-29T09:28:50Z

Also seeing this randomly:

timestamps differ by [n] seconds - check your system clock

And, when using either sudo sntp -sS time.apple.com or sntp -sS time.apple.com on GitHub M1 runner:

sntp: Exchange failed: Timeout

Error verbatim:
/Users/runner/work/repo/build/dist/mac-arm64/Foobar.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Resources/af.lproj/locale.pak: timestamps differ by 211 seconds - check your system clock

idevelop · 2023-11-29T14:51:10Z

Seeing the same issue, interestingly around the same time skew: 183 and 187 in different instances.

tresf · 2023-11-30T04:48:15Z

Support got back to me privately, this is what they recommend as a workaround while engineering investigates:

steps:
  - name: Sync clock
    run: sudo sntp -sS time.windows.com

Surprisingly, the commend succeeds. I asked why, and they said that time.windows.com is permitted in Azure -- where the runners live -- whereas time.apple.com is not currently permitted in Azure.

Since the issue is sporadic, I haven't had enough builds yet to know if it fixes the problem.

(edit 1: comments below seem to be positive that this is a viable workaround)
(edit 2: It's been a week for me and no issues 🤞 )

bjornoleh · 2023-11-30T13:25:18Z

Support got back to me privately, this is what they recommend as a workaround while engineering investigates:
steps:
  - name: Sync clock
    run: sudo sntp -sS time.windows.com
Surprisingly, the commend succeeds. I asked why, and they said that time.windows.com is permitted in Azure -- where the runners live -- whereas time.apple.com is not currently permitted in Azure.

Since the issue is sporadic, I haven't had enough builds yet to know if it fixes the problem.

Thanks @b099l3 for this workaround.

I did some test runs on macos-13, and am getting highly variable results of 0 - 204 seconds time difference. Interestingly, the differences are both positive and negative:

Run sudo sntp -sS time.windows.com
+100.681645 +/- 0.054360
+0.133009 +/- 0.071026
-70.411227 +/- 0.075823
-63.796918 +/- 0.059426
+47.041587 +/- 0.058953
-70.255016 +/- 0.073485
+0.555905 +/- 0.068744
+0.403363 +/- 0.066246
-204.484781 +/- 0.064150
+0.189943 +/- 0.087607

tresf · 2023-11-30T16:15:53Z

Hidden, outdated

Quoting https://github.com/fastlane/fastlane/pull/21583#issuecomment-1833616129:

Results:

Without [sudo sntp -sS time.windows.com]

4 failures in 16 runs (25%)

With [sudo sntp -sS time.windows.com]

2 failures in 14 runs (14%)

... suggesting that the provided workaround from GitHub support only slightly improves this problem, but is still unacceptable. At time of writing this, I still do not have enough runs since applying this patch to make a similar report.

What's particularly interesting about fastlane's bug report is it does not have the same timestamp message in the error output, suggesting that this bug may be affecting other API calls with slightly different error messages.

For example, I have also observed the following error occur in the logs:

Run xcrun notarytool submit --wait "my-file.pkg" \
Conducting pre-submission checks for my-file.pkg and initiating connection to the Apple notary service...
- Error: HTTP status code: 401. Unable to authenticate. The request cannot be processed at this time. Please try again later.
- Ensure that all authentication arguments are correct.

... which may be related to the fastlane error Authentication credentials are missing or invalid.. If this is true, (I'm not sure how to confirm this) it raises the severity of this bug, as it would be affecting more commands (albeit those without a clear or intuitive error to explain why they're failing). If others observe this second error in correlation to time synchronization, I would like to know so that I can provide this as evidence of higher frequency (and thus severity) to GitHub support.

bjornoleh · 2023-11-30T16:33:21Z

Quoting fastlane/fastlane#21583 (comment):

Results:

Without [sudo sntp -sS time.windows.com]

4 failures in 16 runs (25%)

With [sudo sntp -sS time.windows.com]

2 failures in 14 runs (14%)

... suggesting that the provided workaround from GitHub support only slightly improves this problem, but is still unacceptable. At time of writing this, I still do not have enough runs since applying this patch to make a similar report.

Hi, @tresf , sorry, but you are misquoting my testing.

I only have succesful results with this workaround:

steps:
  - name: Sync clock
    run: sudo sntp -sS time.windows.com

The time differences before syncing is reported above, and in summary, I observed time differences from -204 to +100 seconds, and occasionally <1 second. All runs were successful, thanks to the 'Sync clock' step.

The success/failure rates were referencing the open PR to Fastlane:
fastlane/fastlane#21583.

Hope that clarifies things :-)

tresf · 2023-11-30T16:38:37Z

Hope that clarifies things :-)

It does, thank you. I'll edit the post to hide the irrelevant parts.

thboop · 2023-11-30T17:43:51Z

Hey folks, thanks for the report. Our hosted mac team is working on a fix, they will follow up in this thread.

wAuner · 2023-12-06T06:37:44Z

Any updates on this? It's really getting annoying. Our internal deployment fails every few days due to this issue.

tresf · 2023-12-06T17:52:31Z

Any updates on this? It's really getting annoying. Our internal deployment fails every few days due to this issue.

I can't speak on behalf of GitHub support (that's who I reached out to first, because I pay GitHub for these services), but this seems to be the accepted workaround: #2996 (comment). The original question has been amended to include this answer.

nbolton · 2023-12-08T00:29:26Z

this seems to be the accepted workaround

I can confirm that I haven't seen this problem since using the time.windows.com workaround (#2996 (comment)), so that seems to have fixed it.

…ner#2996

nodeselector · 2023-12-14T00:24:11Z

Hey folks, I'm from the hosted macOS runner team, we have rolled out fixes for the root causes of the time drift, and don't expect to see this time drift anymore. There's a slight caveat that some runners that were registered before the fixes were rolled out may still see some impact, but that caveat should expire in a few hours. That being said, please @ me if you belief you're continuing to encounter time drift related issues.

tresf · 2023-12-14T01:33:59Z

Should this be marked as closed or would you rather monitor it?

nodeselector · 2023-12-15T01:09:38Z

@tresf we'll monitor for a bit longer and will then close the comment. Thanks again for bringing this to our attention and for bearing with us.

This reverts commit a5d01ae.

tresf added the bug Something isn't working label Nov 20, 2023

b099l3 mentioned this issue Nov 30, 2023

[spaceship] decrease App Store Connect API token issued-at-time to prevent server rejection fastlane/fastlane#21583

Merged

6 tasks

justinpersaud mentioned this issue Dec 11, 2023

[NoQA] Sync clock on setupGitForOSBotifyApp / remove old action Expensify/App#32859

Merged

47 tasks

timangus added a commit to graphia-app/graphia that referenced this issue Dec 12, 2023

Workaround for GHA clock drift (actions/runner#2996)

a5d01ae

n8maninger added a commit to SiaFoundation/hostd that referenced this issue Dec 12, 2023

ci: sync clock on mac to fix time drift in publish builds actions/run…

14862eb

…ner#2996

n8maninger added a commit to SiaFoundation/hostd that referenced this issue Dec 12, 2023

ci: resync system clock actions/runner#2996

f1a0eab

TingluoHuang closed this as completed Jan 8, 2024

timangus added a commit to graphia-app/graphia that referenced this issue Apr 1, 2024

Revert "Workaround for GHA clock drift (actions/runner#2996)"

92e1cf0

This reverts commit a5d01ae.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

macos-12: timestamps differ by 182 seconds - check your system clock #2996

macos-12: timestamps differ by 182 seconds - check your system clock #2996

tresf commented Nov 20, 2023 •

edited

grzegorzkrukowski commented Nov 28, 2023 •

edited

nbolton commented Nov 29, 2023 •

edited

idevelop commented Nov 29, 2023

tresf commented Nov 30, 2023 •

edited

bjornoleh commented Nov 30, 2023

tresf commented Nov 30, 2023 •

edited

Results:

bjornoleh commented Nov 30, 2023 •

edited

Results:

tresf commented Nov 30, 2023

thboop commented Nov 30, 2023

wAuner commented Dec 6, 2023

tresf commented Dec 6, 2023 •

edited

nbolton commented Dec 8, 2023 •

edited

nodeselector commented Dec 14, 2023

tresf commented Dec 14, 2023

nodeselector commented Dec 15, 2023

macos-12: timestamps differ by 182 seconds - check your system clock #2996

macos-12: timestamps differ by 182 seconds - check your system clock #2996

Comments

tresf commented Nov 20, 2023 • edited

Runner Version and Platform

What's not working?

Workaround

Job Log Output

Runner and Worker's Diagnostic Logs

grzegorzkrukowski commented Nov 28, 2023 • edited

nbolton commented Nov 29, 2023 • edited

idevelop commented Nov 29, 2023

tresf commented Nov 30, 2023 • edited

bjornoleh commented Nov 30, 2023

tresf commented Nov 30, 2023 • edited

Results:

bjornoleh commented Nov 30, 2023 • edited

Results:

tresf commented Nov 30, 2023

thboop commented Nov 30, 2023

wAuner commented Dec 6, 2023

tresf commented Dec 6, 2023 • edited

nbolton commented Dec 8, 2023 • edited

nodeselector commented Dec 14, 2023

tresf commented Dec 14, 2023

nodeselector commented Dec 15, 2023

tresf commented Nov 20, 2023 •

edited

grzegorzkrukowski commented Nov 28, 2023 •

edited

nbolton commented Nov 29, 2023 •

edited

tresf commented Nov 30, 2023 •

edited

tresf commented Nov 30, 2023 •

edited

bjornoleh commented Nov 30, 2023 •

edited

tresf commented Dec 6, 2023 •

edited

nbolton commented Dec 8, 2023 •

edited