Titanium JIRA Archive
Titanium SDK/CLI (TIMOB)

[TIMOB-26673] iOS: Race conditions in async APIs (e.g. timers)

GitHub Issuen/a
TypeBug
PriorityHigh
StatusClosed
ResolutionFixed
Resolution Date2019-01-11T19:46:43.000+0000
Affected Version/sRelease 8.0.0
Fix Version/sRelease 8.0.0
ComponentsiOS
Labelsn/a
ReporterJan Vennemann
AssigneeJan Vennemann
Created2018-12-20T17:45:08.000+0000
Updated2019-01-15T15:13:15.000+0000

Description

Async functions can trigger a race conditions which leads to an internal dead lock inside JavaScriptCore. This happens because we often reschedule block execution using [TiThreadPerformOnMainThread](https://github.com/appcelerator/titanium_mobile/blob/33498aeaddac7409a3f411a60455bfc5ddaeabf6/iphone/TitaniumKit/TitaniumKit/Sources/API/TiBase.m#L166). Note that these race conditions only happen if a lot of async stuff happens at the same time. This example uses a timer with a 5ms interval to force the deadlock to happen. It is very unlikely to happen under normal conditions. *Steps to reproduce the behavior* Run the following code in a classic app on an iOS device:
let counter = 0;
const win = Ti.UI.createWindow({ layout: 'vertical' });
const statusLabel = Ti.UI.createLabel({ top: 100, text: 'Running ...' });
win.add(statusLabel);
const counterLabel = Ti.UI.createLabel({ top: 5 });
win.add(counterLabel);
const testButton = Ti.UI.createButton({ top: 6, title: 'Click me!' });
testButton.addEventListener('click', () => Ti.API.info('expected'));
win.add(testButton);

function triggerRaceCondition() {
  counterLabel.text = counter++;
  console.log([${counter}] requestUserNotificationSettings);
  Ti.App.iOS.UserNotificationCenter.requestUserNotificationSettings(e => {
    console.log([${counter}] requestUserNotificationSettings callback);
  });
}
const triggerInterval = setInterval(() => triggerRaceCondition(), 5);
setTimeout(() => {
  clearInterval(triggerInterval);
  statusLabel.text = 'Finished!';
}, 1000);

win.open();
*Actual behavior* The whole app will freeze after a few iterations. The counter will not increase anymore and the button will not accept clicks. *Expected behavior* The counter should increase for about one second and then stop. The status should switch from "Running" to "Finished". The button should accept click events and print "expected" to the console. *Additional information* This is caused by [TiThreadPerformOnMainThread](https://github.com/appcelerator/titanium_mobile/blob/33498aeaddac7409a3f411a60455bfc5ddaeabf6/iphone/TitaniumKit/TitaniumKit/Sources/API/TiBase.m#L166) which reschedules a block on the main queue when not running on main thread. In this particular test case various things happen which ultimately lead to the deadlock inside JSCore:

The timer fires and calls out to its callback function (1)

Now, this function contains an async function, namely Ti.App.iOS.UserNotificationCenter.requestUserNotificationSettings. Under the hood this will call [getNotificationSettingsWithCompletionHandler:](https://developer.apple.com/documentation/usernotifications/unusernotificationcenter/1649524-getnotificationsettingswithcompl) of UNUserNotificationCenter. The completion handler for this method will be called on a separate thread. This is important for the race condition to happen.

Eventually the completion handler is called and it will call the JS callback (2) [here](https://github.com/appcelerator/titanium_mobile/blob/33498aeaddac7409a3f411a60455bfc5ddaeabf6/iphone/Classes/TiAppiOSUserNotificationCenterProxy.m#L199).

The timer fires again and it will be added to the dispatch queue to be processed.

Inside the callback (2) we make use of console.log. Since the callback was called from a different thread, KrollMethod will reschedule the console.log call to the main thread [here](https://github.com/appcelerator/titanium_mobile/blob/33498aeaddac7409a3f411a60455bfc5ddaeabf6/iphone/TitaniumKit/TitaniumKit/Sources/Kroll/KrollMethod.m#L42). This will schedule the method call behind the previously scheduled timer.

The timer callback (1) is now called which also want's to use console.log. However, the pending call from callback (2) still has a lock on that. Boom, deadlock!

Comments

  1. Jan Vennemann 2018-12-20

    A simple workaround for this specific test case using UNNotificationCenter is to wrap calling the callback in TiThreadPerformOnMainThread. This will schedule the complete callback execution on the main thread and not every single JS statement made in the callback. This should also be a lot more performant since we do not need to constantly switch threads.
  2. Jan Vennemann 2018-12-20

    PR: https://github.com/appcelerator/titanium_mobile/pull/10556 This fixes the issues with UNNotificationCenter. We may need to scan our SDK for similar issues.
  3. Jan Vennemann 2019-01-08

    8_0_X backport done in https://github.com/appcelerator/titanium_mobile/pull/10584
  4. Keerthi Mahalingam 2019-01-10

    FR Passed. Waiting for merge conflicts to be resolved for merge
  5. Lokesh Choudhary 2019-01-11

    PR's Merged.
  6. Samir Mohammed 2019-01-15

    Closing ticket, Verified fix in SDK Version 8.1.0.v20190115054502 and SDK version 8.0.0.v20190114160512. Test and other information can be found at: Master: https://github.com/appcelerator/titanium_mobile/pull/10556 8_0_X: https://github.com/appcelerator/titanium_mobile/pull/10584

JSON Source