The computation time for the same block of simple calculation varies significantly in IOS 8.4

Question

Created Aug ’15

Replies 2

Boosts 0

Participants 2

Just want to know if anybody hit the same issue. I filed a bug report (21793207) to https://bugreport.apple.com on 7/13/2015. I got no response so far.

Summary: The problem came from a complex task, but I simplified the problem to the code below.

For this block of simple calculations:

{

double test = 0;

for (int i = 0; i < 1000000; i++) {

test += 1./(1+exp(-i));

test = sqrt(test);

}

the computation time can vary significantly on iPhone6 IOS 8.4 (check below iPhone6.ios8.4.log), from using 0.110 seconds to 0.031 seconds. In reality, it should only use 0.031 seconds to finish. I checked the performance of the same code on iPhone4S IOS 8.1.1 (check below iPhone4s.ios8.1.1.log), the computation time is consistent, always use 0.074 seconds. It doesn't make sense that doing the same thing, iPhone6 could be slower than iPhone4S.

My hypothesis is that this is a bug in IOS 8.4.

Expected Results:

The computation time for that same block of code should always be: 0.031 seconds or something close to that one, instead that right now it can increase 3 times more in the current setting.

Actual Results:

The same block of computations code uses significant different time to finish, from 0.031 seconds to 0.110 seconds. The behavior is different significantly in different environments.

Code:

- (double)testLoad:(int)iii {

double test = 0;

NSDate *startDate = [NSDate date];

for (int i = 0; i < 1000000; i++) {

test += 1./(1+exp(-i));

test = sqrt(test);

}

NSTimeInterval elapsedTime = [[NSDate date] timeIntervalSinceDate:startDate];

NSLog(@"%4.3f\t%f\t%d", elapsedTime, test, iii);

return test;

}

- (void)testTimeoutCallback:(NSTimer *)timer {

NSLog(@"testTimeoutCallback called");

for (int i = 0; i < 10; i++) [self testLoad:i];

}

- (IBAction)start:(id)sender {

testTimer = [NSTimer scheduledTimerWithTimeInterval:1 target:self selector:@selector(testTimeoutCallback:) userInfo:nil repeats:YES];

}

iPhone6.ios8.4.log

2015-07-13 07:21:49.627 Testing[426:19837] testTimeoutCallback called

2015-07-13 07:21:49.737 Testing[426:19837] 0.107 1.618034 0

2015-07-13 07:21:49.810 Testing[426:19837] 0.073 1.618034 1

2015-07-13 07:21:49.867 Testing[426:19837] 0.056 1.618034 2

2015-07-13 07:21:49.920 Testing[426:19837] 0.052 1.618034 3

2015-07-13 07:21:49.961 Testing[426:19837] 0.041 1.618034 4

2015-07-13 07:21:49.999 Testing[426:19837] 0.039 1.618034 5

2015-07-13 07:21:50.036 Testing[426:19837] 0.037 1.618034 6

2015-07-13 07:21:50.068 Testing[426:19837] 0.032 1.618034 7

2015-07-13 07:21:50.100 Testing[426:19837] 0.031 1.618034 8

2015-07-13 07:21:50.131 Testing[426:19837] 0.031 1.618034 9

2015-07-13 07:21:50.627 Testing[426:19837] testTimeoutCallback called

2015-07-13 07:21:50.735 Testing[426:19837] 0.107 1.618034 0

2015-07-13 07:21:50.809 Testing[426:19837] 0.073 1.618034 1

2015-07-13 07:21:50.867 Testing[426:19837] 0.058 1.618034 2

2015-07-13 07:21:50.919 Testing[426:19837] 0.051 1.618034 3

2015-07-13 07:21:50.961 Testing[426:19837] 0.041 1.618034 4

2015-07-13 07:21:51.000 Testing[426:19837] 0.038 1.618034 5

2015-07-13 07:21:51.036 Testing[426:19837] 0.037 1.618034 6

2015-07-13 07:21:51.068 Testing[426:19837] 0.032 1.618034 7

2015-07-13 07:21:51.100 Testing[426:19837] 0.031 1.618034 8

2015-07-13 07:21:51.131 Testing[426:19837] 0.031 1.618034 9

iPhone4s.ios8.1.1.log

2015-07-13 07:24:34.756 Testing[1504:319466] testTimeoutCallback called

2015-07-13 07:24:34.833 Testing[1504:319466] 0.073 1.618034 0

2015-07-13 07:24:34.908 Testing[1504:319466] 0.074 1.618034 1

2015-07-13 07:24:34.982 Testing[1504:319466] 0.073 1.618034 2

2015-07-13 07:24:35.057 Testing[1504:319466] 0.074 1.618034 3

2015-07-13 07:24:35.131 Testing[1504:319466] 0.074 1.618034 4

2015-07-13 07:24:35.207 Testing[1504:319466] 0.074 1.618034 5

2015-07-13 07:24:35.281 Testing[1504:319466] 0.074 1.618034 6

2015-07-13 07:24:35.355 Testing[1504:319466] 0.073 1.618034 7

2015-07-13 07:24:35.430 Testing[1504:319466] 0.074 1.618034 8

2015-07-13 07:24:35.505 Testing[1504:319466] 0.074 1.618034 9

2015-07-13 07:24:35.755 Testing[1504:319466] testTimeoutCallback called

2015-07-13 07:24:35.830 Testing[1504:319466] 0.073 1.618034 0

2015-07-13 07:24:35.904 Testing[1504:319466] 0.074 1.618034 1

2015-07-13 07:24:35.978 Testing[1504:319466] 0.073 1.618034 2

2015-07-13 07:24:36.053 Testing[1504:319466] 0.074 1.618034 3

2015-07-13 07:24:36.127 Testing[1504:319466] 0.073 1.618034 4

2015-07-13 07:24:36.202 Testing[1504:319466] 0.074 1.618034 5

2015-07-13 07:24:36.276 Testing[1504:319466] 0.074 1.618034 6

2015-07-13 07:24:36.350 Testing[1504:319466] 0.074 1.618034 7

2015-07-13 07:24:36.425 Testing[1504:319466] 0.074 1.618034 8

2015-07-13 07:24:36.500 Testing[1504:319466] 0.074 1.618034 9

Boost

Answer 1

DTS Engineer OP

Apple

Aug ’15

The computation time for that same block of code should always be: 0.031 seconds or something close to that one [...]

That’s an unreasonable expectation. There are lots of things that can cause computation time to vary significantly from run-to-run. The most obvious ones that spring to mind are:

thread scheduling
thermal (the system slows down the CPU as it gets hotter)

Artificially tests like this one are useful in some situations but I suspect that in this case you’ll have to take a step back and discuss what your app is trying to do at a higher level.

Share and Enjoy
—
Quinn "The Eskimo!"
Apple Developer Relations, Developer Technical Support, Core OS/Hardware

let myEmail = "eskimo" + "1" + "@apple.com"

0

Answer 2

jcheng_ca OP

Aug ’15

Eskimo, thank you for your reply.

It seems that you believe it is a regular behavior in a mobile device instead of a bug. My bug hypothesis is based on the observation that the same computation unit behaved differently on iPhone4S IOS 8.1.1 and on iPhone6 IOS 8.4.

Although you gave your hypothesis, still there are a few observations that cannot be explained:

1. The computation time of the same code on iPhone4S IOS 8.1.1 (check iPhone4s.ios8.1.1.log) is consistent, always use 0.074 seconds.

2. On iPhone6 IOS 8.4, the first loop to do the computation requires 0.107 seconds. The computation time will decrease to the expected value (0.031 seconds) after a few more loops. If starting over again, it will repeat the same pattern. "thermal (the system slows down the CPU as it gets hotter)" should not apply here.

Bug or not bug may be verified by running the same code on iPhone6 with IOS 8.1.1. Since I can't restore my iPhone6' IOS back to 8.1.1, I can't verify that. Maybe the next IOS version can give some hints.

In the real app, we have a same computation task every 0.128 seconds. The behavior is: In the first 4.5 seconds, every computation unit fluctuates around 0.02 seconds to finish. After 4.5 seconds, the same computation unit will require around 0.06 seconds to finish, and always keep that value. It is also observable using Profile/Instruments/Time Profiler instead of using log.

Again, the simpflied code is in the bug report (21793207), https://bugreport.apple.com. All code is in ViewController.m. There are less than 20 lines of code.

0