Merge "Add locallog to reveal the binding flakiness in CarrierServiceBindHelper"
diff --git a/src/java/com/android/internal/telephony/CarrierServiceBindHelper.java b/src/java/com/android/internal/telephony/CarrierServiceBindHelper.java
index 69d59af..817a461 100644
--- a/src/java/com/android/internal/telephony/CarrierServiceBindHelper.java
+++ b/src/java/com/android/internal/telephony/CarrierServiceBindHelper.java
@@ -38,6 +38,7 @@
import android.telephony.SubscriptionManager;
import android.telephony.TelephonyManager;
import android.text.TextUtils;
+import android.util.LocalLog;
import android.util.Log;
import android.util.SparseArray;
@@ -68,6 +69,7 @@
@VisibleForTesting
public SparseArray<String> mLastSimState = new SparseArray<>();
private final PackageChangeReceiver mPackageMonitor = new CarrierServicePackageMonitor();
+ private final LocalLog mLocalLog = new LocalLog(100);
// whether we have successfully bound to the service
private boolean mServiceBound = false;
@@ -76,7 +78,7 @@
@Override
public void onReceive(Context context, Intent intent) {
final String action = intent.getAction();
- log("Received " + action);
+ logdWithLocalLog("Received " + action);
if (Intent.ACTION_USER_UNLOCKED.equals(action)) {
// On user unlock, new components might become available, so reevaluate all
@@ -101,20 +103,21 @@
public void handleMessage(Message msg) {
int phoneId;
AppBinding binding;
- log("mHandler: " + msg.what);
+ logdWithLocalLog("mHandler: " + msg.what);
switch (msg.what) {
case EVENT_REBIND:
phoneId = (int) msg.obj;
binding = mBindings.get(phoneId);
if (binding == null) return;
- log("Rebinding if necessary for phoneId: " + binding.getPhoneId());
+ logdWithLocalLog("Rebinding if necessary for phoneId: " + binding.getPhoneId());
binding.rebind();
break;
case EVENT_PERFORM_IMMEDIATE_UNBIND:
phoneId = (int) msg.obj;
binding = mBindings.get(phoneId);
if (binding == null) return;
+ logdWithLocalLog("Unbind immediate with phoneId: " + binding.getPhoneId());
binding.performImmediateUnbind();
break;
case EVENT_MULTI_SIM_CONFIG_CHANGED:
@@ -141,7 +144,7 @@
new IntentFilter(Intent.ACTION_USER_UNLOCKED), null /* broadcastPermission */,
mHandler);
} catch (PackageManager.NameNotFoundException e) {
- loge("Package name not found: " + e.getMessage());
+ logeWithLocalLog("Package name not found: " + e.getMessage());
}
}
@@ -166,7 +169,7 @@
}
void updateForPhoneId(int phoneId, String simState) {
- log("update binding for phoneId: " + phoneId + " simState: " + simState);
+ logdWithLocalLog("update binding for phoneId: " + phoneId + " simState: " + simState);
if (!SubscriptionManager.isValidPhoneId(phoneId)) {
return;
}
@@ -218,13 +221,13 @@
);
if (carrierPackageNames == null || carrierPackageNames.size() <= 0) {
- log("No carrier app for: " + phoneId);
+ logdWithLocalLog("No carrier app for: " + phoneId);
// Unbind after a delay in case this is a temporary blip in carrier privileges.
unbind(false /* immediate */);
return;
}
- log("Found carrier app: " + carrierPackageNames);
+ logdWithLocalLog("Found carrier app: " + carrierPackageNames);
String candidateCarrierPackage = carrierPackageNames.get(0);
// If we are binding to a different package, unbind immediately from the current one.
if (!TextUtils.equals(carrierPackage, candidateCarrierPackage)) {
@@ -249,15 +252,18 @@
// Only bind if the service wants it
if (metadata == null ||
!metadata.getBoolean("android.service.carrier.LONG_LIVED_BINDING", false)) {
- log("Carrier app does not want a long lived binding");
+ logdWithLocalLog("Carrier app does not want a long lived binding");
unbind(true /* immediate */);
return;
}
if (!TextUtils.equals(carrierServiceClass, candidateServiceClass)) {
+ logdWithLocalLog("CarrierService class changed, unbind immediately.");
// Unbind immediately if the carrier service component has changed.
unbind(true /* immediate */);
} else if (connection != null) {
+ logdWithLocalLog(
+ "CarrierService class unchanged with connection up, cancelScheduledUnbind");
// Component is unchanged and connection is up - do nothing, but cancel any
// scheduled unbinds.
cancelScheduledUnbind();
@@ -267,7 +273,7 @@
carrierPackage = candidateCarrierPackage;
carrierServiceClass = candidateServiceClass;
- log("Binding to " + carrierPackage + " for phone " + phoneId);
+ logdWithLocalLog("Binding to " + carrierPackage + " for phone " + phoneId);
// Log debug information
bindCount++;
@@ -284,7 +290,7 @@
| Context.BIND_INCLUDE_CAPABILITIES,
(r) -> mHandler.post(r),
connection)) {
- log("service bound");
+ logdWithLocalLog("service bound");
mServiceBound = true;
return;
}
@@ -294,8 +300,8 @@
error = ex.getMessage();
}
- log("Unable to bind to " + carrierPackage + " for phone " + phoneId +
- ". Error: " + error);
+ logdWithLocalLog("Unable to bind to " + carrierPackage + " for phone " + phoneId
+ + ". Error: " + error);
unbind(true /* immediate */);
}
@@ -318,12 +324,13 @@
// not running anyway and it may be a permanent disconnection (e.g. the app was
// disabled).
if (immediate || !connection.connected) {
+ logdWithLocalLog("unbind immediately or with disconnected connection");
cancelScheduledUnbind();
performImmediateUnbind();
} else if (mUnbindScheduledUptimeMillis == -1) {
long currentUptimeMillis = SystemClock.uptimeMillis();
mUnbindScheduledUptimeMillis = currentUptimeMillis + UNBIND_DELAY_MILLIS;
- log("Scheduling unbind in " + UNBIND_DELAY_MILLIS + " millis");
+ logdWithLocalLog("Scheduling unbind in " + UNBIND_DELAY_MILLIS + " millis");
mHandler.sendMessageAtTime(
mHandler.obtainMessage(EVENT_PERFORM_IMMEDIATE_UNBIND, phoneId),
mUnbindScheduledUptimeMillis);
@@ -341,22 +348,23 @@
// Actually unbind
if (mServiceBound) {
- log("Unbinding from carrier app");
+ logdWithLocalLog("Unbinding from carrier app");
mServiceBound = false;
try {
mContext.unbindService(connection);
} catch (IllegalArgumentException e) {
//TODO(b/151328766): Figure out why we unbind without binding
- loge("Tried to unbind without binding e=" + e);
+ logeWithLocalLog("Tried to unbind without binding e=" + e);
}
} else {
- log("Not bound, skipping unbindService call");
+ logdWithLocalLog("Not bound, skipping unbindService call");
}
connection = null;
mUnbindScheduledUptimeMillis = -1;
}
private void cancelScheduledUnbind() {
+ logdWithLocalLog("cancelScheduledUnbind");
mHandler.removeMessages(EVENT_PERFORM_IMMEDIATE_UNBIND);
mUnbindScheduledUptimeMillis = -1;
}
@@ -378,25 +386,25 @@
@Override
public void onServiceConnected(ComponentName name, IBinder service) {
- log("Connected to carrier app: " + name.flattenToString());
+ logdWithLocalLog("Connected to carrier app: " + name.flattenToString());
connected = true;
}
@Override
public void onServiceDisconnected(ComponentName name) {
- log("Disconnected from carrier app: " + name.flattenToString());
+ logdWithLocalLog("Disconnected from carrier app: " + name.flattenToString());
connected = false;
}
@Override
public void onBindingDied(ComponentName name) {
- log("Binding from carrier app died: " + name.flattenToString());
+ logdWithLocalLog("Binding from carrier app died: " + name.flattenToString());
connected = false;
}
@Override
public void onNullBinding(ComponentName name) {
- log("Null binding from carrier app: " + name.flattenToString());
+ logdWithLocalLog("Null binding from carrier app: " + name.flattenToString());
connected = false;
}
@@ -446,7 +454,8 @@
// is unset, in case this package change resulted in a new carrier package becoming
// available for binding.
if (isBindingForPackage) {
- log(carrierPackageName + " changed and corresponds to a phone. Rebinding.");
+ logdWithLocalLog(
+ carrierPackageName + " changed and corresponds to a phone. Rebinding.");
}
if (appBindingPackage == null || isBindingForPackage) {
if (forceUnbind) {
@@ -458,16 +467,22 @@
}
}
- private static void log(String message) {
- Log.d(LOG_TAG, message);
+ private void logdWithLocalLog(String msg) {
+ Log.d(LOG_TAG, msg);
+ mLocalLog.log(msg);
}
- private static void loge(String message) { Log.e(LOG_TAG, message); }
+ private void logeWithLocalLog(String msg) {
+ Log.e(LOG_TAG, msg);
+ mLocalLog.log(msg);
+ }
public void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
pw.println("CarrierServiceBindHelper:");
for (int i = 0; i < mBindings.size(); i++) {
mBindings.get(i).dump(fd, pw, args);
}
+ pw.println("CarrierServiceBindHelperLogs=");
+ mLocalLog.dump(fd, pw, args);
}
}