Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 380efb91 authored by Tyler Gunn's avatar Tyler Gunn
Browse files

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
parent 1ce36279
Loading
Loading
Loading
Loading
+126 −61
Original line number Diff line number Diff line
@@ -19,17 +19,20 @@ package com.android.server.telecom;
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;
import android.net.Uri;
import android.os.AsyncTask;
import android.os.Looper;
import android.os.UserHandle;
import android.os.PersistableBundle;
import android.os.UserManager;
import android.provider.CallLog;
import android.provider.CallLog.Calls;
import android.telecom.Connection;
@@ -42,6 +45,7 @@ import android.telecom.VideoProfile;
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,8 @@ import com.android.server.telecom.callfiltering.CallFilteringResult;
import java.util.Arrays;
import java.util.Locale;
import java.util.Objects;
import java.util.UUID;
import java.util.concurrent.Executor;
import java.util.stream.Stream;

/**
@@ -68,16 +74,19 @@ public final class CallLogManager extends CallsManagerListenerBase {
     */
    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 +97,17 @@ public final class CallLogManager extends CallsManagerListenerBase {
    // 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 final Executor mCallLogExecutor;
    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 +119,15 @@ public final class CallLogManager extends CallsManagerListenerBase {
    private String mCurrentCountryIso;

    public CallLogManager(Context context, PhoneAccountRegistrar phoneAccountRegistrar,
            MissedCallNotifier missedCallNotifier) {
            MissedCallNotifier missedCallNotifier, AnomalyReporterAdapter anomalyReporterAdapter,
            Executor executor) {
        mContext = context;
        mCarrierConfigManager = (CarrierConfigManager) mContext
                .getSystemService(Context.CARRIER_CONFIG_SERVICE);
        mPhoneAccountRegistrar = phoneAccountRegistrar;
        mMissedCallNotifier = missedCallNotifier;
        mAnomalyReporterAdapter = anomalyReporterAdapter;
        mCallLogExecutor = executor;
        mLock = new Object();
    }

@@ -240,8 +258,10 @@ public final class CallLogManager extends CallsManagerListenerBase {
            logCall(call, type, new LogCallCompletedListener() {
                @Override
                public void onLogCompleted(@Nullable Uri uri) {
                    mContext.getMainExecutor().execute(() -> {
                        mMissedCallNotifier.showMissedCallNotification(
                                new MissedCallNotifier.CallInfo(call));
                    });
                }
            }, result);
        } else {
@@ -385,7 +405,7 @@ public final class CallLogManager extends CallsManagerListenerBase {
                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());
@@ -491,33 +511,33 @@ public final class CallLogManager extends CallsManagerListenerBase {
     * Adds the call defined by the parameters in the provided AddCallArgs to the CallLogProvider
     * using an AsyncTask to avoid blocking the main thread.
     *
     * @param args Prepopulated call details.
     * @return A handle to the AsyncTask that will add the call to the call log asynchronously.
     * @param c Prepopulated call details.
     */
    public AsyncTask<AddCallArgs, Void, Uri[]> logCallAsync(AddCallArgs args) {
        return new LogCallAsyncTask().execute(args);
    }

    /**
     * Helper AsyncTask to access the call logs database asynchronously since database operations
     * can take a long time depending on the system's load. Since it extends AsyncTask, it uses
     * its own thread pool.
     */
    private class LogCallAsyncTask extends AsyncTask<AddCallArgs, Void, Uri[]> {

        private LogCallCompletedListener[] mListeners;

        @Override
        protected Uri[] doInBackground(AddCallArgs... callList) {
            int count = callList.length;
            Uri[] result = new Uri[count];
            mListeners = new LogCallCompletedListener[count];
            for (int i = 0; i < count; i++) {
                AddCallArgs c = callList[i];
                mListeners[i] = c.logCallCompletedListener;
    public void logCallAsync(final AddCallArgs c) {
        mCallLogExecutor.execute(() -> {
            Uri result;
            try {
                // May block.
                    result[i] = Calls.addCall(c.context, c.params);
                ContentResolver resolver = c.context.getContentResolver();
                Pair<Integer, Integer> startStats = getCallLogStats(resolver);
                Log.i(TAG, "LogCall; about to log callId=%s, "
                                + "startCount=%d, startMaxId=%d",
                        c.callId, startStats.first, startStats.second);

                result = Calls.addCall(c.context, c.params);
                Pair<Integer, Integer> endStats = getCallLogStats(resolver);
                Log.i(TAG, "LogCall; logged callId=%s, uri=%s, "
                                + "endCount=%d, endMaxId=%s",
                        c.callId, result, 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,31 +546,25 @@ public final class CallLogManager extends CallsManagerListenerBase {
                //
                // 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.");
                    result[i] = null;
                }
            }
            return result;
                Log.e(TAG, e, "LogCall: Exception raised adding callId=%s", c.callId);
                result = null;
                mAnomalyReporterAdapter.reportAnomaly(LOG_CALL_FAILED_ANOMALY_ID,
                        LOG_CALL_FAileD_ANOMALY_DESC);
            }

        @Override
        protected void onPostExecute(Uri[] result) {
            for (int i = 0; i < result.length; i++) {
                Uri uri = result[i];
            /*
             Performs a simple correctness check to make sure the call was written in the
             database.
             Typically there is only one result per call so it is easy to identify which one
             failed.
             */
                if (uri == null) {
                    Log.w(TAG, "Failed to write call to the log.");
                }
                if (mListeners[i] != null) {
                    mListeners[i].onLogCompleted(uri);
                }
            if (result == null) {
                Log.w(TAG, "LogCall: Failed to write call to the log.");
            }
            if (c.logCallCompletedListener != null) {
                c.logCallCompletedListener.onLogCompleted(result);
            }
        });
    }

    private void sendAddCallBroadcast(int callType, long duration) {
@@ -602,4 +616,55 @@ public final class CallLogManager extends CallsManagerListenerBase {
            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 {
            final UserManager userManager = mContext.getSystemService(UserManager.class);
            final int currentUserId = userManager.getProcessUserId();

            // Use shadow provider based on current user unlock state.
            Uri providerUri;
            if (userManager.isUserUnlocked(currentUserId)) {
                providerUri = Calls.CONTENT_URI;
            } else {
                providerUri = Calls.SHADOW_CONTENT_URI;
            }
            int maxCallId = -1;
            int numFound;
            Cursor countCursor = resolver.query(providerUri,
                    new String[]{Calls._ID},
                    null,
                    null,
                    Calls._ID + " DESC");
            try {
                numFound = countCursor.getCount();
                if (numFound > 0) {
                    countCursor.moveToFirst();
                    maxCallId = countCursor.getInt(0);
                }
            } finally {
                countCursor.close();
            }
            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;
    }
}
+7 −3
Original line number Diff line number Diff line
@@ -655,7 +655,8 @@ public class CallsManager extends Call.ListenerBase
        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, asyncCallAudioTaskExecutor);
        mConnectionServiceRepository =
                new ConnectionServiceRepository(mPhoneAccountRegistrar, mContext, mLock, this);
        mInCallWakeLockController = inCallWakeLockControllerFactory.create(context, this);
@@ -1381,8 +1382,11 @@ public class CallsManager extends Call.ListenerBase
    }

    @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) {
+6 −0
Original line number Diff line number Diff line
@@ -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>
+28 −0
Original line number Diff line number Diff line
@@ -6,6 +6,7 @@ import android.app.Activity;
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 @@ import android.widget.Toast;

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 @@ public class TestDialerActivity extends Activity {
            }
        });

        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 @@ public class TestDialerActivity extends Activity {
        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);
        }

    }
}
+4 −1
Original line number Diff line number Diff line
@@ -65,6 +65,7 @@ import android.test.suitebuilder.annotation.SmallTest;
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 @@ public class CallLogManagerTest extends TelecomTestCase {
    PhoneAccountRegistrar mMockPhoneAccountRegistrar;
    @Mock
    MissedCallNotifier mMissedCallNotifier;
    @Mock
    AnomalyReporterAdapter mAnomalyReporterAdapter;

    @Override
    @Before
@@ -130,7 +133,7 @@ public class CallLogManagerTest extends TelecomTestCase {
        super.setUp();
        mContext = mComponentContextFixture.getTestDouble().getApplicationContext();
        mCallLogManager = new CallLogManager(mContext, mMockPhoneAccountRegistrar,
                mMissedCallNotifier);
                mMissedCallNotifier, mAnomalyReporterAdapter, Runnable::run);
        mDefaultAccountHandle = new PhoneAccountHandle(
                new ComponentName("com.android.server.telecom.tests", "CallLogManagerTest"),
                TEST_PHONE_ACCOUNT_ID,
Loading