Improve CallsLogManager logging code.
CallLogManager currently emits a Telecom event when we decide to log to
the call log. To aid in diagnosis of potential problems, we track the
count of call log entries and max id before and after adding an entry to
help try to ascertain in Telecom whether logging did suceeed. We will
also trigger an anomaly report if logging did not complete as expected to
help gain more information about this.
Also, added a button to the test app to add a load of call log entries to
help test cases where the call log has lots of stuff in it.
Test: Manual testing of new logging infra.
Bug: 290557274
Change-Id: Id7368331ba16682c1e61925bea7bf67859f135de
diff --git a/src/com/android/server/telecom/CallLogManager.java b/src/com/android/server/telecom/CallLogManager.java
index 3005656..d085be6 100644
--- a/src/com/android/server/telecom/CallLogManager.java
+++ b/src/com/android/server/telecom/CallLogManager.java
@@ -19,9 +19,12 @@
import static android.provider.CallLog.Calls.BLOCK_REASON_NOT_BLOCKED;
import static android.telephony.CarrierConfigManager.KEY_SUPPORT_IMS_CONFERENCE_EVENT_PACKAGE_BOOL;
+import android.annotation.NonNull;
import android.annotation.Nullable;
+import android.content.ContentResolver;
import android.content.Context;
import android.content.Intent;
+import android.database.Cursor;
import android.location.Country;
import android.location.CountryDetector;
import android.location.Location;
@@ -42,6 +45,7 @@
import android.telephony.CarrierConfigManager;
import android.telephony.PhoneNumberUtils;
import android.telephony.SubscriptionManager;
+import android.util.Pair;
import com.android.internal.annotations.VisibleForTesting;
import com.android.server.telecom.callfiltering.CallFilteringResult;
@@ -49,6 +53,7 @@
import java.util.Arrays;
import java.util.Locale;
import java.util.Objects;
+import java.util.UUID;
import java.util.stream.Stream;
/**
@@ -68,16 +73,19 @@
*/
private static class AddCallArgs {
public AddCallArgs(Context context, CallLog.AddCallParams params,
- @Nullable LogCallCompletedListener logCallCompletedListener) {
+ @Nullable LogCallCompletedListener logCallCompletedListener,
+ @NonNull String callId) {
this.context = context;
this.params = params;
this.logCallCompletedListener = logCallCompletedListener;
+ this.callId = callId;
}
// Since the members are accessed directly, we don't use the
// mXxxx notation.
public final Context context;
public final CallLog.AddCallParams params;
+ public final String callId;
@Nullable
public final LogCallCompletedListener logCallCompletedListener;
}
@@ -88,11 +96,16 @@
// TODO: come up with a better way to indicate in a android.telecom.DisconnectCause that
// a conference was merged successfully
private static final String REASON_IMS_MERGED_SUCCESSFULLY = "IMS_MERGED_SUCCESSFULLY";
+ private static final UUID LOG_CALL_FAILED_ANOMALY_ID =
+ UUID.fromString("1c4c15f3-ab4f-459c-b9ef-43d2988bae82");
+ private static final String LOG_CALL_FAileD_ANOMALY_DESC =
+ "Failed to record a call to the call log.";
private final Context mContext;
private final CarrierConfigManager mCarrierConfigManager;
private final PhoneAccountRegistrar mPhoneAccountRegistrar;
private final MissedCallNotifier mMissedCallNotifier;
+ private AnomalyReporterAdapter mAnomalyReporterAdapter;
private static final String ACTION_CALLS_TABLE_ADD_ENTRY =
"com.android.server.telecom.intent.action.CALLS_ADD_ENTRY";
private static final String PERMISSION_PROCESS_CALLLOG_INFO =
@@ -104,12 +117,13 @@
private String mCurrentCountryIso;
public CallLogManager(Context context, PhoneAccountRegistrar phoneAccountRegistrar,
- MissedCallNotifier missedCallNotifier) {
+ MissedCallNotifier missedCallNotifier, AnomalyReporterAdapter anomalyReporterAdapter) {
mContext = context;
mCarrierConfigManager = (CarrierConfigManager) mContext
.getSystemService(Context.CARRIER_CONFIG_SERVICE);
mPhoneAccountRegistrar = phoneAccountRegistrar;
mMissedCallNotifier = missedCallNotifier;
+ mAnomalyReporterAdapter = anomalyReporterAdapter;
mLock = new Object();
}
@@ -385,7 +399,7 @@
okayToLogCall(accountHandle, logNumber, call.isEmergencyCall());
if (okayToLog) {
AddCallArgs args = new AddCallArgs(mContext, paramBuilder.build(),
- logCallCompletedListener);
+ logCallCompletedListener, call.getId());
Log.addEvent(call, LogUtils.Events.LOG_CALL, "number=" + Log.piiHandle(logNumber)
+ ",postDial=" + Log.piiHandle(call.getPostDialDigits()) + ",pres="
+ call.getHandlePresentation());
@@ -515,9 +529,27 @@
for (int i = 0; i < count; i++) {
AddCallArgs c = callList[i];
mListeners[i] = c.logCallCompletedListener;
+
try {
// May block.
+ ContentResolver resolver = c.context.getContentResolver();
+ Pair<Integer, Integer> startStats = getCallLogStats(resolver);
result[i] = Calls.addCall(c.context, c.params);
+ Pair<Integer, Integer> endStats = getCallLogStats(resolver);
+
+ Log.i(TAG, "LogCallAsync; logged callId=%s, uri=%s, "
+ + "startCount=%d, startMaxId=%d, endCount=%d, endMaxId=%s",
+ c.callId, result[i], startStats.first, startStats.second,
+ endStats.first, endStats.second);
+ if ((endStats.second - startStats.second) <= 0) {
+ // No call was added or even worse we lost a call in the log. Trigger an
+ // anomaly report. Note: it technically possible that an app modified the
+ // call log while we were writing to it here; that is pretty unlikely, and
+ // the goal here is to try and identify potential anomalous conditions with
+ // logging calls.
+ mAnomalyReporterAdapter.reportAnomaly(LOG_CALL_FAILED_ANOMALY_ID,
+ LOG_CALL_FAileD_ANOMALY_DESC);
+ }
} catch (Exception e) {
// This is very rare but may happen in legitimate cases.
// E.g. If the phone is encrypted and thus write request fails, it may cause
@@ -526,8 +558,10 @@
//
// We don't want to crash the whole process just because of that, so just log
// it instead.
- Log.e(TAG, e, "Exception raised during adding CallLog entry.");
+ Log.e(TAG, e, "LogCallAsync: Exception raised adding callId=%s", c.callId);
result[i] = null;
+ mAnomalyReporterAdapter.reportAnomaly(LOG_CALL_FAILED_ANOMALY_ID,
+ LOG_CALL_FAileD_ANOMALY_DESC);
}
}
return result;
@@ -544,7 +578,7 @@
failed.
*/
if (uri == null) {
- Log.w(TAG, "Failed to write call to the log.");
+ Log.w(TAG, "LogCallAsync: Failed to write call to the log.");
}
if (mListeners[i] != null) {
mListeners[i].onLogCompleted(uri);
@@ -602,4 +636,40 @@
return mCurrentCountryIso;
}
}
+
+ /**
+ * Returns a pair containing the number of rows in the call log, as well as the maximum call log
+ * ID. There is a limit of 500 entries in the call log for a phone account, so once we hit 500
+ * we can reasonably expect that number to not change before and after logging a call.
+ * We determine the maximum ID in the call log since this is a way we can objectively check if
+ * the provider did record a call log entry or not. Ideally there should me more call log
+ * entries after logging than before, and certainly not less.
+ * @param resolver content resolver
+ * @return pair with number of rows in the call log and max id.
+ */
+ private Pair<Integer, Integer> getCallLogStats(@NonNull ContentResolver resolver) {
+ try {
+ int maxCallId = -1;
+ Cursor countCursor = resolver.query(Calls.CONTENT_URI,
+ new String[]{Calls._ID},
+ null,
+ null,
+ Calls._ID + " DESC");
+ int numFound = countCursor.getCount();
+ if (numFound > 0) {
+ countCursor.moveToFirst();
+ maxCallId = countCursor.getInt(0);
+ }
+ return new Pair<>(numFound, maxCallId);
+ } catch (Exception e) {
+ // Oh jeepers, we crashed getting the call count.
+ Log.e(TAG, e, "getCountOfCallLogRows: failed");
+ return new Pair<>(-1, -1);
+ }
+ }
+
+ @VisibleForTesting
+ public void setAnomalyReporterAdapter(AnomalyReporterAdapter anomalyReporterAdapter){
+ mAnomalyReporterAdapter = anomalyReporterAdapter;
+ }
}
diff --git a/src/com/android/server/telecom/CallsManager.java b/src/com/android/server/telecom/CallsManager.java
index 04e0f74..4f4f20c 100644
--- a/src/com/android/server/telecom/CallsManager.java
+++ b/src/com/android/server/telecom/CallsManager.java
@@ -655,7 +655,8 @@
mTtyManager = new TtyManager(context, mWiredHeadsetManager);
mProximitySensorManager = proximitySensorManagerFactory.create(context, this);
mPhoneStateBroadcaster = new PhoneStateBroadcaster(this);
- mCallLogManager = new CallLogManager(context, phoneAccountRegistrar, mMissedCallNotifier);
+ mCallLogManager = new CallLogManager(context, phoneAccountRegistrar, mMissedCallNotifier,
+ mAnomalyReporter);
mConnectionServiceRepository =
new ConnectionServiceRepository(mPhoneAccountRegistrar, mContext, mLock, this);
mInCallWakeLockController = inCallWakeLockControllerFactory.create(context, this);
@@ -1381,8 +1382,11 @@
}
@VisibleForTesting
- public void setAnomalyReporterAdapter(AnomalyReporterAdapter mAnomalyReporterAdapter){
- mAnomalyReporter = mAnomalyReporterAdapter;
+ public void setAnomalyReporterAdapter(AnomalyReporterAdapter anomalyReporterAdapter){
+ mAnomalyReporter = anomalyReporterAdapter;
+ if (mCallLogManager != null) {
+ mCallLogManager.setAnomalyReporterAdapter(anomalyReporterAdapter);
+ }
}
void processIncomingConference(PhoneAccountHandle phoneAccountHandle, Bundle extras) {
diff --git a/testapps/res/layout/testdialer_main.xml b/testapps/res/layout/testdialer_main.xml
index 749d236..77ee15e 100644
--- a/testapps/res/layout/testdialer_main.xml
+++ b/testapps/res/layout/testdialer_main.xml
@@ -101,4 +101,10 @@
android:layout_width="wrap_content"
android:layout_height="wrap_content"
android:text="@string/send_contact_discovery" />
+
+ <Button
+ android:id="@+id/add_call_log_entries"
+ android:layout_width="wrap_content"
+ android:layout_height="wrap_content"
+ android:text="Fill Call Log" />
</LinearLayout>
diff --git a/testapps/src/com/android/server/telecom/testapps/TestDialerActivity.java b/testapps/src/com/android/server/telecom/testapps/TestDialerActivity.java
index f17af2c..1b82f39 100644
--- a/testapps/src/com/android/server/telecom/testapps/TestDialerActivity.java
+++ b/testapps/src/com/android/server/telecom/testapps/TestDialerActivity.java
@@ -6,6 +6,7 @@
import android.app.UiModeManager;
import android.app.role.RoleManager;
import android.content.ComponentName;
+import android.content.ContentResolver;
import android.content.ContentValues;
import android.content.Context;
import android.content.Intent;
@@ -31,6 +32,7 @@
public class TestDialerActivity extends Activity {
private static final int REQUEST_CODE_SET_DEFAULT_DIALER = 1;
+ private static int sEntryNumber = 1;
private EditText mNumberView;
private CheckBox mRttCheckbox;
@@ -78,6 +80,13 @@
}
});
+ findViewById(R.id.add_call_log_entries).setOnClickListener(new OnClickListener() {
+ @Override
+ public void onClick(View v) {
+ addCallLogEntries();
+ }
+ });
+
mNumberView = (EditText) findViewById(R.id.number);
mRttCheckbox = (CheckBox) findViewById(R.id.call_with_rtt_checkbox);
mComposerCheckbox = (CheckBox) findViewById(R.id.add_composer_attachments_checkbox);
@@ -237,4 +246,23 @@
intent.putExtra(Settings.EXTRA_SUB_ID, SubscriptionManager.getDefaultSubscriptionId());
startActivity(intent);
}
+
+ private void addCallLogEntries() {
+ ContentResolver contentResolver = getContentResolver();
+ for (int ix = 0; ix < 1000; ix ++) {
+ ContentValues values = new ContentValues();
+ String number = String.format("1650%07d", sEntryNumber++);
+ values.put(Calls.TYPE, Calls.OUTGOING_TYPE);
+ values.put(Calls.NUMBER, number);
+ values.put(Calls.NUMBER_PRESENTATION, Calls.PRESENTATION_ALLOWED);
+ values.put(Calls.DATE, System.currentTimeMillis());
+ values.put(Calls.DURATION, 10);
+ values.put(Calls.PHONE_ACCOUNT_COMPONENT_NAME, "com.android.phone/com.android.services.telephony.TelephonyConnectionService");
+ values.put(Calls.PHONE_ACCOUNT_ID, 1);
+ values.put(Calls.PHONE_ACCOUNT_ADDRESS, "650-555-1212");
+ values.put(Calls.NEW, 1);
+ contentResolver.insert(Calls.CONTENT_URI, values);
+ }
+
+ }
}
diff --git a/tests/src/com/android/server/telecom/tests/CallLogManagerTest.java b/tests/src/com/android/server/telecom/tests/CallLogManagerTest.java
index 9466220..c68cbbf 100644
--- a/tests/src/com/android/server/telecom/tests/CallLogManagerTest.java
+++ b/tests/src/com/android/server/telecom/tests/CallLogManagerTest.java
@@ -65,6 +65,7 @@
import androidx.test.filters.FlakyTest;
import com.android.server.telecom.Analytics;
+import com.android.server.telecom.AnomalyReporterAdapter;
import com.android.server.telecom.Call;
import com.android.server.telecom.CallLogManager;
import com.android.server.telecom.CallState;
@@ -123,6 +124,8 @@
PhoneAccountRegistrar mMockPhoneAccountRegistrar;
@Mock
MissedCallNotifier mMissedCallNotifier;
+ @Mock
+ AnomalyReporterAdapter mAnomalyReporterAdapter;
@Override
@Before
@@ -130,7 +133,7 @@
super.setUp();
mContext = mComponentContextFixture.getTestDouble().getApplicationContext();
mCallLogManager = new CallLogManager(mContext, mMockPhoneAccountRegistrar,
- mMissedCallNotifier);
+ mMissedCallNotifier, mAnomalyReporterAdapter);
mDefaultAccountHandle = new PhoneAccountHandle(
new ComponentName("com.android.server.telecom.tests", "CallLogManagerTest"),
TEST_PHONE_ACCOUNT_ID,