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

bug(android): getKeyboardInfo with invalid index: -1 #6703

Closed
sentry-io bot opened this issue Jun 4, 2022 · 25 comments · Fixed by #6704
Closed

bug(android): getKeyboardInfo with invalid index: -1 #6703

sentry-io bot opened this issue Jun 4, 2022 · 25 comments · Fixed by #6704

Comments

@sentry-io
Copy link

sentry-io bot commented Jun 4, 2022

Sentry Issue: KEYMAN-ANDROID-75

getKeyboardInfo with invalid index: -1

    at dalvik.system.VMStack.getThreadStackTrace(VMStack.java)
    at java.lang.Thread.getStackTrace(Thread.java:1736)
    at com.tavultesoft.kmea.util.KMLog.LogError(KMLog.java:39)
    at com.tavultesoft.kmea.data.KeyboardController.getKeyboardInfo(KeyboardController.java:170)
    at com.tavultesoft.kmea.KMManager.getCurrentKeyboardInfo(KMManager.java:1747)
    at com.keyman.android.SystemKeyboard.onStartInput(SystemKeyboard.java:142)
    at android.inputmethodservice.InputMethodService.doStartInput(InputMethodService.java:2433)
    at android.inputmethodservice.InputMethodService$InputMethodImpl.startInput(InputMethodService.java:652)
    at android.inputmethodservice.InputMethodService$InputMethodImpl.dispatchStartInputWithToken(InputMethodService.java:688)
    at android.inputmethodservice.IInputMethodWrapper.executeMessage(IInputMethodWrapper.java:199)
    at com.android.internal.os.HandlerCaller$MyHandler.handleMessage(HandlerCaller.java:44)
    at android.os.Handler.dispatchMessage(Handler.java:106)
    at android.os.Looper.loop(Looper.java:257)
    at android.app.ActivityThread.main(ActivityThread.java:8192)
    at java.lang.reflect.Method.invoke(Method.java)
    at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:626)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1015)
@mcdurdin mcdurdin added this to the A16S3 milestone Jun 4, 2022
mcdurdin added a commit that referenced this issue Jun 4, 2022
This fixes crash reported as #6703. This issue was first reported in
14.0.282-stable. I have done a careful review of changes in 14.0.282
(and 14.0.281) but have been unable to find any changes that could have
bearing on this.

The basic issue is that there appears to be some circumstances where
`KMManager` thinks that it has a keyboard loaded (ref
`SystemKeyboardLoaded` variable), but `KMKeyboard.currentKeyboard` is
still `null`.

The crash has been reported for only a very small set of users, 119 at
time of fix, but average reports per user is over 100. As is usual with
this type of thing, a small fraction of those users are reporting the
majority of crashes. I have not found any real commonality across the
error reports -- they are geographically dispersed, across multiple
device types and Android versions.

Note that this addresses the error at hand but as I am unable to
reproduce the issue, does not necessarily address the root problem, so
there may still be other issues reported even after this is fixed.

A longer-term refactor would eliminate `SystemKeyboardLoaded` because
from what I can tell, we should always be able to determine that from
the state of `KMKeyboard.currentKeyboard`. However, the state
entanglement is a lot deeper than just those two variables, with cross
references to keyboard indexes between `KMManager` and `KMKeyboard`
which need to be resolved (`KMKeyboard` should *never* refer to
`KMManager`).
@mcdurdin mcdurdin linked a pull request Jun 4, 2022 that will close this issue
mcdurdin added a commit that referenced this issue Jun 4, 2022
This fixes crash reported as #6703. This issue was first reported in
14.0.282-stable. I have done a careful review of changes in 14.0.282
(and 14.0.281) but have been unable to find any changes that could have
bearing on this.

The basic issue is that there appears to be some circumstances where
`KMManager` thinks that it has a keyboard loaded (ref
`SystemKeyboardLoaded` variable), but `KMKeyboard.currentKeyboard` is
still `null`.

The crash has been reported for only a very small set of users, 119 at
time of fix, but average reports per user is over 100. As is usual with
this type of thing, a small fraction of those users are reporting the
majority of crashes. I have not found any real commonality across the
error reports -- they are geographically dispersed, across multiple
device types and Android versions.

Note that this addresses the error at hand but as I am unable to
reproduce the issue, does not necessarily address the root problem, so
there may still be other issues reported even after this is fixed.

A longer-term refactor would eliminate `SystemKeyboardLoaded` because
from what I can tell, we should always be able to determine that from
the state of `KMKeyboard.currentKeyboard`. However, the state
entanglement is a lot deeper than just those two variables, with cross
references to keyboard indexes between `KMManager` and `KMKeyboard`
which need to be resolved (`KMKeyboard` should *never* refer to
`KMManager`).
@jahorton
Copy link
Contributor

jahorton commented Jun 7, 2022

Reference for part of that call stack:

public static Keyboard getCurrentKeyboardInfo(Context context) {
int index = getCurrentKeyboardIndex(context);
return KeyboardController.getInstance().getKeyboardInfo(index);
}

Upon initial digging, it's pretty clear that index = -1 in this case. After all...

/**
* Return the keyboard info at index
* @param index - int
* @return Keyboard
*/
public Keyboard getKeyboardInfo(int index) {
if (!isInitialized) {
KMLog.LogError(TAG, "getKeyboardInfo while KeyboardController() not initialized");
return null;
} else if (index < 0) {
KMLog.LogError(TAG, "getKeyboardInfo with invalid index: " + index);
return null;
}

So yeah. Definitely a value of -1. For whatever reason, getCurrentKeyboardInfo is clearly operating under the assumption that a valid index will be returned, but it's not happening.

My current running theory: if there is no current keyboard somehow, null won't show up in the keyboards array and thus results in the index of -1. Whether or not I'm wrong... clearly we need some sort of fallback behavior here, likely to select the first index.

Part of why: for the frame before it in the call-stack...

/**
* This is the main point where we do our initialization of the input method
* to begin operating on an application. At this point we have been
* bound to the client, and are now receiving all of the detailed information
* about the target of our edits.
*/
@Override
public void onStartInput(EditorInfo attribute, boolean restarting) {
attribute.imeOptions |= EditorInfo.IME_FLAG_NO_EXTRACT_UI | EditorInfo.IME_FLAG_NO_FULLSCREEN;
super.onStartInput(attribute, restarting);
KMManager.onStartInput(attribute, restarting);
KMManager.resetContext(KeyboardType.KEYBOARD_TYPE_SYSTEM);
// Select numeric layer if applicable
int inputType = attribute.inputType;
if (((inputType & InputType.TYPE_MASK_CLASS) == InputType.TYPE_CLASS_NUMBER) ||
((inputType & InputType.TYPE_MASK_CLASS) == InputType.TYPE_CLASS_PHONE)) {
KMManager.setNumericLayer(KeyboardType.KEYBOARD_TYPE_SYSTEM);
}
// Temporarily disable predictions if entering a hidden password field
KMManager.setMayPredictOverride(inputType);
if (KMManager.getMayPredictOverride()) {
KMManager.setBannerOptions(false);
} else if (KMManager.isKeyboardLoaded(KeyboardType.KEYBOARD_TYPE_SYSTEM)){
// Check if predictions needs to be re-enabled per Settings preference
Context appContext = getApplicationContext();
Keyboard kbInfo = KMManager.getCurrentKeyboardInfo(appContext);
if (kbInfo != null) {
String langId = kbInfo.getLanguageID();
SharedPreferences prefs = appContext.getSharedPreferences(appContext.getString(R.string.kma_prefs_name), Context.MODE_PRIVATE);
boolean mayPredict = prefs.getBoolean(KMManager.getLanguagePredictionPreferenceKey(langId), true);
KMManager.setBannerOptions(mayPredict);
}
}

So, this is happening when the system keyboard is getting loaded for the first time, during initialization. It's possible that it's simply too early in the process for the active keyboard to have been set. Fortunately... the code asking about the keyboard's info just passively skips the affected operation set. This makes me wonder if we have any issues about the prediction banner acting funny or going missing on the initial load of the system keyboard... but I don't see evidence of such an issue in the repo.

@mcdurdin
Copy link
Member

mcdurdin commented Jun 8, 2022

Fortunately... the code asking about the keyboard's info just passively skips the affected operation set.

Except that this crashes the app.

Please see the fix I've already written in #6704.

@jahorton
Copy link
Contributor

jahorton commented Jun 8, 2022

Please see the fix I've already written in #6704.

From said fix's description:

Note that this addresses the error at hand but as I am unable to reproduce the issue, does not necessarily address the root problem, so there may still be other issues reported even after this is fixed.

I found myself with some extra time to try looking into the root problem, so I did a little digging. I'd rather find the source if it's easy enough to do so.

@jahorton
Copy link
Contributor

jahorton commented Jun 8, 2022

Except that this crashes the app.

Are we sure about this? Granted, the Sentry logs for Android don't exactly make clear when the app or keyboard is truly crashed or if it was a logged error, but...

/**
* Return the keyboard info at index
* @param index - int
* @return Keyboard
*/
public Keyboard getKeyboardInfo(int index) {
if (!isInitialized) {
KMLog.LogError(TAG, "getKeyboardInfo while KeyboardController() not initialized");
return null;
} else if (index < 0) {
KMLog.LogError(TAG, "getKeyboardInfo with invalid index: " + index);
return null;
}

Note line 170 - that's quite clearly a logged error, with no exception thrown. Given that there's no pressing issue in the repo or on the Community site we can point to as an analogue, I think it's just that - a logged error. We should know something if it were an egregious crash of the keyboard.

For verification, here's the definition of KMLog.LogError:

/**
* Utility to log error and send to Sentry
* @param tag String of the caller
* @param msg String of the error message
*/
public static void LogError(String tag, String msg) {
if (msg != null && !msg.isEmpty()) {
Log.e(tag, msg);
if (Sentry.isEnabled()) {
Sentry.captureMessage(msg, SentryLevel.ERROR);
}
}
}

@jahorton
Copy link
Contributor

jahorton commented Jun 8, 2022

Then again, maybe it does make it obvious. I just didn't notice how until now.

image

Different Sentry log, of course, but I think it's clear that that one is a crash.

@jahorton
Copy link
Contributor

jahorton commented Jun 8, 2022

tl;dr: I believe we have a race condition on our hands.

(Further investigation, as of #6703 (comment), has all but disproven this.)


Further investigation - this is the expected codepath for system keyboard's initialization of the initial keyboard:

private void pageLoaded(WebView view, String url) {
Log.d("KMEA", "pageLoaded: [system] " + url);
if (SystemKeyboard == null) {
KMLog.LogError(TAG, "pageLoaded and SystemKeyboard null");
return;
}
SystemKeyboard.keyboardSet = false;
currentLexicalModel = null;
if (url.startsWith("file:")) { // TODO: is this test necessary?
SystemKeyboardLoaded = true;
SharedPreferences prefs = context.getSharedPreferences(context.getString(R.string.kma_prefs_name), Context.MODE_PRIVATE);
int index = prefs.getInt(KMManager.KMKey_UserKeyboardIndex, 0);
if (index < 0) {
index = 0;
}
Keyboard keyboardInfo = KMManager.getKeyboardInfo(context, index);
String langId = null;
if (keyboardInfo != null) {
langId = keyboardInfo.getLanguageID();
SystemKeyboard.setKeyboard(keyboardInfo);
} else {

Note this section in particular:

Keyboard keyboardInfo = KMManager.getKeyboardInfo(context, index);
String langId = null;
if (keyboardInfo != null) {
langId = keyboardInfo.getLanguageID();
SystemKeyboard.setKeyboard(keyboardInfo);
} else {

This code is called whenever the keyboard host page has finished loading.


Note how this, by its nature, is almost certainly an asynchronous callback from the WebView; I know this to be the case for the iOS app. Likewise, the true entrypoint for the system keyboard is onCreate, with onStartInput being called a little later by the system.

So, my guess is that we have two asynchronous methods operating in parallel, with one of them expected to finish before the other. But... is there anything guaranteeing this? Is this a race condition?

@jahorton
Copy link
Contributor

jahorton commented Jun 8, 2022

As an aside, an interesting view from the Sentry issue:

image

There are a number of users with single-digit event counts on the following (tabulated) page.

@jahorton
Copy link
Contributor

jahorton commented Jun 8, 2022

Continuing the investigation, onCreate calls Manager.initialize(), which in turn calls KeyboardController.initialize(). This call is not wrapped in a conditional, so the call will always chain through. That, in turn, marks the KeyboardController as initialized, as needed here:

/**
* Return the keyboard info at index
* @param index - int
* @return Keyboard
*/
public Keyboard getKeyboardInfo(int index) {
if (!isInitialized) {
KMLog.LogError(TAG, "getKeyboardInfo while KeyboardController() not initialized");
return null;
} else if (index < 0) {
KMLog.LogError(TAG, "getKeyboardInfo with invalid index: " + index);
return null;
}

However, that same function... doesn't actually initialize the field for tracking the active keyboard. It certainly loads all data for installed keyboards, I'll give you that. But... there's no call to set the keyboard's currentKeyboard field there. Largely because it's a different class, of course - the KMKeyboard class tracks that field, not KeyboardController.

KeyboardController.initialize() definition, for reference.

public synchronized void initialize(Context context) {
if (isInitialized) {
Log.w(TAG, "initialize called multiple times");
return;
}
File keyboards_dat = new File(context.getDir("userdata", Context.MODE_PRIVATE),
KMManager.KMFilename_KeyboardsList);
File keyboards_json = new File(context.getDir("userdata", Context.MODE_PRIVATE),
KMFilename_Installed_KeyboardsList);
if (list == null) {
list = new ArrayList<Keyboard>();
if (keyboards_dat.exists() && !keyboards_json.exists()) {
try {
// Migrate installed_keyboards.dat to keyboards_list.json
ObjectInputStream inputStream = new ObjectInputStream(new FileInputStream(keyboards_dat));
ArrayList<HashMap<String, String>> dat_list = (ArrayList<HashMap<String, String>>) inputStream.readObject();
inputStream.close();
list = KMManager.updateOldKeyboardsList(context, dat_list);
} catch (Exception e) {
KMLog.LogException(TAG, "Exception migrating installed_keyboards.dat", e);
list.add(Keyboard.getDefaultKeyboard(context));
}
} else if (keyboards_json.exists()) {
JSONArray json_list = null;
try {
// Get installed keyboards from keyboards_list.json
JSONParser jsonParser = new JSONParser();
json_list = jsonParser.getJSONObjectFromFile(keyboards_json, JSONArray.class);
if (json_list != null) {
// Can't foreach JSONArray
for (int i=0; i<json_list.length(); i++) {
JSONObject o = json_list.getJSONObject(i);
if (o != null) {
Keyboard k = new Keyboard(o);
list.add(k);
}
}
} else {
KMLog.LogError(TAG, KMFilename_Installed_KeyboardsList + " is null");
}
} catch (Exception e) {
KMLog.LogExceptionWithData(TAG, "Exception reading " + KMFilename_Installed_KeyboardsList,
KMFilename_Installed_KeyboardsList, json_list, e);
list.add(Keyboard.getDefaultKeyboard(context));
}
} else {
// No installed keyboards lists
// 3rd-party OEM may not have sil_euro_latin, so don't assign a default keyboard
//list.add(Keyboard.getDefaultKeyboard(context));
Log.w(TAG, "initialize with no default keyboard");
}
// We'd prefer not to overwrite a file if it exists
if (!keyboards_json.exists() && list != null && list.size() > 0) {
save(context);
// Now we can delete legacy keyboards list
if (keyboards_dat.exists()) {
keyboards_dat.delete();
}
}
}
isInitialized = true;
}

@jahorton
Copy link
Contributor

jahorton commented Jun 9, 2022

An important note for any potential reproduction attempts:

  • When you set Keyman as the default system keyboard from within the app, the system will immediately initialize the keyboard in the background, long before it has the chance to be displayed.
    • So... good luck with a direct reproduction when using a default "Debug" launch of the app.
  • If you power the device off then back on again...
    1. You'll be presented with the device's originally-shipped default keyboard on initial log in. (The OS does warn up front about this.)
    2. Once the boot-up operation completes, lock the device.
    3. When you attempt to unlock it again and go to put in the password, then the system will initialize the Keyman system keyboard. This is the best way to affect the timing of the moving parts mentioned above.

Alternatively... just don't set it as the default system keyboard from the app.

  1. With the app terminated...
  2. Go to the device's Settings > System > Languages > Languages & Input > Virtual Keyboard > Manage Keyboards
  3. If Keyman is currently toggled on, toggle it off.
  4. Then toggle it on.

This will ensure that the manufacturer-default keyboard has a globe key for keyboard swapping, allowing you to swap to the Keyman system keyboard. The first time you do so, with the app currently terminated, you'll be able to test how the system keyboard initializes when set to be immediately active.

... not that I've actually achieved a full repro yet; I still haven't reproduced the actual log message when testing against beta. I have been able to delay the host page's init, at least, and that gave me enough info to discern the information above.

That said... there are logs on Sentry that strongly suggest that a few select users have a far more consistent trigger; their installations will produce log messages at or over 3 times a minute sometimes. It's hard to say what that is without further investigation, though I'm pretty sure that the rate above indicates that it's not happening from just fresh-boot loads of the keyboard.

@jahorton
Copy link
Contributor

jahorton commented Jun 10, 2022

It's taken a few passes and some serious debug-logging, but I'm starting to make better sense of some of the codepaths involved now...

private void pageLoaded(WebView view, String url) {
Log.d("KMEA", "pageLoaded: [system] " + url);
if (SystemKeyboard == null) {
KMLog.LogError(TAG, "pageLoaded and SystemKeyboard null");
return;
}
SystemKeyboard.keyboardSet = false;
currentLexicalModel = null;
if (url.startsWith("file:")) { // TODO: is this test necessary?
SystemKeyboardLoaded = true;

Line 2471 there is the only line in the codebase that sets SystemKeyboardLoaded = true. This condition is absolutely necessary for a critical condition seen here:

public void onStartInput(EditorInfo attribute, boolean restarting) {
attribute.imeOptions |= EditorInfo.IME_FLAG_NO_EXTRACT_UI | EditorInfo.IME_FLAG_NO_FULLSCREEN;
super.onStartInput(attribute, restarting);
KMManager.onStartInput(attribute, restarting);
KMManager.resetContext(KeyboardType.KEYBOARD_TYPE_SYSTEM);
// Temporarily disable predictions on certain fields (e.g. hidden password field or numeric)
int inputType = attribute.inputType;
KMManager.setMayPredictOverride(inputType);
if (KMManager.getMayPredictOverride()) {
KMManager.setBannerOptions(false);
} else if (KMManager.isKeyboardLoaded(KeyboardType.KEYBOARD_TYPE_SYSTEM)){
// Check if predictions needs to be re-enabled per Settings preference
Context appContext = getApplicationContext();
Keyboard kbInfo = KMManager.getCurrentKeyboardInfo(appContext);

Line 142 there...

} else if (KMManager.isKeyboardLoaded(KeyboardType.KEYBOARD_TYPE_SYSTEM)){

is essentially

} else if (SystemKeyboardLoaded) {

Therefore... the host page must have loaded for us to reach line 145...

Keyboard kbInfo = KMManager.getCurrentKeyboardInfo(appContext);

which is the line seen in the Sentry logs' call stack.

But... is there anything guaranteeing this? Is this a race condition?

Well, I found the "anything": it's that SystemKeyboardLoaded variable. So either we have multiple threads in operation... or there is no race condition after all. Which then re-raises the question of where this -1 might be coming from.

And after a bit more investigation... all lines seen above appear to be executed on the same thread, according to my investigation via Android Studio's debugger. Huh.

@jahorton
Copy link
Contributor

Oh, and other good news - where I'd thought we might have a scenario disrespecting 'privacy mode' for password entry, the same investigation leading to the previous comment's notes has also demonstrated that such a scenario (fortunately) doesn't exist. The active keyboard isn't even referenced when the "prediction override" toggle is set. It just took a number of passes through the codebase to recognize that toggle's related logic for what it was.

@jahorton
Copy link
Contributor

jahorton commented Jun 10, 2022

OK, so I've been trying from a new angle. I'm using a couple of recently discovered bugs to try to repro this one.

By using both of these bugs, it's possible to get the app into a state best represented by the following screenshots:

Screen Shot 2022-06-10 at 3 07 53 PM

Screen Shot 2022-06-10 at 3 08 08 PM

I can safely return from Settings without the keyboard resetting.

It is possible to leave English installed (sil_euro_latin) instead of Pinyin (sil_cameroon_azerty), which would actually be an even more pronounced difference.

Even then, for our current scenario... by the way our mobile apps work internally, the displayed keyboard uses a different keyboard-language pairing than the only one currently installed. Therefore, if my understanding is correct, the currently active keyboard will not be found in the app's list of installed keyboards. (Yes, even if it's using the same keyboard ID.) From here, this may take some exploration, but this should be a good foundation, usable somehow to get at least one form of repro for this bug.

Attempts:

  • Using the system menu approach to activate the system keyboard... it loads the lone remaining installation (for Pinyin, as seen in Settings) without issue or notable log message.
    • Likely because there was a semblance of a prior keyboard index, even if technically for a different language pairing.
    • When initializing, it operates by index first. So, it would seem that there is an index value once the state above is reached.
      • ...is there a way to clear that while maintaining the state? If one can be found, a retry may be worth it.
  • Force-closing, then relaunching the app (after having activated the system keyboard)
    • Same result as with the previous attempt... likely for the same reason.
  • Using the in-app keyboard picker, then backing out.
    • The keyboard reset here, loading for the Pinyin language. I didn't notice any significant error logs at the time.

It's also possible that I should try deleting both the installed pairings and just leave the default EuroLatin in place, as I can do so while maintaining the Baka installation initially. That said, some of the failsafes in the code attempt to fall back on the default keyboard; I was hoping to get far enough to trip over even those aspects, as it is possible to uninstall the default keyboard from the app.

@mcdurdin mcdurdin modified the milestones: A16S3, A16S4 Jun 11, 2022
@jahorton
Copy link
Contributor

  • Using the system menu approach to activate the system keyboard... it loads the lone remaining installation (for Pinyin, as seen in Settings) without issue or notable log message.
    • Likely because there was a semblance of a prior keyboard index, even if technically for a different language pairing.
    • When initializing, it operates by index first. So, it would seem that there is an index value once the state above is reached.

Well... turns out this particular avenue doesn't appear to be viable for a repro attempt.

private void pageLoaded(WebView view, String url) {

} else {
// Revert to default (index 0) or fallback keyboard
keyboardInfo = KMManager.getKeyboardInfo(context, 0);
if (keyboardInfo == null) {
KMLog.LogError(TAG, "No keyboards installed. Reverting to fallback");
keyboardInfo = KMManager.getDefaultKeyboard(context);
}
if (keyboardInfo != null) {
langId = keyboardInfo.getLanguageID();
SystemKeyboard.setKeyboard(keyboardInfo);
}

With the repro attempt steps listed above (using other bugs to try reproducing this one), we actually reach line 2490 there; the system defaults back to index 0 when the originally-specified index returned no keyboard info. But, this occurs before any call that would result in this issue's error... ensuring that afterward, a valid index exists.

mcdurdin added a commit that referenced this issue Jun 14, 2022
…-logging

chore(android): adds diagnostic logging to assist a fix for #6703
@mcdurdin mcdurdin modified the milestones: A16S4, A16S5 Jun 24, 2022
@mcdurdin mcdurdin modified the milestones: A16S7, A16S8 Aug 7, 2022
@mcdurdin mcdurdin modified the milestones: A16S8, A16S9 Aug 22, 2022
@mcdurdin mcdurdin modified the milestones: A16S9, A16S10 Sep 5, 2022
@mcdurdin mcdurdin modified the milestones: A16S10, A16S11 Sep 17, 2022
@mcdurdin mcdurdin modified the milestones: A16S11, A16S12 Oct 2, 2022
@jahorton
Copy link
Contributor

jahorton commented Oct 5, 2022

So, a minor update, given the logging added in #6761:

image

That's almost an absolutely perfect correlation between the two error-log events.

@jahorton
Copy link
Contributor

jahorton commented Oct 5, 2022

For that to happen, it's worth noting that the basic getKeyboardIndex preconditions are clearly met:

public int getKeyboardIndex(String packageID, String keyboardID, String languageID) {
int index = INDEX_NOT_FOUND;
if (!isInitialized || list == null) {
KMLog.LogError(TAG, "getIndexOfKey while KeyboardController() not initialized");
return index;
}
if (packageID == null || packageID.isEmpty() || keyboardID == null || keyboardID.isEmpty()) {
return index;
}
boolean matchLanguage = (languageID != null && !languageID.isEmpty());
synchronized (list) {
for (int i=0; i<list.size(); i++) {
Keyboard k = list.get(i);
if (k.getPackageID().equals(packageID) && k.getKeyboardID().equals(keyboardID)) {
if ( (matchLanguage && BCP47.languageEquals(k.getLanguageID(), languageID)) ||
!matchLanguage ) {
return i;
}
}
}
}
Log.w(TAG, "getKeyboardIndex failed for packageID: " + packageID +
", keyboardID: " + keyboardID + ", languageID: " + languageID);
return index;
}

Lines 225, 229, and 248 all return -1 if reached, but only the last of the 3 emits the getKeyboardIndex failed ... log / Sentry event. Yet, we're clearly making it past this block:

public int getKeyboardIndex(String packageID, String keyboardID, String languageID) {
int index = INDEX_NOT_FOUND;
if (!isInitialized || list == null) {
KMLog.LogError(TAG, "getIndexOfKey while KeyboardController() not initialized");
return index;
}
if (packageID == null || packageID.isEmpty() || keyboardID == null || keyboardID.isEmpty()) {
return index;
}


I point all of the above details out because of how the two Sentry events relate:

public static Keyboard getCurrentKeyboardInfo(Context context) {
int index = getCurrentKeyboardIndex(context);
if(index < 0) {
// As of 15.0-beta and 15.0-stable, this only appears to occur when
// #6703 would trigger. This logging may help us better identify the
// root cause.
String key = KMKeyboard.currentKeyboard();
// Even if it's null, it's still a notable error. This function shouldn't
// be reachable in execution (15.0) at a time this variable would be set to `null`.
KMLog.LogError(TAG, "Failed getCurrentKeyboardIndex check for keyboard: " + key);
return null;
}
return KeyboardController.getInstance().getKeyboardInfo(index);
}

Any of the three lines noted above (that return the -1 value) would meet the condition for this block's line 2005. Yet it's nigh-exclusively the last option that occurs. (I'm not sifting through 3000+ event reports to verify that there's literally no case where the other two lines occur.)


So, what does that tell us?

if (!isInitialized || list == null) {
KMLog.LogError(TAG, "getIndexOfKey while KeyboardController() not initialized");
return index;
}

Passing the block above means that:

  1. The class has initialized.
  2. The class property/field list holds a valid reference - there is a live array.

synchronized (list) {
for (int i=0; i<list.size(); i++) {
Keyboard k = list.get(i);
if (k.getPackageID().equals(packageID) && k.getKeyboardID().equals(keyboardID)) {
if ( (matchLanguage && BCP47.languageEquals(k.getLanguageID(), languageID)) ||
!matchLanguage ) {
return i;
}
}
}
}

Again, list has a live, non-null instance - we'd have an exception from line 235 otherwise. But, for whatever reason, the list does not contain (or, "no longer contains"?) the keyboard being requested.

In the logs, I see that this sometimes arises when the app is resumed after being paused, and sometimes occurs when the device "wakes up" after having been locked / "put to sleep".

@jahorton
Copy link
Contributor

jahorton commented Oct 5, 2022

Just a thought here, but...

if (k.getPackageID().equals(packageID) && k.getKeyboardID().equals(keyboardID)) {

Is it possible that case sensitivity is at play here? This code, as written, does assume that case sensitivity is not a factor - that some form of casing standardization has already been applied. And we've run into situations that arose from a lack of enforcement in other areas. I remember it being a factor in #6733.

Looking into the code a bit, I can find

public String getPackageID(File path) {
String filename = path.getName().toLowerCase();

That suggests that the first half of the condition is probably safe. But for the second half... I don't see a clear, definitive answer.

I guess there's also

if ( (matchLanguage && BCP47.languageEquals(k.getLanguageID(), languageID)) ||

to look into as well in this regard, though I think that case is sufficiently handled:

public static boolean languageEquals(String id1, String id2) {
if (id1 == null || id2 == null) {
return false;
}
return id1.equalsIgnoreCase(id2);
}

@jahorton
Copy link
Contributor

jahorton commented Oct 5, 2022

Following up on the #6732 angle (which was kinda tied to #6733)...

The PR that fixed #6732 - that is, #7239 - had this to say early on in its description:

Currently, if a keyboard package installation involves selecting language(s), the default language tag isn't being standardized (lower-cased). This causes the temporary language list to contain duplicates of the same language (e.g. bkc-latn and bkc-Latn).

So... are we sure that this only ever affected the temporary list and never the permanent one?

Is it possible that after fixing previous case-insensitivity bugs like this... that we never actually re-validated the language list and/or prior keyboard setting? If user settings weren't updated to ensure standardized casing, and thus unstandardized forms of the keyboard ID live on for a select few devices & users... perhaps that could be our underlying cause? It is kinda noteworthy just how few users this bug affects, especially given the frequency at which it affects the users who do experience it.

Worth noticing: the core Keyboard object does not enforce a standardized casing for the keyboard ID:

public Keyboard(JSONObject languageJSON, JSONObject keyboardJSON) {
try {
this.packageID = keyboardJSON.optString(KMManager.KMKey_PackageID, KMManager.KMDefault_UndefinedPackageID);
this.resourceID = keyboardJSON.getString(KMManager.KMKey_ID);
this.resourceName = keyboardJSON.getString(KMManager.KMKey_Name);


If this line of thinking is correct... maybe just tweaking

if (k.getPackageID().equals(packageID) && k.getKeyboardID().equals(keyboardID)) {

to use equalsIgnoreCase() instead of equals() would be enough? We aren't getting outright crashes from this, at least.

Of course, it's probably best to fully patch everything up, lest we have this assumption be invalidated somewhere else in the future again by mistake.

@darcywong00: thoughts?

While I personally am not 100% convinced on this... there's that old, famous maxim about eliminating the impossible:

Once you eliminate the impossible, whatever remains, no matter how improbable, must be the truth.

Arthur Conan Doyle

I can't say that literally everything impossible has been eliminated, but this is the first angle of "possible" I've been able to find for this issue given all the other things we know thus far.

@jahorton
Copy link
Contributor

jahorton commented Oct 27, 2022

Found something interesting while analyzing Sentry error reports today:

image

https://sentry.io/share/issue/bed2060d7ba24e44854b8f70078d6229/

We have proof of at least one wild mixed-case scenario, unless my interpretation's off somehow?

Either way, this is clearly within the Keyman for Android app (or engine), and the language ID lasted long enough to be passed off to KMW, as this error came from the Web side.

@jahorton
Copy link
Contributor

jahorton commented Oct 27, 2022

From #7415 (comment)

I think it's unlikely that the keyboardid or packageid (aka keyboard and package filenames) would have mixed case [...] but all keyboards and packages hosted on Keyman Cloud will have lower case IDs, and the compiler complains about mixed case for these ids.

... I can't help but notice now, especially given the odd frequency of related error logs talking about sil_euro_latin... from the fv_all package... that we may need to double-check what guards are in place for installations from ad-hoc (user-to-user .kmp transfer) cases.

@mcdurdin
Copy link
Member

I'm confused -- why? sil_euro_latin and fv_all are both lower case.

@jahorton
Copy link
Contributor

Because of the language IDs in the package, not the package IDs.

@mcdurdin
Copy link
Member

Yes, language ID comparisons should always have been case-insensitive.

@mcdurdin mcdurdin modified the milestones: A16S13, B16S1 Oct 31, 2022
@mcdurdin mcdurdin modified the milestones: B16S1, B16S2 Nov 11, 2022
@darcywong00
Copy link
Contributor

I think this can be closed now.
getKeyboardInfo correctly returns the invalid index -1 when generating the language list for "Add languages to installed keyboard".

The languages on that list are not currently installed.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Development

Successfully merging a pull request may close this issue.

3 participants