bug(ios): app hanging for more than 2000ms during system-keyboard startup

[jahorton]

Describe the bug

Relates to #1492.

We have quite a number of Sentry reports in which our iOS system keyboard is terminated due to taking too long to initialize. This termination tends to happen in a number of places within the code; after all, it's a externally-based time-triggered termination.

Good point-of-reference report: https://keyman.sentry.io/issues/5518064391/events/ca1f3a0ca13e4c0fb3f3408a3aa9e821/

As can be seen from the linked report above, we sometimes have repeated page-reloading occurring as the system-keyboard is starting up. Using the same Breadcrumbs section -> View All pattern, we can see a number of reloads all triggered within the span of two seconds.

• Earliest visible "Keyboard loaded" breadcrumb: 03:37:10.476
• Last one: 03:37:12.502
• Count: 8 (!)

That's eight times that the function below - which triggers when the keyboard host-page finishes loading - was triggered within the span of two seconds:

keyman/ios/engine/KMEI/KeymanEngine/Classes/Keyboard/KeymanWebViewController.swift

Lines 593 to 600 in 402b196

	extension KeymanWebViewController: KeymanWebDelegate {
	func keyboardLoaded(_ keymanWeb: KeymanWebViewController) {
	delegate?.keyboardLoaded(keymanWeb)
	isLoading = false
	let message = "Loaded keyboard."
	os_log("%{public}s", log: KeymanEngineLogger.engine, type: .info, message)
	SentryManager.breadcrumb(message, sentryLevel: .debug)

The report above in particular is interesting for an extra reason - it fits a pattern for some of the "overused RAM" reports and even includes a "low memory" event notification in its logs.

---

Note: not all cases are during the initial load. This one has the same report title, but it's triggered at a distinctly different point within the keyboard lifecycle: https://keyman.sentry.io/issues/5368749989/events/24c32ecb945d4932bc6ecc8451ba6fb2/

Reproduce the bug

No response

Expected behavior

No response

Related issues

No response

Keyman apps

• Keyman for Android
• Keyman for iPhone and iPad
• Keyman for Linux
• Keyman for macOS
• Keyman for Windows
• Keyman Developer
• KeymanWeb
• Other - give details at bottom of form

Keyman version

No response

Operating system

No response

Device

No response

Target application

No response

Browser

No response

Keyboard name

No response

Keyboard version

No response

Language name

No response

Additional context

No response

[jahorton]

Regarding the multi-reload...

keyman/ios/engine/KMEI/KeymanEngine/resources/Keyman.bundle/Contents/Resources/ios-host.js

Lines 72 to 77 in 84ede94

	// During proper loads of KMW, a keyboard will be set very early on.
	// There's a chance that the keyboard is still loading, so we double-check
	// against the stub count.
	if(!keyman.core.activeKeyboard && !keyman.keyboardRequisitioner.cache.defaultStub) {
	location.reload();
	}

There's a chance that this is related, though its usage seems to be restricted to an operation that should be one-time - I believe it was originally added to detect 'blank keyboard' states we ran into in the past (when loading the keyboard after it was backgrounded) + do a one-time reload to work around them.

[jahorton]

Possibly worth investigating:

keyman/ios/engine/KMEI/KeymanEngine/Classes/Keyboard/KeymanWebViewController.swift

Lines 303 to 306 in 65b3c75

	// Warning: without special handling, any `guard` that fails here can trigger an
	// infinite keyboard reload, as the keyboard page itself will note that the keyboard
	// failed to initialize properly.
	guard FileManager.default.fileExists(atPath: fileURL.path) else {

[sentry]

Sentry Issue: KEYMAN-MAC-JA

[sentry]

Sentry Issue: KEYMAN-IOS-78

[jahorton]

Possibly of note: our iOS app is currently using synchronous calls when making JS calls into the keyboard's host page.

Refer to https://stackoverflow.com/a/73839219.

What we use: https://developer.apple.com/documentation/webkit/wkwebview/evaluatejavascript(_:completionhandler:)

There is an async version: https://developer.apple.com/documentation/webkit/wkwebview/callasyncjavascript(_:arguments:in:in:completionhandler:)

It is worth noting, though, that our Android app requires an internal JS queue that took us a while to get just right. It'd be nice if we could find a way to introduce a minor gap here or there to prevent hanging behavior that wouldn't require as much investment as that JS queue did.

Here's a fun related stack trace from one of the events for the linked Sentry issue:

  libsystem_kernel    0x1e4411178  mach_msg2_trap
  libsystem_kernel    0x1e4410f0c  mach_msg2_internal
  libsystem_kernel    0x1e4410e24  mach_msg_overwrite
  libsystem_kernel    0x1e4410c64  mach_msg
  libdispatch         0x1a4c9cefc  _dispatch_mach_send_and_wait_for_reply
  libdispatch         0x1a4c9d29c  dispatch_mach_send_with_result_and_wait_for_reply
  libxpc              0x206e056d0  xpc_connection_send_message_with_reply_sync
  RunningBoardServices0x1abd473d0  -[RBSXPCMessage sendToConnection:error:]
  RunningBoardServices0x1abd47090  -[RBSXPCMessage invokeOnConnection:withReturnCollectionClass:entryClass:error:]
  RunningBoardServices0x1abd47018  -[RBSXPCMessage invokeOnConnection:withReturnClass:error:]
  RunningBoardServices0x1abd5656c  -[RBSConnection limitationsForInstance:error:]
  RunningBoardServices0x1abd56494  -[RBSProcessHandle activeLimitations]
  WebKit              0x1b1f71cf0  WebKit::PageClientImpl::canTakeForegroundAssertions
  WebKit              0x1b20a2f00  WebKit::WebPageProxy::runJavaScriptInFrameInScriptWorld
  WebKit              0x1b1d69190  -[WKWebView _evaluateJavaScript:asAsyncFunction:withSourceURL:withArguments:forceUserGesture:inFrame:inWorld:completionHandler:]
  WebKit              0x1b1d68018  -[WKWebView evaluateJavaScript:completionHandler:]
  KeymanEngine        0x103697164  KeymanWebViewController.setSpacebarText (KeymanWebViewController.swift:237)
  KeymanEngine        0x103690a4c  KeymanWebViewController.updateSpacebarText (KeymanWebViewController.swift:242)
  KeymanEngine        0x103698cec  KeymanWebViewController.keyboardLoaded (KeymanWebViewController.swift:747)
  KeymanEngine        0x1036a0a68  KeymanWebViewController.webView (KeymanWebViewController.swift:666)
  KeymanEngine        0x1036992a0  KeymanWebViewController.webView (<compiler-generated>)
  KeymanEngine        0x1036992a0  KeymanWebViewController.webView (<compiler-generated>:659)
  WebKit              0x1b1eb2040  WebKit::NavigationState::NavigationClient::didFinishNavigation
  WebKit              0x1b20a7ff0  WebKit::WebPageProxy::didFinishLoadForFrame
  WebKit              0x1b2476ed8  WebKit::WebPageProxy::didReceiveMessage
  WebKit              0x1b258128c  IPC::MessageReceiverMap::dispatchMessage
  WebKit              0x1b20fb174  WebKit::WebProcessProxy::didReceiveMessage
  WebKit              0x1b257c228  IPC::Connection::dispatchMessage
  WebKit              0x1b257c674  IPC::Connection::dispatchIncomingMessages
  JavaScriptCore      0x1b2775df0  WTF::RunLoop::performWork
  JavaScriptCore      0x1b2776cc0  WTF::RunLoop::performWork
  CoreFoundation      0x19ccb90ac  <redacted>
  CoreFoundation      0x19ccb8328  <redacted>

Given that the app-hanging detection triggered here, it certainly looks like a synchronizing wait is made as part of the executeJavaScript call.

[mcdurdin]

It is worth noting, though, that our Android app requires an internal JS queue that took us a while to get just right. It'd be nice if we could find a way to introduce a minor gap here or there to prevent hanging behavior that wouldn't require as much investment as that JS queue did.

I think this kind of change should be done in alpha -- changing from sync to async often leads to unexpected issues (often in weird places, too).