Report anamoly when getting SQLiteException in opening MMS/SMS database

Bug: 275225402
Test: SMS, MMS, call with live network. Manually test to trigger bugreport.
atest com.android.providers.telephony.MmsSmsDatabaseHelperTest
atest com.android.providers.telephony.MmsProviderTest
atest com.android.providers.telephony.SmsProviderTest

Change-Id: Iec5ba5e3fc1adc314ae58fe423e3311e9df2fc8d
diff --git a/src/com/android/providers/telephony/MmsProvider.java b/src/com/android/providers/telephony/MmsProvider.java
index db11db1..c1358f0 100644
--- a/src/com/android/providers/telephony/MmsProvider.java
+++ b/src/com/android/providers/telephony/MmsProvider.java
@@ -126,6 +126,7 @@
             String selection, String[] selectionArgs, String sortOrder) {
         final int callerUid = Binder.getCallingUid();
         final UserHandle callerUserHandle = Binder.getCallingUserHandle();
+        String callingPackage = getCallingPackage();
         // First check if a restricted view of the "pdu" table should be used based on the
         // caller's identity. Only system, phone or the default sms app can have full access
         // of mms data. For other apps, we present a restricted view which only contains sent
@@ -294,10 +295,17 @@
         Cursor ret;
         try {
             SQLiteDatabase db = mOpenHelper.getReadableDatabase();
+            if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+                ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                        callingPackage + ";MmsProvider.query;" + uri, true);
+            }
             ret = qb.query(db, projection, selection,
                     selectionArgs, null, null, finalSortOrder);
         } catch (SQLiteException e) {
             Log.e(TAG, "returning NULL cursor, query: " + uri, e);
+            if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+                ((MmsSmsDatabaseHelper) mOpenHelper).printDatabaseOpeningDebugLog();
+            }
             return null;
         }
 
@@ -426,6 +434,10 @@
         }
 
         SQLiteDatabase db = mOpenHelper.getWritableDatabase();
+        if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                    callerPkg + ";MmsProvider.insert;" + uri, false);
+        }
         ContentValues finalValues;
         Uri res = Mms.CONTENT_URI;
         Uri caseSpecificUri = null;
@@ -494,6 +506,9 @@
 
             if ((rowId = db.insert(table, null, finalValues)) <= 0) {
                 Log.e(TAG, "MmsProvider.insert: failed!");
+                if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+                    ((MmsSmsDatabaseHelper) mOpenHelper).printDatabaseOpeningDebugLog();
+                }
                 return null;
             }
 
@@ -509,6 +524,9 @@
 
             if ((rowId = db.insert(table, null, finalValues)) <= 0) {
                 Log.e(TAG, "Failed to insert address");
+                if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+                    ((MmsSmsDatabaseHelper) mOpenHelper).printDatabaseOpeningDebugLog();
+                }
                 return null;
             }
 
@@ -621,6 +639,9 @@
 
             if ((rowId = db.insert(table, null, finalValues)) <= 0) {
                 Log.e(TAG, "MmsProvider.insert: failed!");
+                if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+                    ((MmsSmsDatabaseHelper) mOpenHelper).printDatabaseOpeningDebugLog();
+                }
                 return null;
             }
 
@@ -675,6 +696,9 @@
 
             if ((rowId = db.insert(table, null, finalValues)) <= 0) {
                 Log.e(TAG, "MmsProvider.insert: failed!");
+                if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+                    ((MmsSmsDatabaseHelper) mOpenHelper).printDatabaseOpeningDebugLog();
+                }
                 return null;
             }
             res = Uri.parse(res + "/drm/" + rowId);
@@ -712,6 +736,7 @@
             String[] selectionArgs) {
         final UserHandle callerUserHandle = Binder.getCallingUserHandle();
         int match = sURLMatcher.match(uri);
+        String callingPackage = getCallingPackage();
         if (LOCAL_LOGV) {
             Log.v(TAG, "Delete uri=" + uri + ", match=" + match);
         }
@@ -766,6 +791,10 @@
 
         String finalSelection = concatSelections(selection, extraSelection);
         SQLiteDatabase db = mOpenHelper.getWritableDatabase();
+        if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                    callingPackage + ";MmsProvider.insert;" + uri, false);
+        }
         int deletedRows = 0;
 
         final long token = Binder.clearCallingIdentity();
@@ -997,6 +1026,10 @@
 
         String finalSelection = concatSelections(selection, extraSelection);
         SQLiteDatabase db = mOpenHelper.getWritableDatabase();
+        if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                    callerPkg + ";MmsProvider.update;" + uri, false);
+        }
         int count = db.update(table, finalValues, finalSelection, selectionArgs);
         if (notify && (count > 0)) {
             notifyChange(uri, null);
diff --git a/src/com/android/providers/telephony/MmsSmsDatabaseHelper.java b/src/com/android/providers/telephony/MmsSmsDatabaseHelper.java
index dbbd138..f00618f 100644
--- a/src/com/android/providers/telephony/MmsSmsDatabaseHelper.java
+++ b/src/com/android/providers/telephony/MmsSmsDatabaseHelper.java
@@ -18,6 +18,7 @@
 
 import static com.android.providers.telephony.SmsProvider.NO_ERROR_CODE;
 
+import android.annotation.NonNull;
 import android.content.BroadcastReceiver;
 import android.content.ContentValues;
 import android.content.Context;
@@ -47,6 +48,7 @@
 import android.provider.Telephony.Threads;
 import android.telephony.AnomalyReporter;
 import android.telephony.SubscriptionManager;
+import android.text.format.DateFormat;
 import android.util.Log;
 
 import com.android.internal.annotations.VisibleForTesting;
@@ -63,6 +65,7 @@
 import java.util.ArrayList;
 import java.util.HashSet;
 import java.util.Iterator;
+import java.util.List;
 import java.util.UUID;
 import java.util.concurrent.atomic.AtomicBoolean;
 
@@ -269,6 +272,10 @@
 
     private final Context mContext;
     private LowStorageMonitor mLowStorageMonitor;
+    private final List<String> mDatabaseReadOpeningInfos = new ArrayList<>();
+    private final List<String> mDatabaseWriteOpeningInfos = new ArrayList<>();
+    private final Object mDatabaseOpeningInfoLock = new Object();
+    private static final int MAX_DATABASE_OPENING_INFO_STORED = 10;
 
     // SharedPref key used to check if initial create has been done (if onCreate has already been
     // called once)
@@ -278,6 +285,8 @@
 
     private static final UUID CREATE_CALLED_MULTIPLE_TIMES_UUID = UUID.fromString(
         "6ead002e-c001-4c05-9bca-67d7c4e29782");
+    private static final UUID DATABASE_OPENING_EXCEPTION_UUID = UUID.fromString(
+            "de3f61e1-ecd8-41ee-b059-9282b294b235");
 
     /**
      * The primary purpose of this DatabaseErrorHandler is to broadcast an intent on corruption and
@@ -2182,7 +2191,13 @@
 
     @Override
     public synchronized  SQLiteDatabase getReadableDatabase() {
-        SQLiteDatabase db = super.getWritableDatabase();
+        SQLiteDatabase db;
+        try {
+            db = super.getWritableDatabase();
+        } catch (SQLiteException ex) {
+            reportAnomalyForDatabaseOpeningException(ex);
+            throw ex;
+        }
 
         // getReadableDatabase gets or creates a database. So we know for sure that a database has
         // already been created at this point.
@@ -2195,7 +2210,13 @@
 
     @Override
     public synchronized SQLiteDatabase getWritableDatabase() {
-        SQLiteDatabase db = super.getWritableDatabase();
+        SQLiteDatabase db;
+        try {
+            db = super.getWritableDatabase();
+        } catch (SQLiteException ex) {
+            reportAnomalyForDatabaseOpeningException(ex);
+            throw ex;
+        }
 
         // getWritableDatabase gets or creates a database. So we know for sure that a database has
         // already been created at this point.
@@ -2540,4 +2561,70 @@
         Log.d(TAG, "tableName: " + table + " columnName: " + column + " isExists: " + isExists);
         return isExists;
     }
+
+    /**
+     * Add the MMS/SMS database opening info to the debug log.
+     */
+    public void addDatabaseOpeningDebugLog(@NonNull String databaseOpeningLog, boolean isQuery) {
+        if (!ProviderUtil.sFeatureFlag.logMmsSmsDatabaseAccessInfo()) {
+            return;
+        }
+        addDatabaseOpeningDebugLog(isQuery ? mDatabaseReadOpeningInfos : mDatabaseWriteOpeningInfos,
+                databaseOpeningLog);
+    }
+
+    /**
+     * Print the MMS/SMS database opening debug log to file.
+     */
+    public void printDatabaseOpeningDebugLog() {
+        if (!ProviderUtil.sFeatureFlag.logMmsSmsDatabaseAccessInfo()) {
+            return;
+        }
+        Log.e(TAG, "MMS/SMS database read opening info: "
+                + getDatabaseOpeningInfo(mDatabaseReadOpeningInfos));
+        Log.e(TAG, "MMS/SMS database write opening info: "
+                + getDatabaseOpeningInfo(mDatabaseWriteOpeningInfos));
+        ProviderUtil.logRunningTelephonyProviderProcesses(mContext);
+    }
+
+    private void addDatabaseOpeningDebugLog(List<String> databaseOpeningInfos,
+            @NonNull String callingPackage) {
+        synchronized (mDatabaseOpeningInfoLock) {
+            if (databaseOpeningInfos.size() >= MAX_DATABASE_OPENING_INFO_STORED) {
+                databaseOpeningInfos.remove(0);
+            }
+            databaseOpeningInfos.add(buildDatabaseOpeningInfoStr(callingPackage));
+        }
+    }
+
+    private String buildDatabaseOpeningInfoStr(@NonNull String databaseOpeningLog) {
+        StringBuilder sb = new StringBuilder();
+        sb.append(DateFormat.format(
+                "MM-dd HH:mm:ss.mmm", System.currentTimeMillis()).toString());
+        sb.append(" ");
+        sb.append(databaseOpeningLog);
+        return sb.toString();
+    }
+
+    private String getDatabaseOpeningInfo(List<String> databaseOpeningInfos) {
+        synchronized (mDatabaseOpeningInfoLock) {
+            StringBuilder sb = new StringBuilder();
+            for (String databaseOpeningInfo : databaseOpeningInfos) {
+                sb.append("{");
+                sb.append(databaseOpeningInfo);
+                sb.append("}");
+            }
+            return sb.toString();
+        }
+    }
+
+    private void reportAnomalyForDatabaseOpeningException(@NonNull Exception ex) {
+        if (!ProviderUtil.sFeatureFlag.logMmsSmsDatabaseAccessInfo()) {
+            return;
+        }
+        Log.e(TAG, "DatabaseOpeningException=" + ex);
+        printDatabaseOpeningDebugLog();
+        AnomalyReporter.reportAnomaly(DATABASE_OPENING_EXCEPTION_UUID,
+                "MmsSmsDatabaseHelper: Got exception in opening SQLite database");
+    }
 }
diff --git a/src/com/android/providers/telephony/MmsSmsProvider.java b/src/com/android/providers/telephony/MmsSmsProvider.java
index 8ee924f..c3af98a 100644
--- a/src/com/android/providers/telephony/MmsSmsProvider.java
+++ b/src/com/android/providers/telephony/MmsSmsProvider.java
@@ -339,6 +339,7 @@
             String selection, String[] selectionArgs, String sortOrder) {
         final int callerUid = Binder.getCallingUid();
         final UserHandle callerUserHandle = Binder.getCallingUserHandle();
+        String callingPackage = getCallingPackage();
 
         // First check if restricted views of the "sms" and "pdu" tables should be used based on the
         // caller's identity. Only system, phone or the default sms app can have full access
@@ -369,6 +370,10 @@
         }
 
         SQLiteDatabase db = mOpenHelper.getReadableDatabase();
+        if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                    callingPackage + ";MmsSmsProvider.query;" + uri, true);
+        }
         Cursor cursor = null;
         Cursor emptyCursor = new MatrixCursor((projection == null) ?
                 (new String[] {}) : projection);
@@ -846,6 +851,9 @@
             db.setTransactionSuccessful();
         } catch (Throwable ex) {
             Log.e(LOG_TAG, ex.getMessage(), ex);
+            if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+                ((MmsSmsDatabaseHelper) mOpenHelper).printDatabaseOpeningDebugLog();
+            }
             TelephonyStatsLog.write(
                 TelephonyStatsLog.MMS_SMS_PROVIDER_GET_THREAD_ID_FAILED,
                 FAILURE_FIND_OR_CREATE_THREAD_ID_SQL);
@@ -1370,6 +1378,10 @@
         }
 
         SQLiteDatabase db = mOpenHelper.getWritableDatabase();
+        if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                    getCallingPackage() + ";MmsSmsProvider.delete;" + uri, false);
+        }
         Context context = getContext();
         int affectedRows = 0;
 
@@ -1441,8 +1453,12 @@
         final UserHandle callerUserHandle = Binder.getCallingUserHandle();
         final int callerUid = Binder.getCallingUid();
         SQLiteDatabase db = mOpenHelper.getWritableDatabase();
-        int matchIndex = URI_MATCHER.match(uri);
+        if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                    getCallingPackage() + ";MmsSmsProvider.insert;" + uri, false);
+        }
 
+        int matchIndex = URI_MATCHER.match(uri);
         // TODO (b/256992531): Currently, one sim card is set as default sms subId in work
         //  profile. Default sms subId should be updated based on user pref.
         int defaultSmsSubId = SmsManager.getDefaultSmsSubscriptionId();
@@ -1497,6 +1513,11 @@
         }
 
         SQLiteDatabase db = mOpenHelper.getWritableDatabase();
+        if (mOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) mOpenHelper).addDatabaseOpeningDebugLog(
+                    callerPkg + ";MmsSmsProvider.update;" + uri, false);
+        }
+
         int affectedRows = 0;
         switch(URI_MATCHER.match(uri)) {
             case URI_CONVERSATIONS_MESSAGES:
diff --git a/src/com/android/providers/telephony/ProviderUtil.java b/src/com/android/providers/telephony/ProviderUtil.java
index ddab594..c2b1bc8 100644
--- a/src/com/android/providers/telephony/ProviderUtil.java
+++ b/src/com/android/providers/telephony/ProviderUtil.java
@@ -18,6 +18,7 @@
 
 import android.annotation.NonNull;
 import android.annotation.Nullable;
+import android.app.ActivityManager;
 import android.content.ComponentName;
 import android.content.ContentValues;
 import android.content.Context;
@@ -40,6 +41,7 @@
 import com.android.internal.telephony.flags.FeatureFlagsImpl;
 
 import java.util.ArrayList;
+import java.util.Arrays;
 import java.util.List;
 import java.util.Map;
 import java.util.stream.Collectors;
@@ -49,6 +51,8 @@
  */
 public class ProviderUtil {
     private final static String TAG = "SmsProvider";
+    private static final String TELEPHONY_PROVIDER_PACKAGE = "com.android.providers.telephony";
+    private static final int PHONE_UID = 1001;
     /** Feature flags for Provider features. */
     public static final FeatureFlags sFeatureFlag = new FeatureFlagsImpl();
 
@@ -244,4 +248,34 @@
                     callerUserHandle);
         }
     }
+
+    /**
+     * Log all running processes of the telephony provider package.
+     */
+    public static void logRunningTelephonyProviderProcesses(@NonNull Context context) {
+        if (!sFeatureFlag.logMmsSmsDatabaseAccessInfo()) {
+            return;
+        }
+
+        ActivityManager am = context.getSystemService(ActivityManager.class);
+        List<ActivityManager.RunningAppProcessInfo> processInfos = am.getRunningAppProcesses();
+        StringBuilder sb = new StringBuilder();
+        for (ActivityManager.RunningAppProcessInfo processInfo : processInfos) {
+            if (Arrays.asList(processInfo.pkgList).contains(TELEPHONY_PROVIDER_PACKAGE)
+                    || processInfo.uid == PHONE_UID) {
+                sb.append("{ProcessName=");
+                sb.append(processInfo.processName);
+                sb.append(";PID=");
+                sb.append(processInfo.pid);
+                sb.append(";UID=");
+                sb.append(processInfo.uid);
+                sb.append(";pkgList=");
+                for (String pkg : processInfo.pkgList) {
+                    sb.append(pkg + ";");
+                }
+                sb.append("}");
+            }
+        }
+        Log.d(TAG, "RunningTelephonyProviderProcesses:" + sb.toString());
+    }
 }
diff --git a/src/com/android/providers/telephony/SmsProvider.java b/src/com/android/providers/telephony/SmsProvider.java
index f0e3fb6..0819e29 100644
--- a/src/com/android/providers/telephony/SmsProvider.java
+++ b/src/com/android/providers/telephony/SmsProvider.java
@@ -132,6 +132,7 @@
     @Override
     public Cursor query(Uri url, String[] projectionIn, String selection,
             String[] selectionArgs, String sort) {
+        String callingPackage = getCallingPackage();
         final int callingUid = Binder.getCallingUid();
         final UserHandle callerUserHandle = Binder.getCallingUserHandle();
 
@@ -160,6 +161,11 @@
         // Generate the body of the query.
         int match = sURLMatcher.match(url);
         SQLiteDatabase db = getReadableDatabase(match);
+        SQLiteOpenHelper sqLiteOpenHelper = getDBOpenHelper(match);
+        if (sqLiteOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) sqLiteOpenHelper).addDatabaseOpeningDebugLog(
+                    callingPackage + ";SmsProvider.query;" + url, true);
+        }
         switch (match) {
             case SMS_ALL:
                 constructQueryForBox(qb, Sms.MESSAGE_TYPE_ALL, smsTable);
@@ -741,6 +747,11 @@
         }
 
         SQLiteDatabase db = getWritableDatabase(match);
+        SQLiteOpenHelper sqLiteOpenHelper = getDBOpenHelper(match);
+        if (sqLiteOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) sqLiteOpenHelper).addDatabaseOpeningDebugLog(
+                    callerPkg + ";SmsProvider.insert;" + url, false);
+        }
 
         if (table.equals(TABLE_SMS)) {
             boolean addDate = false;
@@ -901,6 +912,9 @@
             return uri;
         } else {
             Log.e(TAG, "insert: failed!");
+            if (sqLiteOpenHelper instanceof MmsSmsDatabaseHelper) {
+                ((MmsSmsDatabaseHelper) sqLiteOpenHelper).printDatabaseOpeningDebugLog();
+            }
         }
 
         return null;
@@ -995,6 +1009,11 @@
         int count;
         int match = sURLMatcher.match(url);
         SQLiteDatabase db = getWritableDatabase(match);
+        SQLiteOpenHelper sqLiteOpenHelper = getDBOpenHelper(match);
+        if (sqLiteOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) sqLiteOpenHelper).addDatabaseOpeningDebugLog(
+                    getCallingPackage() + ";SmsProvider.delete;" + url, false);
+        }
         boolean notifyIfNotDefault = true;
         switch (match) {
             case SMS_ALL:
@@ -1213,6 +1232,11 @@
         boolean notifyIfNotDefault = true;
         int match = sURLMatcher.match(url);
         SQLiteDatabase db = getWritableDatabase(match);
+        SQLiteOpenHelper sqLiteOpenHelper = getDBOpenHelper(match);
+        if (sqLiteOpenHelper instanceof MmsSmsDatabaseHelper) {
+            ((MmsSmsDatabaseHelper) sqLiteOpenHelper).addDatabaseOpeningDebugLog(
+                    callerPkg + ";SmsProvider.update;" + url, false);
+        }
 
         switch (match) {
             case SMS_RAW_MESSAGE:
diff --git a/src/com/android/providers/telephony/TelephonyProvider.java b/src/com/android/providers/telephony/TelephonyProvider.java
index 773402c..f3ee592 100644
--- a/src/com/android/providers/telephony/TelephonyProvider.java
+++ b/src/com/android/providers/telephony/TelephonyProvider.java
@@ -3217,8 +3217,8 @@
                 Context.MODE_PRIVATE);
         mManagedApnEnforced = spEnforcedFile.getBoolean(ENFORCED_KEY, false);
 
+        ProviderUtil.logRunningTelephonyProviderProcesses(getContext());
         if (VDBG) log("onCreate:- ret true");
-
         return true;
     }