Report an Anomaly when VoLTE moves to a deprovisioned state
We are seeing issues where devices are moving to deprovisioned state
which is very unlikely.
1) Enhance logs to include more information so that debug is easier
2) Attribute the package name of who is accessing/modifying
provisioning state.
3) Record a new anomaly when VoLTE deprovision happens so that we can
track down what is causing the issue
Bug: b/349598680
Flag: EXEMPT P0 CL to collect data on ongoing issue
Test: manual deprovision; atest ImsProvisioningControllerTest
Change-Id: I885a49f911d65a9db371a022667140598e988d43
diff --git a/src/com/android/phone/ImsProvisioningController.java b/src/com/android/phone/ImsProvisioningController.java
index e4bda19..ea60633 100644
--- a/src/com/android/phone/ImsProvisioningController.java
+++ b/src/com/android/phone/ImsProvisioningController.java
@@ -49,9 +49,11 @@
import android.os.PersistableBundle;
import android.os.RemoteCallbackList;
import android.os.RemoteException;
+import android.telephony.AnomalyReporter;
import android.telephony.CarrierConfigManager;
import android.telephony.CarrierConfigManager.Ims;
import android.telephony.SubscriptionManager;
+import android.telephony.TelephonyManager;
import android.telephony.TelephonyRegistryManager;
import android.telephony.ims.ProvisioningManager;
import android.telephony.ims.aidl.IFeatureProvisioningCallback;
@@ -76,6 +78,7 @@
import java.util.Arrays;
import java.util.Map;
+import java.util.UUID;
import java.util.concurrent.Executor;
/**
@@ -154,6 +157,10 @@
CAPABILITY_TYPE_PRESENCE_UCE, Ims.KEY_CAPABILITY_TYPE_PRESENCE_UCE_INT_ARRAY
);
+ private static final UUID VOLTE_PROVISIONING_ANOMALY =
+ UUID.fromString("f5f90e4d-3d73-4f63-a0f9-cbe1941ca57c");
+ private static final String VOLTE_PROVISIONING_ANOMALY_DESC = "VoLTE is Not Provisioned";
+
/**
* Create a FeatureConnector for this class to use to connect to an ImsManager.
*/
@@ -249,7 +256,7 @@
(FeatureProvisioningData) msg.obj);
} catch (NullPointerException e) {
logw(LOG_PREFIX, msg.arg1,
- "can not find callback manager message" + msg.what);
+ "can not find callback manager, message" + msg.what);
}
break;
case EVENT_MULTI_SIM_CONFIGURATION_CHANGE:
@@ -257,9 +264,11 @@
onMultiSimConfigChanged(activeModemCount);
break;
case EVENT_PROVISIONING_VALUE_CHANGED:
- log("subId " + msg.arg1 + " changed provisioning value item : " + msg.arg2
+ logAttr("ImsConfig", "EVENT_PROVISIONING_VALUE_CHANGED", msg.arg1,
+ "changed provisioning value, item : " + msg.arg2
+ " value : " + (int) msg.obj);
- updateCapabilityTechFromKey(msg.arg1, msg.arg2, (int) msg.obj);
+ updateCapabilityTechFromKey("ImsConfig[" + msg.arg1 + "]",
+ msg.arg1, msg.arg2, (int) msg.obj);
break;
case EVENT_NOTIFY_INIT_PROVISIONED_VALUE:
int slotId = msg.arg1;
@@ -1136,11 +1145,12 @@
* return the provisioning status for MmTel capability in specific radio tech
*/
@VisibleForTesting
- public boolean getImsProvisioningStatusForCapability(int subId, int capability, int tech) {
+ public boolean getImsProvisioningStatusForCapability(String attributionPackage, int subId,
+ int capability, int tech) {
boolean mmTelProvisioned = isImsProvisioningRequiredForCapability(subId, capability, tech);
if (!mmTelProvisioned) { // provisioning not required
- log("getImsProvisioningStatusForCapability : not required "
- + " capability " + capability + " tech " + tech);
+ logAttr(attributionPackage, "getImsProvisioningStatusForCapability", subId,
+ " not required, capability " + capability + " tech " + tech);
return true;
}
@@ -1153,14 +1163,15 @@
result = getValueFromImsService(subId, capability, tech);
mmTelProvisioned = getBoolValue(result);
if (result != ProvisioningManager.PROVISIONING_RESULT_UNKNOWN) {
- setAndNotifyMmTelProvisioningValue(subId, capability, tech, mmTelProvisioned);
+ setAndNotifyMmTelProvisioningValue(attributionPackage, subId, capability, tech,
+ mmTelProvisioned);
}
} else {
mmTelProvisioned = getBoolValue(result);
}
- log("getImsProvisioningStatusForCapability : "
- + " capability " + capability
+ logAttr(attributionPackage, "getImsProvisioningStatusForCapability", subId,
+ " capability " + capability
+ " tech " + tech
+ " result " + mmTelProvisioned);
return mmTelProvisioned;
@@ -1170,20 +1181,21 @@
* set MmTel provisioning status in specific tech
*/
@VisibleForTesting
- public void setImsProvisioningStatusForCapability(int subId, int capability, int tech,
- boolean isProvisioned) {
+ public void setImsProvisioningStatusForCapability(String attributionPackage, int subId,
+ int capability, int tech, boolean isProvisioned) {
boolean mmTelProvisioned = isImsProvisioningRequiredForCapability(subId, capability, tech);
if (!mmTelProvisioned) { // provisioning not required
- log("setImsProvisioningStatusForCapability : not required "
- + " capability " + capability + " tech " + tech);
+ logAttr(attributionPackage, "setImsProvisioningStatusForCapability", subId,
+ "not required, capability " + capability + " tech " + tech);
return;
}
// write value to ImsProvisioningLoader
- boolean isChanged = setAndNotifyMmTelProvisioningValue(subId, capability, tech,
- isProvisioned);
+ boolean isChanged = setAndNotifyMmTelProvisioningValue(attributionPackage, subId,
+ capability, tech, isProvisioned);
if (!isChanged) {
- log("status not changed mmtel capability " + capability + " tech " + tech);
+ logAttr(attributionPackage, "setImsProvisioningStatusForCapability", subId,
+ "status not changed, capability " + capability + " tech " + tech);
return;
}
@@ -1192,7 +1204,8 @@
int value = getIntValue(isProvisioned);
int key = getKeyFromCapability(capability, tech);
if (key != INVALID_VALUE) {
- log("setImsProvisioningStatusForCapability : matched key " + key);
+ logAttr(attributionPackage, "setImsProvisioningStatusForCapability", subId,
+ "matched key " + key);
try {
// set key and value to vendor ImsService for MmTel
mMmTelFeatureListenersSlotMap.get(slotId).setProvisioningValue(key, value);
@@ -1291,20 +1304,22 @@
* {@link ImsConfigImplBase#CONFIG_RESULT_SUCCESS} or
*/
@VisibleForTesting
- public int setProvisioningValue(int subId, int key, int value) {
- log("setProvisioningValue");
+ public int setProvisioningValue(String attributionPackage, int subId, int key, int value) {
+ logAttr(attributionPackage, "setProvisioningValue", subId, key + ": " + value);
int retVal = ImsConfigImplBase.CONFIG_RESULT_FAILED;
// check key value
if (!Arrays.stream(LOCAL_IMS_CONFIG_KEYS).anyMatch(keyValue -> keyValue == key)) {
- log("not matched key " + key);
+ logAttr(attributionPackage, "setProvisioningValue", subId,
+ "not matched key " + key);
return ImsConfigImplBase.CONFIG_RESULT_UNKNOWN;
}
// check subId
int slotId = getSlotId(subId);
if (slotId <= SubscriptionManager.INVALID_SIM_SLOT_INDEX || slotId >= mNumSlot) {
- loge("Fail to retrieve slotId from subId");
+ logAttrE(attributionPackage, "setProvisioningValue", subId,
+ "Fail to retrieve slotId from subId");
return ImsConfigImplBase.CONFIG_RESULT_FAILED;
}
@@ -1326,12 +1341,13 @@
retVal = mRcsFeatureListenersSlotMap.get(slotId).setProvisioningValue(key, value);
}
} catch (NullPointerException e) {
- loge("can not access FeatureListener to set provisioning value");
+ logAttrE(attributionPackage, "setProvisioningValue", subId,
+ "can not access FeatureListener to set provisioning value");
return ImsConfigImplBase.CONFIG_RESULT_FAILED;
}
// update and notify provisioning status changed capability and tech from key
- updateCapabilityTechFromKey(subId, key, value);
+ updateCapabilityTechFromKey(attributionPackage, subId, key, value);
return retVal;
}
@@ -1349,17 +1365,19 @@
* {@link ImsConfigImplBase#CONFIG_RESULT_UNKNOWN}
*/
@VisibleForTesting
- public int getProvisioningValue(int subId, int key) {
+ public int getProvisioningValue(String attributionPackage, int subId, int key) {
// check key value
if (!Arrays.stream(LOCAL_IMS_CONFIG_KEYS).anyMatch(keyValue -> keyValue == key)) {
- log("not matched key " + key);
+ logAttr(attributionPackage, "getProvisioningValue", subId,
+ "not matched key " + key);
return ImsConfigImplBase.CONFIG_RESULT_UNKNOWN;
}
// check subId
int slotId = getSlotId(subId);
if (slotId <= SubscriptionManager.INVALID_SIM_SLOT_INDEX || slotId >= mNumSlot) {
- loge("Fail to retrieve slotId from subId");
+ logAttrE(attributionPackage, "getProvisioningValue", subId,
+ "Fail to retrieve slotId from subId");
return ImsConfigImplBase.CONFIG_RESULT_UNKNOWN;
}
@@ -1376,7 +1394,8 @@
capability, tech);
}
if (result != ImsProvisioningLoader.STATUS_NOT_SET) {
- log("getProvisioningValue from loader : key " + key + " result " + result);
+ logAttr(attributionPackage, "getProvisioningValue", subId,
+ "cache hit : key=" + key + ": value=" + result);
return result;
}
}
@@ -1385,24 +1404,27 @@
if (key == KEY_EAB_PROVISIONING_STATUS) {
result = getRcsValueFromImsService(subId, capability);
if (result == ImsConfigImplBase.CONFIG_RESULT_UNKNOWN) {
- logw("getProvisioningValue : fail to get data from ImsService capability"
- + capability);
+ logAttrW(attributionPackage, "getProvisioningValue", subId,
+ "fail to get data from ImsService, capability=" + capability);
return result;
}
- log("getProvisioningValue from vendor : key " + key + " result " + result);
+ logAttr(attributionPackage, "getProvisioningValue", subId,
+ "cache miss, get from RCS - key=" + key + ": value=" + result);
setAndNotifyRcsProvisioningValueForAllTech(subId, capability, getBoolValue(result));
return result;
} else {
result = getValueFromImsService(subId, capability, tech);
if (result == ImsConfigImplBase.CONFIG_RESULT_UNKNOWN) {
- logw("getProvisioningValue : fail to get data from ImsService capability"
- + capability);
+ logAttrW(attributionPackage, "getProvisioningValue", subId,
+ "fail to get data from ImsService, capability=" + capability);
return result;
}
- log("getProvisioningValue from vendor : key " + key + " result " + result);
+ logAttr(attributionPackage, "getProvisioningValue", subId,
+ "cache miss, get from MMTEL - key=" + key + ": value=" + result);
- setAndNotifyMmTelProvisioningValue(subId, capability, tech, getBoolValue(result));
+ setAndNotifyMmTelProvisioningValue(attributionPackage, subId, capability, tech,
+ getBoolValue(result));
return result;
}
}
@@ -1531,20 +1553,23 @@
}
}
- private void updateCapabilityTechFromKey(int subId, int key, int value) {
+ private void updateCapabilityTechFromKey(String attributionPackage, int subId, int key,
+ int value) {
boolean isProvisioned = getBoolValue(value);
int capability = getCapabilityFromKey(key);
int tech = getTechFromKey(key);
if (capability == INVALID_VALUE || tech == INVALID_VALUE) {
- logw("updateCapabilityTechFromKey : unknown key " + key);
+ logAttrW(attributionPackage, "updateCapabilityTechFromKey", subId,
+ "unknown key " + key);
return;
}
if (key == KEY_VOLTE_PROVISIONING_STATUS
|| key == KEY_VT_PROVISIONING_STATUS
|| key == KEY_VOICE_OVER_WIFI_ENABLED_OVERRIDE) {
- setAndNotifyMmTelProvisioningValue(subId, capability, tech, isProvisioned);
+ setAndNotifyMmTelProvisioningValue(attributionPackage, subId, capability, tech,
+ isProvisioned);
}
if (key == KEY_EAB_PROVISIONING_STATUS) {
setAndNotifyRcsProvisioningValueForAllTech(subId, capability, isProvisioned);
@@ -1631,12 +1656,33 @@
return value == ProvisioningManager.PROVISIONING_VALUE_ENABLED ? true : false;
}
- private boolean setAndNotifyMmTelProvisioningValue(int subId, int capability, int tech,
+ // If VoLTE is not provisioned, generate an anomaly report as this is not expected.
+ private void checkProvisioningValueForAnomaly(String attributionPackage, int subId,
+ int capability, int tech, boolean isProvisioned) {
+ if (isProvisioned) return;
+ boolean isVolte = capability == CAPABILITY_TYPE_VOICE && tech == REGISTRATION_TECH_LTE;
+ if (!isVolte) return;
+ // We have hit the condition where VoLTE has been de-provisioned
+ int carrierId = TelephonyManager.UNKNOWN_CARRIER_ID;
+ TelephonyManager manager = mApp.getSystemService(TelephonyManager.class);
+ if (manager != null) {
+ carrierId = manager.createForSubscriptionId(subId).getSimCarrierId();
+ }
+ logAttrW(attributionPackage, "checkProvisioningValueForAnomaly", subId,
+ "VoLTE provisioning disabled");
+ AnomalyReporter.reportAnomaly(VOLTE_PROVISIONING_ANOMALY,
+ VOLTE_PROVISIONING_ANOMALY_DESC, carrierId);
+ }
+
+ private boolean setAndNotifyMmTelProvisioningValue(String attributionPackage, int subId,
+ int capability, int tech,
boolean isProvisioned) {
boolean changed = mImsProvisioningLoader.setProvisioningStatus(subId, FEATURE_MMTEL,
capability, tech, isProvisioned);
// notify MmTel capability changed
if (changed) {
+ checkProvisioningValueForAnomaly(attributionPackage, subId, capability, tech,
+ isProvisioned);
mHandler.sendMessage(mHandler.obtainMessage(EVENT_PROVISIONING_CAPABILITY_CHANGED,
getSlotId(subId), 0, (Object) new FeatureProvisioningData(
capability, tech, isProvisioned, /*isMmTel*/true)));
@@ -1766,6 +1812,18 @@
}
}
+ private void logAttr(String attr, String prefix, int subId, String log) {
+ Rlog.d(TAG, prefix + "[" + subId + "]: " + log + ", attr = [" + attr + "]");
+ }
+
+ private void logAttrW(String attr, String prefix, int subId, String log) {
+ Rlog.w(TAG, prefix + "[" + subId + "]: " + log + ", attr = [" + attr + "]");
+ }
+
+ private void logAttrE(String attr, String prefix, int subId, String log) {
+ Rlog.e(TAG, prefix + "[" + subId + "]: " + log + ", attr = [" + attr + "]");
+ }
+
private void log(String s) {
Rlog.d(TAG, s);
}
diff --git a/src/com/android/phone/ImsProvisioningLoader.java b/src/com/android/phone/ImsProvisioningLoader.java
index 1238b9a..8d63463 100644
--- a/src/com/android/phone/ImsProvisioningLoader.java
+++ b/src/com/android/phone/ImsProvisioningLoader.java
@@ -113,7 +113,7 @@
logd("check UT provisioning status " + UtProvisioningStatus);
if (STATUS_PROVISIONED == UtProvisioningStatus) {
- setProvisioningStatusToSubIdBundle(ImsFeature.FEATURE_MMTEL, tech,
+ setProvisioningStatusToSubIdBundle(subId, ImsFeature.FEATURE_MMTEL, tech,
MmTelFeature.MmTelCapabilities.CAPABILITY_TYPE_UT, subIdBundle,
UtProvisioningStatus);
}
@@ -130,7 +130,7 @@
subIdBundle = mSubIdBundleArray.get(subId, null);
}
- return getProvisioningStatusFromSubIdBundle(imsFeature, tech,
+ return getProvisioningStatusFromSubIdBundle(subId, imsFeature, tech,
capability, subIdBundle);
}
@@ -146,42 +146,44 @@
}
PersistableBundle subIdBundle = mSubIdBundleArray.get(subId, null);
- setProvisioningStatusToSubIdBundle(imsFeature, tech, capability, subIdBundle,
+ setProvisioningStatusToSubIdBundle(subId, imsFeature, tech, capability, subIdBundle,
newValue);
saveSubIdBundleToXml(subId, subIdBundle);
}
return true;
}
- private int getProvisioningStatusFromSubIdBundle(int imsFeature, int tech,
+ private int getProvisioningStatusFromSubIdBundle(int subId, int imsFeature, int tech,
int capability, PersistableBundle subIdBundle) {
// If it doesn't exist in xml, return STATUS_NOT_SET
if (subIdBundle == null || subIdBundle.isEmpty()) {
- logd("xml is empty");
+ logd("getProvisioningStatusFromSubIdBundle", subId, "xml is empty");
return STATUS_NOT_SET;
}
PersistableBundle regTechBundle = subIdBundle.getPersistableBundle(
String.valueOf(imsFeature));
if (regTechBundle == null) {
- logd("ImsFeature " + imsFeature + " is not exist in xml");
+ logd("getProvisioningStatusFromSubIdBundle", subId,
+ "ImsFeature " + imsFeature + " does not exist in xml");
return STATUS_NOT_SET;
}
PersistableBundle capabilityBundle = regTechBundle.getPersistableBundle(
String.valueOf(tech));
if (capabilityBundle == null) {
- logd("RegistrationTech " + tech + " is not exist in xml");
+ logd("getProvisioningStatusFromSubIdBundle", subId,
+ "RegistrationTech " + tech + " does not exist in xml");
return STATUS_NOT_SET;
}
- return getIntValueFromBundle(String.valueOf(capability), capabilityBundle);
+ return getIntValueFromBundle(subId, tech, String.valueOf(capability), capabilityBundle);
}
- private void setProvisioningStatusToSubIdBundle(int imsFeature, int tech,
+ private void setProvisioningStatusToSubIdBundle(int subId, int imsFeature, int tech,
int capability, PersistableBundle subIdBundle, int newStatus) {
- logd("set provisioning status " + newStatus + " ImsFeature "
- + imsFeature + " tech " + tech + " capa " + capability);
+ logd("setProvisioningStatusToSubIdBundle", subId, "set provisioning status " + newStatus
+ + " ImsFeature " + imsFeature + " tech " + tech + " capa " + capability);
PersistableBundle regTechBundle = subIdBundle.getPersistableBundle(
String.valueOf(imsFeature));
@@ -201,9 +203,10 @@
}
// Default value is STATUS_NOT_SET
- private int getIntValueFromBundle(String key, PersistableBundle bundle) {
+ private int getIntValueFromBundle(int subId, int tech, String key, PersistableBundle bundle) {
int value = bundle.getInt(key, STATUS_NOT_SET);
- logd("get value " + value);
+ logd("getIntValueFromBundle", subId,
+ "Cache hit, tech=" + tech + " capability=" + key + ": returning " + value);
return value;
}
@@ -293,7 +296,7 @@
String[] infoArray) {
for (String info : infoArray) {
String[] paramArray = info.split(",");
- setProvisioningStatusToSubIdBundle(Integer.valueOf(paramArray[0]),
+ setProvisioningStatusToSubIdBundle(subId, Integer.valueOf(paramArray[0]),
Integer.valueOf(paramArray[1]), Integer.valueOf(paramArray[2]),
subIdBundle, Integer.valueOf(paramArray[3]));
}
@@ -304,6 +307,10 @@
Log.e(LOG_TAG, contents);
}
+ private void logd(String prefix, int subId, String contents) {
+ Log.d(LOG_TAG, prefix + "[" + subId + "]: " + contents);
+ }
+
private void logd(String contents) {
Log.d(LOG_TAG, contents);
}
diff --git a/src/com/android/phone/PhoneInterfaceManager.java b/src/com/android/phone/PhoneInterfaceManager.java
index 1652375..6dc2add 100644
--- a/src/com/android/phone/PhoneInterfaceManager.java
+++ b/src/com/android/phone/PhoneInterfaceManager.java
@@ -5466,6 +5466,7 @@
enforceTelephonyFeatureWithException(getCurrentPackageName(),
FEATURE_TELEPHONY_IMS, "setImsProvisioningStatusForCapability");
+ String displayPackageName = getCurrentPackageNameOrPhone();
final long identity = Binder.clearCallingIdentity();
try {
ImsProvisioningController controller = ImsProvisioningController.getInstance();
@@ -5473,7 +5474,7 @@
loge("setImsProvisioningStatusForCapability: Device does not support IMS");
return;
}
- controller.setImsProvisioningStatusForCapability(
+ controller.setImsProvisioningStatusForCapability(displayPackageName,
subId, capability, tech, isProvisioned);
} finally {
Binder.restoreCallingIdentity(identity);
@@ -5488,6 +5489,7 @@
enforceTelephonyFeatureWithException(getCurrentPackageName(),
FEATURE_TELEPHONY_IMS, "getImsProvisioningStatusForCapability");
+ String displayPackageName = getCurrentPackageNameOrPhone();
final long identity = Binder.clearCallingIdentity();
try {
ImsProvisioningController controller = ImsProvisioningController.getInstance();
@@ -5497,7 +5499,8 @@
// device does not support IMS, this method will return true always.
return true;
}
- return controller.getImsProvisioningStatusForCapability(subId, capability, tech);
+ return controller.getImsProvisioningStatusForCapability(displayPackageName,
+ subId, capability, tech);
} finally {
Binder.restoreCallingIdentity(identity);
}
@@ -5560,6 +5563,7 @@
enforceTelephonyFeatureWithException(getCurrentPackageName(),
FEATURE_TELEPHONY_IMS, "getImsProvisioningInt");
+ String displayPackageName = getCurrentPackageNameOrPhone();
final long identity = Binder.clearCallingIdentity();
try {
// TODO: Refactor to remove ImsManager dependence and query through ImsPhone directly.
@@ -5577,7 +5581,8 @@
// device does not support IMS, this method will return CONFIG_RESULT_UNKNOWN.
return ImsConfigImplBase.CONFIG_RESULT_UNKNOWN;
}
- int retVal = controller.getProvisioningValue(subId, key);
+ int retVal = controller.getProvisioningValue(displayPackageName, subId,
+ key);
if (retVal != ImsConfigImplBase.CONFIG_RESULT_UNKNOWN) {
return retVal;
}
@@ -5633,6 +5638,7 @@
enforceTelephonyFeatureWithException(getCurrentPackageName(),
FEATURE_TELEPHONY_IMS, "setImsProvisioningInt");
+ String displayPackageName = getCurrentPackageNameOrPhone();
final long identity = Binder.clearCallingIdentity();
try {
// TODO: Refactor to remove ImsManager dependence and query through ImsPhone directly.
@@ -5650,7 +5656,8 @@
// device does not support IMS, this method will return CONFIG_RESULT_FAILED.
return ImsConfigImplBase.CONFIG_RESULT_FAILED;
}
- int retVal = controller.setProvisioningValue(subId, key, value);
+ int retVal = controller.setProvisioningValue(displayPackageName, subId, key,
+ value);
if (retVal != ImsConfigImplBase.CONFIG_RESULT_UNKNOWN) {
return retVal;
}
@@ -10853,6 +10860,19 @@
}
/**
+ * @return The calling package name or "phone" if the caller is the phone process. This is done
+ * because multiple Phone has multiple packages in it and the first element in the array is not
+ * actually always the caller.
+ * Note: This is for logging purposes only and should not be used for security checks.
+ */
+ private String getCurrentPackageNameOrPhone() {
+ PackageManager pm = mApp.getPackageManager();
+ String uidName = pm == null ? null : pm.getNameForUid(Binder.getCallingUid());
+ if (uidName != null && !uidName.isEmpty()) return uidName;
+ return getCurrentPackageName();
+ }
+
+ /**
* Return whether data is enabled for certain APN type. This will tell if framework will accept
* corresponding network requests on a subId.
*