Improve debug logging

Test: adb shell am instrument -w com.android.providers.contacts.tests
... with and without the verbose logging.

Test: manual tests
Change-Id: Ia685d15b6cce1e828766c63b08c477d1d7c114fd

2 files changed, 53 insertions, 8 deletions

diff --git a/src/com/android/providers/contacts/CallLogProvider.java b/src/com/android/providers/contacts/CallLogProvider.java
index 3d3678ef..452255fa 100644
--- a/src/com/android/providers/contacts/CallLogProvider.java
+++ b/src/com/android/providers/contacts/CallLogProvider.java
@@ -58,7 +58,7 @@ import java.util.concurrent.CountDownLatch;
  * Call log content provider.
  */
 public class CallLogProvider extends ContentProvider {
-    private static final String TAG = CallLogProvider.class.getSimpleName();
+    private static final String TAG = "CallLogProvider";
 
     public static final boolean VERBOSE_LOGGING = AbstractContactsProvider.VERBOSE_LOGGING;
 
@@ -184,6 +184,11 @@ public class CallLogProvider extends ContentProvider {
 
     @Override
     public boolean onCreate() {
+        if (VERBOSE_LOGGING) {
+            Log.v(TAG, "onCreate: " + this.getClass().getSimpleName()
+                    + " user=" + android.os.Process.myUserHandle().getIdentifier());
+        }
+
         setAppOps(AppOpsManager.OP_READ_CALL_LOG, AppOpsManager.OP_WRITE_CALL_LOG);
         if (Log.isLoggable(Constants.PERFORMANCE_TAG, Log.DEBUG)) {
             Log.d(Constants.PERFORMANCE_TAG, getProviderName() + ".onCreate start");
diff --git a/src/com/android/providers/contacts/VoicemailContentProvider.java b/src/com/android/providers/contacts/VoicemailContentProvider.java
index da0c3b7c..762177a7 100644
--- a/src/com/android/providers/contacts/VoicemailContentProvider.java
+++ b/src/com/android/providers/contacts/VoicemailContentProvider.java
@@ -36,8 +36,11 @@ import com.android.providers.contacts.CallLogDatabaseHelper.Tables;
 import com.android.providers.contacts.util.ContactsPermissions;
 import com.android.providers.contacts.util.SelectionBuilder;
 import com.android.providers.contacts.util.TypedUriMatcherImpl;
+import com.android.providers.contacts.util.UserUtils;
+
 import com.google.common.annotations.VisibleForTesting;
 import java.io.FileNotFoundException;
+import java.util.Arrays;
 import java.util.List;
 
 /**
@@ -48,12 +51,20 @@ import java.util.List;
  */
 public class VoicemailContentProvider extends ContentProvider
         implements VoicemailTable.DelegateHelper {
+    private static final String TAG = "VoicemailProvider";
+
+    public static final boolean VERBOSE_LOGGING = AbstractContactsProvider.VERBOSE_LOGGING;
+
     private VoicemailPermissions mVoicemailPermissions;
     private VoicemailTable.Delegate mVoicemailContentTable;
     private VoicemailTable.Delegate mVoicemailStatusTable;
 
     @Override
     public boolean onCreate() {
+        if (VERBOSE_LOGGING) {
+            Log.v(TAG, "onCreate: " + this.getClass().getSimpleName()
+                    + " user=" + android.os.Process.myUserHandle().getIdentifier());
+        }
         if (Log.isLoggable(Constants.PERFORMANCE_TAG, Log.INFO)) {
             Log.i(Constants.PERFORMANCE_TAG, "VoicemailContentProvider.onCreate start");
         }
@@ -110,6 +121,12 @@ public class VoicemailContentProvider extends ContentProvider
     @Override
     public Cursor query(Uri uri, String[] projection, String selection, String[] selectionArgs,
             String sortOrder) {
+        if (VERBOSE_LOGGING) {
+            Log.v(TAG, "query: uri=" + uri + "  projection=" + Arrays.toString(projection) +
+                    "  selection=[" + selection + "]  args=" + Arrays.toString(selectionArgs) +
+                    "  order=[" + sortOrder + "] CPID=" + Binder.getCallingPid() +
+                    " User=" + UserUtils.getCurrentUserHandle(getContext()));
+        }
         UriData uriData = checkPermissionsAndCreateUriDataForRead(uri);
         SelectionBuilder selectionBuilder = new SelectionBuilder(selection);
         selectionBuilder.addClause(getPackageRestrictionClause(true/*isQuery*/));
@@ -119,6 +136,12 @@ public class VoicemailContentProvider extends ContentProvider
 
     @Override
     public int update(Uri uri, ContentValues values, String selection, String[] selectionArgs) {
+        if (VERBOSE_LOGGING) {
+            Log.v(TAG, "update: uri=" + uri +
+                    "  selection=[" + selection + "]  args=" + Arrays.toString(selectionArgs) +
+                    "  values=[" + values + "] CPID=" + Binder.getCallingPid() +
+                    " User=" + UserUtils.getCurrentUserHandle(getContext()));
+        }
         UriData uriData = checkPermissionsAndCreateUriDataForWrite(uri, values);
         SelectionBuilder selectionBuilder = new SelectionBuilder(selection);
         selectionBuilder.addClause(getPackageRestrictionClause(false/*isQuery*/));
@@ -128,6 +151,12 @@ public class VoicemailContentProvider extends ContentProvider
 
     @Override
     public int delete(Uri uri, String selection, String[] selectionArgs) {
+        if (VERBOSE_LOGGING) {
+            Log.v(TAG, "delete: uri=" + uri +
+                    "  selection=[" + selection + "]  args=" + Arrays.toString(selectionArgs) +
+                    " CPID=" + Binder.getCallingPid() +
+                    " User=" + UserUtils.getCurrentUserHandle(getContext()));
+        }
         UriData uriData = checkPermissionsAndCreateUriDataForWrite(uri);
         SelectionBuilder selectionBuilder = new SelectionBuilder(selection);
         selectionBuilder.addClause(getPackageRestrictionClause(false/*isQuery*/));
@@ -136,14 +165,25 @@ public class VoicemailContentProvider extends ContentProvider
 
     @Override
     public ParcelFileDescriptor openFile(Uri uri, String mode) throws FileNotFoundException {
-        UriData uriData = null;
-        if (mode.equals("r")) {
-            uriData = checkPermissionsAndCreateUriDataForRead(uri);
-        } else {
-            uriData = checkPermissionsAndCreateUriDataForWrite(uri);
+        boolean success = false;
+        try {
+            UriData uriData = null;
+            if (mode.equals("r")) {
+                uriData = checkPermissionsAndCreateUriDataForRead(uri);
+            } else {
+                uriData = checkPermissionsAndCreateUriDataForWrite(uri);
+            }
+            // openFileHelper() relies on "_data" column to be populated with the file path.
+            final ParcelFileDescriptor ret = getTableDelegate(uriData).openFile(uriData, mode);
+            success = true;
+            return ret;
+        } finally {
+            if (VERBOSE_LOGGING) {
+                Log.v(TAG, "openFile uri=" + uri + " mode=" + mode + " success=" + success +
+                        " CPID=" + Binder.getCallingPid() +
+                        " User=" + UserUtils.getCurrentUserHandle(getContext()));
+            }
         }
-        // openFileHelper() relies on "_data" column to be populated with the file path.
-        return getTableDelegate(uriData).openFile(uriData, mode);
     }
 
     /** Returns the correct table delegate object that can handle this URI. */