fix(telephony/legacy): handle potential NPE crash on SIM state change request

To reproduce this:
1. Need to unset/disable the PIN code for all SIM cards
2. Assiduously spam the on/off toggle for all SIM cards

The fix consists of two parts:
1. We must separately synchronize the call to setSimState(). The NPE
   happened, because, multiple calls can be performed in parallel (see
   line 1 & 30), and since we're only synchronizing the
   wait()/notifyAll() calls, when a requests finishes slightly earlier,
   it cleans up the requests metadata written by the other call.
2. We also want to refrain from handling SIM power state response
   directly inside callback listeners, as it'll likely be executed on
   the main thread, while in some circumstances we can make database
   requests via Room that disallows this and can throw an exception.
   Also, we don't want to do it before the notifyAll() call, since this
   is a potential error-prone issue that can trigger a false-positive
   timeout of the pending request if for some reason it will take too
   long to complete. Instead, we store the request response code in
   globally accessible metadata, then notify the caller and handle the
   response inside the caller's worker thread

1 D  7SIM.SimListViewModel handleOnSimStateChanged(simEntryId=0,enabled=true).
2 D  7SIM.TelephonyController setSimState(slotIndex=0,enabled=true,keepDisabledAcrossBoots=false) : In sync block.
3 V  7SIM.SubscriptionsImplLegacy persistSubscription(sub=Subscription { id=2 slotIndex=0 simState=ENABLED iconTint=-13408298 name=Vodafone (work) lastActivatedTime=2024-08-20T15:38 lastDeactivatedTime=-999999999-01-01T00:00 keepDisabledAcrossBoots=false }).
4 D  7SIM.SubscriptionsImplLegacy persistSubscriptionState(subId=2,state=ENABLED).
5 V  7SIM.SubscriptionsImplLegacy addOnSimStatusChangedListener().
6 V  7SIM.SubscriptionsImplLegacy registerCarrierConfigChangedReceiver().
7 V  7SIM.SubscriptionsImplLegacy onReceive() : intent=Intent { act=android.telephony.action.SIM_CARD_STATE_CHANGED flg=0x5000010 (has extras) }
8 V  7SIM.SubscriptionsImplLegacy dispatchOnSimStatusChanged(slotIndex=0,state=11).
9 V  7SIM.TelephonyController onSimStatusChanged(slotIndex=0,state=11).
10 D  7SIM.TelephonyController handleOnSetSimPowerStateForSlotFinished(resCode=11) : requestMetadata=Bundle[{last_activated_time=-999999999-01-01T00:00, last_deactivated_time=2024-08-20T15:38, subscription=Subscription { id=2 slotIndex=0 simState=ENABLED iconTint=-13408298 name=Vodafone (work) lastActivatedTime=2024-08-20T15:38 lastDeactivatedTime=-999999999-01-01T00:00 keepDisabledAcrossBoots=false }, keep_disabled_across_boots=true}], requestFailed=false,shouldNotifyAllListeners=true
11 V  7SIM.SubscriptionsImplLegacy removeOnSimStatusChangedListener().
12 V  7SIM.SubscriptionsImplLegacy unregisterCarrierConfigChangedReceiver().

13 D  7SIM.DirectBootAwareBroadcastReceiver onReceive() : intent=Intent { act=android.telephony.action.CARRIER_CONFIG_CHANGED flg=0x15000010 cmp=com.github.iusmac.sevensim/.DirectBootAwareBroadcastReceiver (has extras) }
14 D  7SIM.ForegroundService onCreate().
15 D  7SIM.ForegroundService onStartCommand(intent=Intent { act=ACTION_SUBSCRIPTIONS_CHANGED cmp=com.github.iusmac.sevensim/.ForegroundService (has extras) },flags=0,startId=1).
16 D  7SIM.ForegroundService Worker.execute(taskId=1) Add : mQueueSize=0.
17 D  7SIM.ForegroundService onStartCommand(intent=Intent { act=ACTION_SYNC_SUBSCRIPTION_ENABLED_STATE cmp=com.github.iusmac.sevensim/.ForegroundService (has extras) },flags=0,startId=2).
18 D  7SIM.ForegroundService Worker.execute(taskId=1) Start : mQueueSize=1.
19 D  7SIM.ForegroundService Worker.execute(taskId=2) Add : mQueueSize=1.
20 D  7SIM.ForegroundService onStartCommand(intent=Intent { act=ACTION_UPDATE_NEXT_WEEKLY_REPEAT_SCHEDULE_PROCESSING_ITER cmp=com.github.iusmac.sevensim/.ForegroundService (has extras) },flags=0,startId=3).
21 D  7SIM.ForegroundService Worker.execute(taskId=3) Add : mQueueSize=2.
22 D  7SIM.SubscriptionsImplLegacy syncSubscriptions(dateTime=2024-08-20T15:38:51.853) : Subscription { id=1 slotIndex=1 simState=ENABLED iconTint=-4056997 name=Vodafone lastActivatedTime=-999999999-01-01T00:00 lastDeactivatedTime=-999999999-01-01T00:00 keepDisabledAcrossBoots=false },currentSubState=ENABLED,expectedSubState=UNKNOWN,existsInUsableList=false.
23 D  7SIM.SubscriptionsImplLegacy persistSubscriptionState(subId=1,state=ENABLED).
24 D  7SIM.SubscriptionsImplLegacy syncSubscriptions(dateTime=2024-08-20T15:38:51.853) : Subscription { id=2 slotIndex=-1 simState=UNKNOWN iconTint=-16777216 name= lastActivatedTime=2024-08-20T15:38 lastDeactivatedTime=-999999999-01-01T00:00 keepDisabledAcrossBoots=false }.
25 V  7SIM.SubscriptionsImplLegacy persistSubscription(sub=Subscription { id=2 slotIndex=-1 simState=UNKNOWN iconTint=-16777216 name= lastActivatedTime=-999999999-01-01T00:00 lastDeactivatedTime=-999999999-01-01T00:00 keepDisabledAcrossBoots=false }).
26 D  7SIM.SubscriptionsImplLegacy persistSubscriptionState(subId=2,state=UNKNOWN).
27 D  7SIM.ForegroundService Worker.execute(taskId=1) Finish : mQueueSize=2.
28 D  7SIM.ForegroundService Worker.execute(taskId=2) Start : mQueueSize=2.
29 D  7SIM.SubscriptionScheduler syncSubscriptionEnabledState(subId=1,compareTime=2024-08-20T15:38:51.853,overrideUserPreference=false) : Subscription { id=1 slotIndex=1 simState=ENABLED iconTint=-4056997 name=Vodafone lastActivatedTime=-999999999-01-01T00:00 lastDeactivatedTime=-999999999-01-01T00:00 keepDisabledAcrossBoots=false },nearestEnableTime=Optional[2024-08-20T14:30],nearestDisableTime=Optional[2024-08-20T18:30],expectedEnabled=false,isInCall=false.
30 D  7SIM.TelephonyController setSimState(slotIndex=1,enabled=false,keepDisabledAcrossBoots=false) : In sync block.
31 V  7SIM.SubscriptionsImplLegacy persistSubscription(sub=Subscription { id=1 slotIndex=1 simState=DISABLED iconTint=-4056997 name=Vodafone lastActivatedTime=-999999999-01-01T00:00 lastDeactivatedTime=2024-08-20T15:38 keepDisabledAcrossBoots=false }).
32 D  7SIM.SubscriptionsImplLegacy persistSubscriptionState(subId=1,state=DISABLED).
33 V  7SIM.SubscriptionsImplLegacy addOnSimStatusChangedListener().
34 V  7SIM.SubscriptionsImplLegacy registerCarrierConfigChangedReceiver().

35 D  7SIM.SimListViewModel handleOnSimStateChanged(simEntryId=1,enabled=false).
36 D  7SIM.TelephonyController setSimState(slotIndex=1,enabled=false,keepDisabledAcrossBoots=true) : In sync block.
37 V  7SIM.SubscriptionsImplLegacy onReceive() : intent=Intent { act=android.telephony.action.SIM_CARD_STATE_CHANGED flg=0x5000010 (has extras) }
38 V  7SIM.SubscriptionsImplLegacy dispatchOnSimStatusChanged(slotIndex=1,state=1).
39 V  7SIM.TelephonyController onSimStatusChanged(slotIndex=1,state=1).
40 E  AndroidRuntime Process: com.github.iusmac.sevensim, PID: 2426
41 E  AndroidRuntime java.lang.RuntimeException: Error receiving broadcast Intent { act=android.telephony.action.SIM_CARD_STATE_CHANGED flg=0x5000010 (has extras) } in com.github.iusmac.sevensim.telephony.Subscriptions$1@a222e8c
42 E  AndroidRuntime Caused by: java.lang.NullPointerException: Attempt to invoke virtual method 'int com.github.iusmac.sevensim.telephony.Subscription.getSlotIndex()' on a null object reference
43 E  AndroidRuntime      at com.github.iusmac.sevensim.telephony.TelephonyController$SimStatusChangedListener.onSimStatusChanged(TelephonyController.java:372)
44 E  AndroidRuntime      at com.github.iusmac.sevensim.telephony.Subscriptions.dispatchOnSimStatusChanged(Subscriptions.java:446)
45 E  AndroidRuntime      at com.github.iusmac.sevensim.telephony.Subscriptions.-$$Nest$mdispatchOnSimStatusChanged(Unknown Source:0)
46 E  AndroidRuntime      at com.github.iusmac.sevensim.telephony.Subscriptions$1.onReceive(Subscriptions.java:85)
47 I  am_crash [2426,0,com.github.iusmac.sevensim,550026951,java.lang.NullPointerException,Attempt to invoke virtual method 'int com.github.iusmac.sevensim.telephony.Subscription.getSlotIndex()' on a null object reference,TelephonyController.java,372]

Signed-off-by: iusmac <iusico.maxim@libero.it>

Author: iusmac

src/com/github/iusmac/sevensim/telephony/TelephonyController.java

@@ -61,10 +61,11 @@ public final class TelephonyController {
     private static final String KEY_LAST_ACTIVATED_TIME = "last_activated_time";
     private static final String KEY_LAST_DEACTIVATED_TIME = "last_deactivated_time";
     private static final String KEY_KEEP_DISABLED_ACROSS_BOOTS = "keep_disabled_across_boots";
+    private static final String KEY_REQUEST_RESPONSE_CODE = "request_response_code";
 
     /** The globally accessible request metadata used when performing SIM power state mutations. */
-    @GuardedBy("this")
-    private final Bundle mRequestMetadata = new Bundle(4);
+    @GuardedBy("mRequestMetadata")
+    private final Bundle mRequestMetadata = new Bundle(5);
 
     @GuardedBy("this")
     private SimStatusChangedListener mSimStatusChangedListener;
@@ -128,11 +129,10 @@ public void setSimState(final int slotIndex, final boolean enabled,
                 return;
             }
 
-            // Globally save metadata needed when handling SIM power change request termination
-            mRequestMetadata.putParcelable(KEY_SUBSCRIPTION, sub);
-            if (sub.getKeepDisabledAcrossBoots() != null) {
-                mRequestMetadata.putBoolean(KEY_KEEP_DISABLED_ACROSS_BOOTS,
-                        sub.getKeepDisabledAcrossBoots());
+            if (enabled == sub.isSimEnabled()) {
+                mLogger.w(logPrefix + "Already in state.");
+                mSubscriptions.notifyAllListeners();
+                return;
             }
 
             // Keep track of SIM state whenever it's mutated. This will be persisted in a volatile
@@ -142,18 +142,26 @@ public void setSimState(final int slotIndex, final boolean enabled,
             // SubscriptionManager anymore, even though the SIM is still present in the slot
             sub.setSimState(TelephonyUtils.simStateInt(enabled));
 
-            mRequestMetadata.putString(KEY_LAST_ACTIVATED_TIME,
-                    sub.getLastActivatedTime().toString());
-            mRequestMetadata.putString(KEY_LAST_DEACTIVATED_TIME,
-                    sub.getLastDeactivatedTime().toString());
-
             sub.setLastActivatedTime(enabled ? LocalDateTime.now(ZoneId.systemDefault()) :
                     LocalDateTime.MIN);
             sub.setLastDeactivatedTime(!enabled ? LocalDateTime.now(ZoneId.systemDefault()) :
                     LocalDateTime.MIN);
 
             sub.keepDisabledAcrossBoots(keepDisabledAcrossBoots);
 
+            // Globally save metadata needed when handling SIM power change request termination
+            synchronized (mRequestMetadata) {
+                mRequestMetadata.putParcelable(KEY_SUBSCRIPTION, sub);
+                mRequestMetadata.putString(KEY_LAST_ACTIVATED_TIME,
+                        sub.getLastActivatedTime().toString());
+                mRequestMetadata.putString(KEY_LAST_DEACTIVATED_TIME,
+                        sub.getLastDeactivatedTime().toString());
+                if (sub.getKeepDisabledAcrossBoots() != null) {
+                    mRequestMetadata.putBoolean(KEY_KEEP_DISABLED_ACROSS_BOOTS,
+                            sub.getKeepDisabledAcrossBoots());
+                }
+            }
+
             // Before making any request, persist the subscription associated with the SIM whose
             // power state we're going to change, to immediately reflect the changes on the callers
             // side, since this request is generally successful and pretty fast. In case the SIM
@@ -175,15 +183,18 @@ public void setSimState(final int slotIndex, final boolean enabled,
             long nowMillis = System.currentTimeMillis();
             final long deadlineMillis = nowMillis + SET_SIM_POWER_STATE_REQUEST_TIMEOUT_MILLIS;
             do {
-                try {
-                    wait(deadlineMillis - nowMillis);
-                } catch (InterruptedException e) {
-                    mLogger.w(logPrefix + "Acquire wait interrupted.");
-                    break;
-                }
-                if (mRequestMetadata.isEmpty()) {
-                    // Request metadata consumed, so we break here as this wasn't a spurious wakeup
-                    break;
+                synchronized (mRequestMetadata) {
+                    try {
+                        mRequestMetadata.wait(deadlineMillis - nowMillis);
+                    } catch (InterruptedException e) {
+                        mLogger.w(logPrefix + "Acquire wait interrupted.");
+                        break;
+                    }
+                    if (mRequestMetadata.containsKey(KEY_REQUEST_RESPONSE_CODE)) {
+                        // SIM power request finished, so we break here as this wasn't a spurious
+                        // wakeup nor a timeout
+                        break;
+                    }
                 }
                 nowMillis = System.currentTimeMillis();
             } while (nowMillis < deadlineMillis);
@@ -193,19 +204,25 @@ public void setSimState(final int slotIndex, final boolean enabled,
                 mSimStatusChangedListener = null;
             }
 
-            if (!mRequestMetadata.isEmpty()) { // Timed out
+            synchronized (mRequestMetadata) {
                 final int resCode;
-                if (enabled) {
-                    // When trying to enable SIM, but the response from modem timeouts, then we
-                    // know there's no SIM card in the slot. This is an implicit edge case that
-                    // needs to be handled manually, because by Android telephony design, a powered
-                    // up modem won't respond if there's no SIM card
-                    resCode = SET_SIM_POWER_STATE_SIM_ABSENT;
+                if (!mRequestMetadata.containsKey(KEY_REQUEST_RESPONSE_CODE)) { // Timed out
+                    if (enabled) {
+                        // When trying to enable SIM, but the response from modem timeouts, then we
+                        // know there's no SIM card in the slot. This is an implicit edge case that
+                        // needs to be handled manually, because by Android telephony design, a
+                        // powered up modem won't respond if there's no SIM card
+                        resCode = SET_SIM_POWER_STATE_SIM_ABSENT;
+                    } else {
+                        // When trying to disable SIM, but the response from modem timeouts, then
+                        // most likely the device modem does not support
+                        // TelephonyManager#setSimPowerStateForSlot call. So far, this can occur on
+                        // non-QCOM SoCs
+                        resCode = SET_SIM_POWER_STATE_MODEM_TIMEOUT;
+                    }
                 } else {
-                    // When trying to disable SIM, but the response from modem timeouts, then most
-                    // likely the device modem does not support TelephonyManager#setSimPowerStateForSlot
-                    // call. So far, this can occur on non-QCOM SoCs
-                    resCode = SET_SIM_POWER_STATE_MODEM_TIMEOUT;
+                    resCode = mRequestMetadata.getInt(KEY_REQUEST_RESPONSE_CODE);
+                    mRequestMetadata.remove(KEY_REQUEST_RESPONSE_CODE);
                 }
                 handleOnSetSimPowerStateForSlotFinished(resCode);
             }
@@ -220,17 +237,15 @@ public void setSimState(final int slotIndex, final boolean enabled,
      * {@link TelephonyManager#CARD_POWER_UP}
      * {@link TelephonyManager#CARD_POWER_DOWN}
      */
-    @GuardedBy("this")
     private void setSimPowerStateForSlot(final int slotIndex, final int state) {
         if (Utils.IS_AT_LEAST_S) {
             final Consumer<Integer> callback = (resCode) -> {
-                synchronized (TelephonyController.this) {
-                    handleOnSetSimPowerStateForSlotFinished(resCode);
-                    TelephonyController.this.notifyAll();
+                synchronized (mRequestMetadata) {
+                    mRequestMetadata.putInt(KEY_REQUEST_RESPONSE_CODE, resCode);
+                    mRequestMetadata.notifyAll();
                 }
             };
-            mTelephonyManager.setSimPowerStateForSlot(slotIndex, state, (runnable) ->
-                    runnable.run(), callback);
+            mTelephonyManager.setSimPowerStateForSlot(slotIndex, state, Runnable::run, callback);
         } else {
             ApiDeprecated.setSimPowerStateForSlot(mTelephonyManager, slotIndex, state);
         }
@@ -239,7 +254,8 @@ private void setSimPowerStateForSlot(final int slotIndex, final int state) {
     /**
      * @param resCode The response code from the modem.
      */
-    @GuardedBy("this")
+    @WorkerThread
+    @GuardedBy("mRequestMetadata")
     private void handleOnSetSimPowerStateForSlotFinished(final int resCode) {
         final String logPrefix = String.format(Locale.getDefault(),
                 "handleOnSetSimPowerStateForSlotFinished(resCode=%d) : requestMetadata=%s",
@@ -339,8 +355,7 @@ private void handleOnSetSimPowerStateForSlotFinished(final int resCode) {
             mSubscriptions.notifyAllListeners();
         }
 
-        // Nullify all the metadata as we no longer need them + this will also signal that the
-        // response has been successfully handled within the timeout interval
+        // Nullify all the metadata as we no longer need them
         mRequestMetadata.clear();
     }
 
@@ -380,7 +395,7 @@ public void onSimStatusChanged(final int slotIndex,
                 default: return;
             }
 
-            synchronized (TelephonyController.this) {
+            synchronized (mRequestMetadata) {
                 final Subscription sub = BundleCompat.getParcelable(mRequestMetadata,
                         KEY_SUBSCRIPTION, Subscription.class);
 
@@ -391,8 +406,8 @@ public void onSimStatusChanged(final int slotIndex,
                     return;
                 }
 
-                handleOnSetSimPowerStateForSlotFinished(state);
-                TelephonyController.this.notifyAll();
+                mRequestMetadata.putInt(KEY_REQUEST_RESPONSE_CODE, state);
+                mRequestMetadata.notifyAll();
             }
         }
     }