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

Commit ca5a86ce authored by Grant Menke's avatar Grant Menke
Browse files

Add logging and anomaly detection in CallsLogManager. 

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.

Test: Manual testing for new logging infrastructure.
Bug: 294080756
Change-Id: I1b6d7e889f4bffd8119d027a02e51243b0f95c1c
parent 287caa98

src/com/android/server/telecom/CallLogManager.java

+95 −7
Original line number Diff line number Diff line
@@ -19,9 +19,12 @@ 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;
@@ -30,6 +33,7 @@ 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 +46,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 +54,7 @@ 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.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,16 @@ 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 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 +118,13 @@ public final class CallLogManager extends CallsManagerListenerBase { 
    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 +400,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());
@@ -517,7 +532,26 @@ public final class CallLogManager extends CallsManagerListenerBase { 
                mListeners[i] = c.logCallCompletedListener;

                try {

                    // May block.

                    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[i] = 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,8 +560,10 @@ 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.");

                    Log.e(TAG, e, "LogCall: Exception raised adding callId=%s", c.callId);

                    result[i] = null;

                    mAnomalyReporterAdapter.reportAnomaly(LOG_CALL_FAILED_ANOMALY_ID,

                            LOG_CALL_FAILED_ANOMALY_DESC);

                }

            }

            return result;
@@ -602,4 +638,56 @@ 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;

    }

}

src/com/android/server/telecom/CallsManager.java

+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);

        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) {

tests/src/com/android/server/telecom/tests/CallLogManagerTest.java

+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);

        mDefaultAccountHandle = new PhoneAccountHandle(

                new ComponentName("com.android.server.telecom.tests", "CallLogManagerTest"),

                TEST_PHONE_ACCOUNT_ID,