Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix dispatchIdleTimeout on Apple Silicon #2164

Closed
kevinrenskers opened this issue Sep 15, 2022 · 8 comments · Fixed by #2189
Closed

Fix dispatchIdleTimeout on Apple Silicon #2164

kevinrenskers opened this issue Sep 15, 2022 · 8 comments · Fixed by #2189

Comments

@kevinrenskers
Copy link
Contributor

kevinrenskers commented Sep 15, 2022

Description

The testIdleTimeout_InvokesDispatchAfterWithCorrectWhen test always fails when running on M1 Macs, and that's not because the test is flaky, it's because the underlying logic in the dispatchIdleTimeout method is broken on Apple Silicon.

See also https://stackoverflow.com/questions/73703816/dispatch-time-calculations-are-failing-on-apple-silicon, where sadly no answers have been posted yet.

Test doesn't fail on CI or Philip's machine, because they run on Intel.

@philipphofmann
Copy link
Member

Is the logic also broken on iPhones, @kevinrenskers?

@kevinrenskers
Copy link
Contributor Author

Yes. Just create a new project in Xcode, Obj-C. Use this in the AppDelegate.

- (BOOL)application:(UIApplication *)application didFinishLaunchingWithOptions:(NSDictionary *)launchOptions {
  dispatch_time_t now = dispatch_time(DISPATCH_TIME_NOW, 0);
  dispatch_time_t delta = (uint64_t)(1 * NSEC_PER_SEC);
  dispatch_time_t when = dispatch_time(now, delta);

  NSLog(@"now: %llu", now);
  NSLog(@"delta: %llu", delta);
  NSLog(@"when: %llu", when);
  NSLog(@"real delta: %llu", when-now);
  
  return YES;
}

And yea...

2022-09-15 09:29:31.613265+0200 TimerTest[5795:1519849] now: 3765829882641
2022-09-15 09:29:31.613294+0200 TimerTest[5795:1519849] delta: 1000000000
2022-09-15 09:29:31.613307+0200 TimerTest[5795:1519849] when: 3765853882641
2022-09-15 09:29:31.613318+0200 TimerTest[5795:1519849] real delta: 24000000

@kevinrenskers
Copy link
Contributor Author

Maybe it's not a real world problem, but the fact that the test in Swift returns a different expected when value and thus fails the test is worrying.

@philipphofmann
Copy link
Member

@kevinrenskers, please try

dispatch_time_t delta = (int64_t)(timeout * (NSTimeInterval)NSEC_PER_SEC);
dispatch_time_t dispatchTimeout = dispatch_time(DISPATCH_TIME_NOW, delta);

Instead of getting the dispatch time in advance, pass the constant DISPATCH_TIME_NOW to dispatch_time.

@kevinrenskers
Copy link
Contributor Author

That doesn't help, as it's still the addition of DISPATCH_TIME_NOW plus delta that results in the wrong value. It's only adding 24000000, not 1000000000 (what the delta is).

@kevinrenskers
Copy link
Contributor Author

I've sent a request for help to Apple Developer Technical Support.

@kevinrenskers
Copy link
Contributor Author

Got an answer from Apple.

Hello Kevin,

The dispatch_time function:

https://developer.apple.com/documentation/dispatch/1420519-dispatch_time/

takes a delta parameter in nanoseconds, but the return value is in ticks. (The default clock is based on mach_absolute_time which counts in ticks.)

That means you can’t add the delta to the time, but you should use the function instead.

The behavior is different on M1 Macs from Intel Macs. On Intel Macs ticks are nanoseconds, but that’s not true on M1:

https://developer.apple.com/videos/play/wwdc2020/10214/?time=1280

I wasn't really sure what he meant so I asked for clarification and he sent this:

Sorry for being unclear. You said:

1272914827933 + 1000000000 = 1273914827933, NOT 1272938827933

I said:

… you can’t add the delta to the time, but you should use the function instead.

I meant that you don’t get a valid answer by evaluating the expression 1272914827933 (ticks) + 1000000000 (nanoseconds). You do get the right answer by using the function:

dispatch_time_t when = dispatch_time(now, delta); // where now == 1272914827933, and delta == 1000000000

The correct answer on M1 is 1272938827933, not 1273914827933. The dispatch_time function deals with the fact that its first parameter is in ticks, but its second parameter is in nanoseconds — and returns a result in ticks.

So basically dispatch_time and dispatch_after deal with the fact that it's getting ticks and not nanoseconds. But our tests reads the when value and sees if it's equal to a value we're calculating in Swift without involving dispatch_time at all, and that value isn't the same and thus the test fails.

I don't see a way of calling dispatch_time from Swift though, and I haven't been able to refactor the test to calculate the same value as what the code is using. I'm also not sure how important this test is to begin with? Maybe we can remove it?

@philipphofmann philipphofmann self-assigned this Sep 19, 2022
@philipphofmann philipphofmann moved this from Needs Discussion to In Progress in Mobile & Cross Platform SDK Sep 19, 2022
@philipphofmann
Copy link
Member

That makes sense, @kevinrenskers. Thanks for the update. I'm going to restructure the code a bit and open a PR soon.

philipphofmann added a commit that referenced this issue Sep 19, 2022
The testIdleTimeout_InvokesDispatchAfterWithCorrectWhen
always failed on M1 Macs. This was because we used a different
way of calculating the expected dispatch_time in the tests than
in the ObjC code. The failing tests purpose is to validate that the
proper timeout is used to schedule the cancel block. This PR
restructures the code so the SentryDispatchQueueWrapper
hides this complexity, and callers don't need to calculate the
dispatch_time themselves. Now the test validates that the proper
timeout is passed down to SentryDispatchQueueWrapper.

Fixes GH-2164
philipphofmann added a commit that referenced this issue Sep 20, 2022
The testIdleTimeout_InvokesDispatchAfterWithCorrectWhen
always failed on M1 Macs. This was because we used a different
way of calculating the expected dispatch_time in the tests than
in the ObjC code. The failing tests purpose is to validate that the
proper timeout is used to schedule the cancel block. This PR
restructures the code so the SentryDispatchQueueWrapper
hides this complexity, and callers don't need to calculate the
dispatch_time themselves. Now the test validates that the proper
timeout is passed down to SentryDispatchQueueWrapper.

Fixes GH-2164
Repository owner moved this from In Progress to Done in Mobile & Cross Platform SDK Sep 20, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Archived in project
Development

Successfully merging a pull request may close this issue.

2 participants