PeterCxy/OpenEUICC
9
10
Fork 10
Code Issues 15 Pull requests Actions Projects Releases 6 Wiki Activity

[Issue] OpenEUICC crashes when switching profile #36

New issue
Closed
opened 2024-07-11 18:25:02 +02:00 by anyuta1166 · 2 comments
anyuta1166 commented 2024-07-11 18:25:02 +02:00
Copy link

When trying to switch a profile, the profile gets switched, but OpenEUICC crashes.

The bug was introduced in latest builds.

beta02-15-g790a5cf - works fine, no crash
beta02-50-gd78985b - crash
beta02-59-g829f019 (latest commit as of now) - crash

Phone: Xiaomi Redmi 9T, MIUI, Android 12.
Esim card: 5ber
I have 2 esim cards in both SIM1 and SIM2 slots.

crash log from beta02-59-g829f019:

07-11 19:05:34.918 16551 16580 I OMAPI.SEService: bindService successful
07-11 19:05:34.930 16551 16551 I OMAPI.SEService: Service onServiceConnected
07-11 19:05:34.931 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 0
07-11 19:05:35.034 16551 16580 D EuiccChannelManager: Found eUICC on slot 0 port 0
07-11 19:05:35.034 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 1
07-11 19:05:35.035 16551 16580 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1.
07-11 19:05:35.035 16551 16580 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0
07-11 19:05:35.118 16551 16580 D EuiccChannelManager: Found eUICC on slot 1 port 0
07-11 19:05:35.119 16551 16580 D MainActivity: slot 0 port 0
07-11 19:05:35.131 16551 16580 D MainActivity: xxxx
07-11 19:05:35.167 16551 16580 D MainActivity: slot 1 port 0
07-11 19:05:35.181 16551 16580 D MainActivity: xxxx

==== profile switching here ======

07-11 19:06:05.121 16551 16582 D LPAUtils: Latest notification is 301 before operation
07-11 19:06:05.485 16551 16582 W BpBinder: Slow Binder: BpBinder transact took 285 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false
07-11 19:06:05.533 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 1
07-11 19:06:05.534 16551 16580 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1.
07-11 19:06:05.534 16551 16580 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0
07-11 19:06:05.578 16551 16580 W EuiccChannelManager: TelephonyManager APDU interface unavailable for slot 1 port 0, falling back
07-11 19:06:05.578 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 1
07-11 19:06:05.579 16551 16580 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1.
07-11 19:06:05.583 16551 16551 E AndroidRuntime: FATAL EXCEPTION: main
07-11 19:06:05.583 16551 16551 E AndroidRuntime: Process: im.angry.openeuicc, PID: 16551
07-11 19:06:05.583 16551 16551 E AndroidRuntime: java.lang.NullPointerException
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at im.angry.openeuicc.util.EuiccChannelFragmentUtilsKt.getChannel(EuiccChannelFragmentUtils.kt:38)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at im.angry.openeuicc.ui.EuiccManagementFragment$enableOrDisableProfile$1$1.invokeSuspend(EuiccManagementFragment.kt:200)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at im.angry.openeuicc.ui.EuiccManagementFragment$enableOrDisableProfile$1$1.invoke(Unknown Source:8)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at im.angry.openeuicc.ui.EuiccManagementFragment$enableOrDisableProfile$1$1.invoke(Unknown Source:2)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at im.angry.openeuicc.util.EuiccChannelFragmentUtilsKt$beginTrackedOperation$2.invokeSuspend(EuiccChannelFragmentUtils.kt:47)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlinx.coroutines.internal.LimitedDispatcher.run(LimitedDispatcher.kt:42)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:95)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:570)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:750)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:677)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:664)
07-11 19:06:05.583 16551 16551 E AndroidRuntime: 	Suppressed: kotlinx.coroutines.DiagnosticCoroutineContextException: [StandaloneCoroutine{Cancelling}@dfffc47, Dispatchers.Main.immediate]

success log from beta02-15-g790a5cf:

07-11 19:07:10.244 17430 17471 I OMAPI.SEService: bindService successful
07-11 19:07:10.256 17430 17430 I OMAPI.SEService: Service onServiceConnected
07-11 19:07:10.257 17430 17471 I EuiccChannelManager: Trying OMAPI for physical slot 0
07-11 19:07:10.342 17430 17471 D EuiccChannelManager: Found eUICC on slot 0 port 0
07-11 19:07:10.342 17430 17471 I EuiccChannelManager: Trying OMAPI for physical slot 1
07-11 19:07:10.344 17430 17471 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1.
07-11 19:07:10.344 17430 17471 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0
07-11 19:07:10.780 17430 17471 W BpBinder: Slow Binder: BpBinder transact took 377 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false
07-11 19:07:10.783 17430 17471 D EuiccChannelManager: Found eUICC on slot 1 port 0
07-11 19:07:10.783 17430 17471 D MainActivity: slot 0 port 0
07-11 19:07:10.792 17430 17471 D MainActivity: xxxx
07-11 19:07:10.803 17430 17471 D MainActivity: slot 1 port 0
07-11 19:07:10.814 17430 17471 D MainActivity: xxxx

===== profile switching here ======

07-11 19:07:31.027 17430 17471 D LPAUtils: Latest notification is 303 before operation
07-11 19:07:31.053 17430 17471 I LPAUtils: Disabling active profile xxxx
07-11 19:07:31.262 17430 17471 W BpBinder: Slow Binder: BpBinder transact took 207 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false
07-11 19:07:31.737 17430 17473 W BpBinder: Slow Binder: BpBinder transact took 451 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false
07-11 19:07:31.864 17430 17473 I EuiccChannelManager: Trying OMAPI for physical slot 1
07-11 19:07:31.865 17430 17473 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1.
07-11 19:07:31.865 17430 17473 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0
07-11 19:07:31.933 17430 17473 W EuiccChannelManager: TelephonyManager APDU interface unavailable for slot 1 port 0, falling back
07-11 19:07:31.933 17430 17473 I EuiccChannelManager: Trying OMAPI for physical slot 1
07-11 19:07:31.933 17430 17473 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1.
07-11 19:07:31.934 17430 17471 D EuiccChannelManager: Slot 1 port 0 reconnect failure, retrying in 1000 ms
07-11 19:07:32.937 17430 17472 I EuiccChannelManager: Trying OMAPI for physical slot 1
07-11 19:07:32.938 17430 17472 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1.
07-11 19:07:32.938 17430 17472 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0
07-11 19:07:36.491 17430 17472 D LPAUtils: Operation complete

As far as I see from the logs, the key difference is the absence of connection retry (D EuiccChannelManager: Slot 1 port 0 reconnect failure, retrying in 1000 ms) in latest builds.

When trying to switch a profile, the profile gets switched, but OpenEUICC crashes. The bug was introduced in latest builds. beta02-15-g790a5cf - works fine, no crash beta02-50-gd78985b - crash beta02-59-g829f019 (latest commit as of now) - crash Phone: Xiaomi Redmi 9T, MIUI, Android 12. Esim card: 5ber I have 2 esim cards in both SIM1 and SIM2 slots. crash log from beta02-59-g829f019: ``` 07-11 19:05:34.918 16551 16580 I OMAPI.SEService: bindService successful 07-11 19:05:34.930 16551 16551 I OMAPI.SEService: Service onServiceConnected 07-11 19:05:34.931 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 0 07-11 19:05:35.034 16551 16580 D EuiccChannelManager: Found eUICC on slot 0 port 0 07-11 19:05:35.034 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 1 07-11 19:05:35.035 16551 16580 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1. 07-11 19:05:35.035 16551 16580 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0 07-11 19:05:35.118 16551 16580 D EuiccChannelManager: Found eUICC on slot 1 port 0 07-11 19:05:35.119 16551 16580 D MainActivity: slot 0 port 0 07-11 19:05:35.131 16551 16580 D MainActivity: xxxx 07-11 19:05:35.167 16551 16580 D MainActivity: slot 1 port 0 07-11 19:05:35.181 16551 16580 D MainActivity: xxxx ==== profile switching here ====== 07-11 19:06:05.121 16551 16582 D LPAUtils: Latest notification is 301 before operation 07-11 19:06:05.485 16551 16582 W BpBinder: Slow Binder: BpBinder transact took 285 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false 07-11 19:06:05.533 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 1 07-11 19:06:05.534 16551 16580 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1. 07-11 19:06:05.534 16551 16580 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0 07-11 19:06:05.578 16551 16580 W EuiccChannelManager: TelephonyManager APDU interface unavailable for slot 1 port 0, falling back 07-11 19:06:05.578 16551 16580 I EuiccChannelManager: Trying OMAPI for physical slot 1 07-11 19:06:05.579 16551 16580 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1. 07-11 19:06:05.583 16551 16551 E AndroidRuntime: FATAL EXCEPTION: main 07-11 19:06:05.583 16551 16551 E AndroidRuntime: Process: im.angry.openeuicc, PID: 16551 07-11 19:06:05.583 16551 16551 E AndroidRuntime: java.lang.NullPointerException 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at im.angry.openeuicc.util.EuiccChannelFragmentUtilsKt.getChannel(EuiccChannelFragmentUtils.kt:38) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at im.angry.openeuicc.ui.EuiccManagementFragment$enableOrDisableProfile$1$1.invokeSuspend(EuiccManagementFragment.kt:200) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at im.angry.openeuicc.ui.EuiccManagementFragment$enableOrDisableProfile$1$1.invoke(Unknown Source:8) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at im.angry.openeuicc.ui.EuiccManagementFragment$enableOrDisableProfile$1$1.invoke(Unknown Source:2) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at im.angry.openeuicc.util.EuiccChannelFragmentUtilsKt$beginTrackedOperation$2.invokeSuspend(EuiccChannelFragmentUtils.kt:47) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlinx.coroutines.internal.LimitedDispatcher.run(LimitedDispatcher.kt:42) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlinx.coroutines.scheduling.TaskImpl.run(Tasks.kt:95) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlinx.coroutines.scheduling.CoroutineScheduler.runSafely(CoroutineScheduler.kt:570) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.executeTask(CoroutineScheduler.kt:750) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.runWorker(CoroutineScheduler.kt:677) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(CoroutineScheduler.kt:664) 07-11 19:06:05.583 16551 16551 E AndroidRuntime: Suppressed: kotlinx.coroutines.DiagnosticCoroutineContextException: [StandaloneCoroutine{Cancelling}@dfffc47, Dispatchers.Main.immediate] ``` success log from beta02-15-g790a5cf: ``` 07-11 19:07:10.244 17430 17471 I OMAPI.SEService: bindService successful 07-11 19:07:10.256 17430 17430 I OMAPI.SEService: Service onServiceConnected 07-11 19:07:10.257 17430 17471 I EuiccChannelManager: Trying OMAPI for physical slot 0 07-11 19:07:10.342 17430 17471 D EuiccChannelManager: Found eUICC on slot 0 port 0 07-11 19:07:10.342 17430 17471 I EuiccChannelManager: Trying OMAPI for physical slot 1 07-11 19:07:10.344 17430 17471 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1. 07-11 19:07:10.344 17430 17471 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0 07-11 19:07:10.780 17430 17471 W BpBinder: Slow Binder: BpBinder transact took 377 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false 07-11 19:07:10.783 17430 17471 D EuiccChannelManager: Found eUICC on slot 1 port 0 07-11 19:07:10.783 17430 17471 D MainActivity: slot 0 port 0 07-11 19:07:10.792 17430 17471 D MainActivity: xxxx 07-11 19:07:10.803 17430 17471 D MainActivity: slot 1 port 0 07-11 19:07:10.814 17430 17471 D MainActivity: xxxx ===== profile switching here ====== 07-11 19:07:31.027 17430 17471 D LPAUtils: Latest notification is 303 before operation 07-11 19:07:31.053 17430 17471 I LPAUtils: Disabling active profile xxxx 07-11 19:07:31.262 17430 17471 W BpBinder: Slow Binder: BpBinder transact took 207 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false 07-11 19:07:31.737 17430 17473 W BpBinder: Slow Binder: BpBinder transact took 451 ms, interface=com.android.internal.telephony.ITelephony, code=77 oneway=false 07-11 19:07:31.864 17430 17473 I EuiccChannelManager: Trying OMAPI for physical slot 1 07-11 19:07:31.865 17430 17473 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1. 07-11 19:07:31.865 17430 17473 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0 07-11 19:07:31.933 17430 17473 W EuiccChannelManager: TelephonyManager APDU interface unavailable for slot 1 port 0, falling back 07-11 19:07:31.933 17430 17473 I EuiccChannelManager: Trying OMAPI for physical slot 1 07-11 19:07:31.933 17430 17473 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1. 07-11 19:07:31.934 17430 17471 D EuiccChannelManager: Slot 1 port 0 reconnect failure, retrying in 1000 ms 07-11 19:07:32.937 17430 17472 I EuiccChannelManager: Trying OMAPI for physical slot 1 07-11 19:07:32.938 17430 17472 W EuiccChannelManager: OMAPI APDU interface unavailable for physical slot 1. 07-11 19:07:32.938 17430 17472 I EuiccChannelManager: Trying TelephonyManager for slot 1 port 0 07-11 19:07:36.491 17430 17472 D LPAUtils: Operation complete ``` As far as I see from the logs, the key difference is the absence of connection retry (**D EuiccChannelManager: Slot 1 port 0 reconnect failure, retrying in 1000 ms**) in latest builds.
anyuta1166 commented 2024-07-11 18:58:13 +02:00
Author
Copy link

Reverting d1d85161cc fixed the issue for me.

Reverting d1d85161ccf25f29ab9090a6065200490b2769fa fixed the issue for me.
PeterCxy commented 2024-07-12 14:19:35 +02:00
Owner
Copy link

Thanks, I'll take a look shortly.

Thanks, I'll take a look shortly.
Sign in to join this conversation.
No Branch/Tag specified
Branches Tags
master
mep
unpriv-decouple
lpac
unpriv-v1.0.0
unpriv-beta02
unpriv-beta01
unpriv-alpha03
unpriv-alpha02
unpriv-alpha01
Labels
Clear labels
No items
No labels
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
2 participants
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: PeterCxy/OpenEUICC#36
No description provided.
Delete branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?