"KeyStoreException: BKS not found" during log in

[robovoice1]

Describe the bug
A clear and concise description of what the bug is.
After the update login is not possible any more

To Reproduce
Steps to reproduce the behavior:

1. Start the parchli app
2. Get the error screen (please see screenshot)

Expected behavior
A clear and concise description of what you expected to happen.

Login possible with updated Pachli app

Screenshots or video
If applicable, please add screenshots or video to help explain your problem.

Versions
Please include the version of Pachli and Android you are using, and the software version your server is using. Find this on the Pachli "About" screen.
latest 2.9.0 Pachli (github release)

Google Pixel 6 pro
Android15
GrapheneOs 2024112700

Additional context
Add any other context about the problem here.

type: logcat
osVersion: google/raven/raven:15/AP3A.241105.007/2024112700:user/release-keys
package: app.pachli:24, targetSdk 34
buffers: main,system,crash,events,kernel
level: error

--------- beginning of crash
11-28 17:01:14.627  4694  4694 E AndroidRuntime: FATAL EXCEPTION: main
11-28 17:01:14.627  4694  4694 E AndroidRuntime: Process: app.pachli, PID: 4694
11-28 17:01:14.627  4694  4694 E AndroidRuntime: java.lang.IndexOutOfBoundsException: Empty list doesn't contain element at index 0.
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at kotlin.collections.EmptyList.get(SourceFile:22)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at app.pachli.MainActivity.u(SourceFile:44)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.activity.ComponentActivity.onMenuItemSelected(SourceFile:32)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.fragment.app.FragmentActivity.onMenuItemSelected(SourceFile:1)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.appcompat.app.AppCompatActivity.onMenuItemSelected(SourceFile:1)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.appcompat.view.WindowCallbackWrapper.onMenuItemSelected(SourceFile:3)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.appcompat.app.ToolbarActionBar$2.onMenuItemClick(SourceFile:6)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.appcompat.widget.ActionMenuView$MenuBuilderCallback.a(SourceFile:50)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.appcompat.view.menu.MenuBuilder.e(SourceFile:5)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.appcompat.view.menu.MenuBuilder.q(SourceFile:29)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at androidx.appcompat.view.menu.MenuPopup.onItemClick(SourceFile:39)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.widget.AdapterView.performItemClick(AdapterView.java:330)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.widget.AbsListView.performItemClick(AbsListView.java:1273)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.widget.AbsListView$PerformClick.run(AbsListView.java:3286)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.widget.AbsListView$3.run(AbsListView.java:4252)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.os.Handler.handleCallback(Handler.java:959)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.os.Handler.dispatchMessage(Handler.java:100)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.os.Looper.loopOnce(Looper.java:232)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.os.Looper.loop(Looper.java:317)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at android.app.ActivityThread.main(ActivityThread.java:8744)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at java.lang.reflect.Method.invoke(Native Method)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:580)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at com.android.internal.os.ExecInit.main(ExecInit.java:50)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at com.android.internal.os.RuntimeInit.nativeFinishInit(Native Method)
11-28 17:01:14.627  4694  4694 E AndroidRuntime: 	at com.android.internal.os.RuntimeInit.main(RuntimeInit.java:369)
--------- beginning of main
11-28 17:28:39.293  8338  8338 E app.pachli: Not starting debugger since process cannot load the jdwp agent.
11-28 17:28:39.363  8338  8338 E cutils-trace: Error opening trace file: No such file or directory (2)
11-28 17:28:39.453  8338  8338 E app.pachli: Unable to find pattern file or unable to map it for am
11-28 17:28:39.684  8338  8361 E cutils-trace: Error opening trace file: No such file or directory (2)

Affirmation
I have checked other issues for this project (open and closed) and I cannot find one that matches the problem I am reporting.
Yes

[robovoice1]

All of a sudden this works now as expected.
Closing 😃

[robovoice1]

closed

[turtlegarden]

I am experiencing the same issue, unsure if this issue should be reopened or not. I will wait for 3 days and see if the issue resolves itself with various tests, and if it does not I will ask for reopening / create a new issue.

[turtlegarden]

This issue persists. Because the app requires an account to load in the user interface, I cannot access any information further than version 2.9.0. I am running on a Pixel 6a, Android 15, November security update, November Google Play system update.

[turtlegarden]

Can we please re-open this issue?

[robovoice1]

reopened
and thanks for feedback @turtlegarden

I am using Parchli app 2.9.0 as expected.
Google Pixel 6pro (raven)
Android 15 - GrapheneOS 2024120900
full 2024-12-05 security patch level based on Android15 QPR1
Google Play Store and G Services from latest alpha channel release

[nikclayton]

Please can you both let me know which servers you're using. I'll create test accounts to try and reproduce the issue.

[robovoice1]

social.tchncs.de

[turtlegarden]

gts.turtle.garden (GoToSocial 0.17.1)

[ralencode]

samsung galaxy note 10 (d1) /e/os 2.5 android 13. default microg, pachli installed from fdroid and i believe should not depend on g**gle
currently logged in server was mastodon.ml. also have social.linux.pizza account in the app
tusky 26 worked tho, few minutes later pachli started working by itself

[robovoice1]

Since today i cannot login with Pachli (again) Tusky works.
Only Remove Tab or Manage Tabs are selectable, but gives me this crash log

type: crash
osVersion: google/raven/raven:15/AP4A.241205.013/2024120900:user/release-keys
package: app.pachli:24, targetSdk 34
process: app.pachli
processUptime: 3623 + 202 ms
installer: dev.imranr.obtainium

java.lang.IndexOutOfBoundsException: Empty list doesn't contain element at index 0.
	at kotlin.collections.EmptyList.get(SourceFile:22)
	at app.pachli.MainActivity.u(SourceFile:44)
	at androidx.activity.ComponentActivity.onMenuItemSelected(SourceFile:32)
	at androidx.fragment.app.FragmentActivity.onMenuItemSelected(SourceFile:1)
	at androidx.appcompat.app.AppCompatActivity.onMenuItemSelected(SourceFile:1)
	at androidx.appcompat.view.WindowCallbackWrapper.onMenuItemSelected(SourceFile:3)
	at androidx.appcompat.app.ToolbarActionBar$2.onMenuItemClick(SourceFile:6)
	at androidx.appcompat.widget.ActionMenuView$MenuBuilderCallback.a(SourceFile:50)
	at androidx.appcompat.view.menu.MenuBuilder.e(SourceFile:5)
	at androidx.appcompat.view.menu.MenuBuilder.q(SourceFile:29)
	at androidx.appcompat.view.menu.MenuPopup.onItemClick(SourceFile:39)
	at android.widget.AdapterView.performItemClick(AdapterView.java:330)
	at android.widget.AbsListView.performItemClick(AbsListView.java:1274)
	at android.widget.AbsListView$PerformClick.run(AbsListView.java:3287)
	at android.widget.AbsListView$3.run(AbsListView.java:4266)
	at android.os.Handler.handleCallback(Handler.java:991)
	at android.os.Handler.dispatchMessage(Handler.java:102)
	at android.os.Looper.loopOnce(Looper.java:232)
	at android.os.Looper.loop(Looper.java:317)
	at android.app.ActivityThread.main(ActivityThread.java:8826)
	at java.lang.reflect.Method.invoke(Native Method)
	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:591)
	at com.android.internal.os.ExecInit.main(ExecInit.java:50)
	at com.android.internal.os.RuntimeInit.nativeFinishInit(Native Method)
	at com.android.internal.os.RuntimeInit.main(RuntimeInit.java:369)

[nikclayton]

Thanks for the info. I thought maybe this might be specific to devices running Android forks, but @ralencode's device seems to be stock. It's very odd that this problem has started happening.

I've seen some suggestions online that this might be due to overaggressive stripping of the binary by Proguard, so I'm adjusting the rules to try and mitigate that. I'll have a Pachli Current version out later today with this change.

[nikclayton]

OK, it's not that. Because after making that change and deploying it I saw my first instance of the issue in an emulator connecting to mastodon.social. Hmm...

[nikclayton]

@robovoice1 Separately, #1179 is the fix for the crashes you've reported in this issue.

[nikclayton]

Folks, a few followup questions.

1. When you see this error, what happens if you tap the "Retry" button? In particular, does the second (or third...) attempt work, or does it stay stuck? If subsequent attempts work that suggests a race condition somewhere, which I'm not looking forward to tracking down...
2. When you see this error, what happens if you bring up the list of recent apps, swipe Pachli away, and then relaunch Pachli. Does the error happen again, or is it resolved?
3. @turtlegarden -- If you can reliably reproduce this on your server, can I get an account on it to test? Thanks

[robovoice1]

@nikclayton

1. stays stuck after tapping 10 times Retry and 10 times Cancel.
2. Error happen again (Screenshot1 message) BKS not found.
   Also after Force Stop and restarting the app.

[robovoice1]

After clearing cache and storage of pachli app i can login again 😃

[turtlegarden]

1. When you see this error, what happens if you tap the "Retry" button? In particular, does the second (or third...) attempt work, or does it stay stuck? If subsequent attempts work that suggests a race condition somewhere, which I'm not looking forward to tracking down...

It unfortunately repeats, whether I press Cancel or Retry.

2. When you see this error, what happens if you bring up the list of recent apps, swipe Pachli away, and then relaunch Pachli. Does the error happen again, or is it resolved?

The error happens again. It is possible to log in to Pachli, but the key seems to not be able to be loaded in again after relaunch.

3. (me) If you can reliably reproduce this on your server, can I get an account on it to test? Thanks

I will see if I can test it on a new test account first, as well as other servers, to see if this continues. Then, if I can confirm this, I'll reach out with further test account details.

[nikclayton]

This is very odd. I have a test account at social.tchncs.de and cannot reproduce the error there. The one time the error did occur to me in testing tapping "Retry" retried the request which succeeded.

I can see that this is triggered by one of the network requests that happens when logging in or switching accounts, but I'm not sure which one. #1181 will extend the error message and show the URL and request method that is used, in case there's any commonality there.

The two related libraries (bouncycastle and conscrypt) haven't had any changes in the last release.

Did these errors occur with earlier Pachli versions?

[nikclayton]

Hi folks.

If you're able to sideload an APK on to your device, can you give the one from the APK link at #1182 (comment) a try?

If it fixes the problem, great. If it doesn't then I'm considerably more perplexed.

[turtlegarden]

It seems to have removed the error popup, but it still does not load. When trying to manage tabs (the only action available), the following happens:

java.lang.IllegalStateException: Property pachliAccountId should be initialized before get.
	at kotlin.properties.NotNullVar.a(SourceFile:25)
	at app.pachli.MainActivity.B0(SourceFile:8)
	at app.pachli.MainActivity.u(SourceFile:76)
	at androidx.activity.ComponentActivity.onMenuItemSelected(SourceFile:32)
	at androidx.fragment.app.FragmentActivity.onMenuItemSelected(SourceFile:1)
	at androidx.appcompat.app.AppCompatActivity.onMenuItemSelected(SourceFile:1)
	at androidx.appcompat.view.WindowCallbackWrapper.onMenuItemSelected(SourceFile:3)
	at androidx.appcompat.app.ToolbarActionBar$2.onMenuItemClick(SourceFile:6)
	at androidx.appcompat.widget.ActionMenuView$MenuBuilderCallback.a(SourceFile:50)
	at androidx.appcompat.view.menu.MenuBuilder.e(SourceFile:5)
	at androidx.appcompat.view.menu.MenuBuilder.q(SourceFile:29)
	at androidx.appcompat.view.menu.MenuPopup.onItemClick(SourceFile:39)
	at android.widget.AdapterView.performItemClick(AdapterView.java:330)
	at android.widget.AbsListView.performItemClick(AbsListView.java:1274)
	at android.widget.AbsListView$PerformClick.run(AbsListView.java:3287)
	at android.widget.AbsListView$3.run(AbsListView.java:4266)
	at android.os.Handler.handleCallback(Handler.java:991)
	at android.os.Handler.dispatchMessage(Handler.java:102)
	at android.os.Looper.loopOnce(Looper.java:232)
	at android.os.Looper.loop(Looper.java:317)
	at android.app.ActivityThread.main(ActivityThread.java:8842)
	at java.lang.reflect.Method.invoke(Native Method)
	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:591)
	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:871)

This time, I was able to extract the error. OS information is as follows:

PHONE_MODEL=Pixel 6a
BRAND=google
PRODUCT=bluejay_beta
ANDROID_VERSION=15
BUILD=BOARD=bluejay

This behaviour does not occur on my alternate account on a Mastodon instance. I'm updating the server software to see if this was a "bad server" thing.

[turtlegarden]

Intriguing. It seems to load after all on the new APK. I will need to test this more. (So yes, it fixed it for me!)

[turtlegarden]

I think it fixed the error! But even so, it would be nice if Pachli had a better loading UI (that wouldn't be blank before account info is loaded in). Right now it just looks like this for a few seconds:

[nikclayton]

Thanks for reporting that the change appears to have helped.

Some technical backstory on the UI being blank while loading.

The new anti-abuse features need to know which accounts you follow (so notifications from accounts you don't follow can be optionally hidden).

So when you switch accounts, or reopen the app after a while, your follower list has to be fetched.

This can be done at a typical max of 80 accounts at a time (and your server might return fewer). If each fetch of following takes 150ms, and you follow 300 people, that's 600ms of waiting just to get the info.

(mastodon/mastodon#33066 would fix this)

A future change will hide this behind the splash screen - you still won't be able to do anything while it's loading, but the UI will look "deliberately" empty instead of the current look and feel. I'd hoped to land that change as part of the initial anti-abuse work, but I ran out of time ahead of the end of month release schedule.

[nikclayton]

@turtlegarden The sideloaded APK will not auto-update, so if you want to continue with Pachli Current you'll need to remove it and install it from the Play Store.