Merge "Lazely initialize AccountManager debug table."

am: 18cccec624

Change-Id: If7e12145dfa8e104777956bdab9a743f3f860e24

services/core/java/com/android/server/accounts/AccountManagerService.java

@@ -241,9 +241,6 @@ public class AccountManagerService
         private final HashMap<Account, AtomicReference<String>> previousNameCache =
                 new HashMap<Account, AtomicReference<String>>();
 
-        private int debugDbInsertionPoint = -1;
-        private SQLiteStatement statementForLogging; // TODO Move to AccountsDb
-
         UserAccounts(Context context, int userId, File preNDbFile, File deDbFile) {
             this.userId = userId;
             synchronized (dbLock) {
@@ -1299,7 +1296,6 @@ public class AccountManagerService
                 File preNDbFile = new File(mInjector.getPreNDatabaseName(userId));
                 File deDbFile = new File(mInjector.getDeDatabaseName(userId));
                 accounts = new UserAccounts(mContext, userId, preNDbFile, deDbFile);
-                initializeDebugDbSizeAndCompileSqlStatementForLogging(accounts);
                 mUsers.append(userId, accounts);
                 purgeOldGrants(accounts);
                 validateAccounts = true;
@@ -1399,7 +1395,7 @@ public class AccountManagerService
         if (accounts != null) {
             synchronized (accounts.dbLock) {
                 synchronized (accounts.cacheLock) {
-                    accounts.statementForLogging.close();
+                    accounts.accountsDb.closeDebugStatement();
                     accounts.accountsDb.close();
                 }
             }
@@ -5121,7 +5117,11 @@ public class AccountManagerService
 
             @Override
             public void run() {
-                SQLiteStatement logStatement = userAccount.statementForLogging;
+                synchronized (userAccount.accountsDb.mDebugStatementLock) {
+                    SQLiteStatement logStatement = userAccount.accountsDb.getStatementForLogging();
+                    if (logStatement == null) {
+                        return; // Can't log.
+                    }
                     logStatement.bindLong(1, accountId);
                     logStatement.bindString(2, action);
                     logStatement.bindString(3, mDateFormat.format(new Date()));
@@ -5140,22 +5140,13 @@ public class AccountManagerService
                     }
                 }
             }
-
+        }
+        long insertionPoint = userAccount.accountsDb.reserveDebugDbInsertionPoint();
+        if (insertionPoint != -1) {
             LogRecordTask logTask = new LogRecordTask(action, tableName, accountId, userAccount,
-                callingUid, userAccount.debugDbInsertionPoint);
+                    callingUid, insertionPoint);
-        userAccount.debugDbInsertionPoint = (userAccount.debugDbInsertionPoint + 1)
-                % AccountsDb.MAX_DEBUG_DB_SIZE;
             mHandler.post(logTask);
         }
-
-    /*
-     * This should only be called once to compile the sql statement for logging
-     * and to find the insertion point.
-     */
-    private void initializeDebugDbSizeAndCompileSqlStatementForLogging(UserAccounts userAccount) {
-        userAccount.debugDbInsertionPoint = userAccount.accountsDb
-                .calculateDebugTableInsertionPoint();
-        userAccount.statementForLogging = userAccount.accountsDb.compileSqlStatementForLogging();
     }
 
     public IBinder onBind(@SuppressWarnings("unused") Intent intent) {

services/core/java/com/android/server/accounts/AccountsDb.java

@@ -17,11 +17,13 @@
 package com.android.server.accounts;
 
 import android.accounts.Account;
+import android.annotation.Nullable;
 import android.content.ContentValues;
 import android.content.Context;
 import android.database.Cursor;
 import android.database.DatabaseUtils;
 import android.database.sqlite.SQLiteDatabase;
+import android.database.sqlite.SQLiteException;
 import android.database.sqlite.SQLiteOpenHelper;
 import android.database.sqlite.SQLiteStatement;
 import android.os.FileUtils;
@@ -56,7 +58,6 @@ class AccountsDb implements AutoCloseable {
     private static final int CE_DATABASE_VERSION = 10;
     private static final int DE_DATABASE_VERSION = 3; // Added visibility support in O
 
-
     static final String TABLE_ACCOUNTS = "accounts";
     private static final String ACCOUNTS_ID = "_id";
     private static final String ACCOUNTS_NAME = "name";
@@ -183,6 +184,10 @@ class AccountsDb implements AutoCloseable {
     private final Context mContext;
     private final File mPreNDatabaseFile;
 
+    final Object mDebugStatementLock = new Object();
+    private volatile long mDebugDbInsertionPoint = -1;
+    private volatile SQLiteStatement mDebugStatementForLogging; // not thread safe.
+
     AccountsDb(DeDatabaseHelper deDatabase, Context context, File preNDatabaseFile) {
         mDeDatabase = deDatabase;
         mContext = context;
@@ -1278,7 +1283,8 @@ class AccountsDb implements AutoCloseable {
      * Finds the row key where the next insertion should take place. Returns number of rows
      * if it is less {@link #MAX_DEBUG_DB_SIZE}, otherwise finds the lowest number available.
      */
-    int calculateDebugTableInsertionPoint() {
+    long calculateDebugTableInsertionPoint() {
+        try {
             SQLiteDatabase db = mDeDatabase.getReadableDatabase();
             String queryCountDebugDbRows = "SELECT COUNT(*) FROM " + TABLE_DEBUG;
             int size = (int) DatabaseUtils.longForQuery(db, queryCountDebugDbRows, null);
@@ -1288,21 +1294,61 @@ class AccountsDb implements AutoCloseable {
 
             // This query finds the smallest timestamp value (and if 2 records have
             // same timestamp, the choose the lower id).
-        queryCountDebugDbRows = "SELECT " + DEBUG_TABLE_KEY +
+            queryCountDebugDbRows =
-                " FROM " + TABLE_DEBUG +
+                    "SELECT " + DEBUG_TABLE_KEY
-                " ORDER BY "  + DEBUG_TABLE_TIMESTAMP + "," + DEBUG_TABLE_KEY +
+                    + " FROM " + TABLE_DEBUG
-                " LIMIT 1";
+                    + " ORDER BY "  + DEBUG_TABLE_TIMESTAMP + ","
-        return (int) DatabaseUtils.longForQuery(db, queryCountDebugDbRows, null);
+                    + DEBUG_TABLE_KEY
+                    + " LIMIT 1";
+            return DatabaseUtils.longForQuery(db, queryCountDebugDbRows, null);
+        } catch (SQLiteException e) {
+            Log.e(TAG, "Failed to open debug table" + e);
+            return -1;
+        }
     }
 
     SQLiteStatement compileSqlStatementForLogging() {
-        // TODO b/31708085 Fix debug logging - it eagerly opens database for write without a need
         SQLiteDatabase db = mDeDatabase.getWritableDatabase();
         String sql = "INSERT OR REPLACE INTO " + AccountsDb.TABLE_DEBUG
                 + " VALUES (?,?,?,?,?,?)";
         return db.compileStatement(sql);
     }
 
+    /**
+     * Returns statement for logging or {@code null} on database open failure.
+     * Returned value must be guarded by {link #debugStatementLock}
+     */
+    @Nullable SQLiteStatement getStatementForLogging() {
+        if (mDebugStatementForLogging != null) {
+            return mDebugStatementForLogging;
+        }
+        try {
+            mDebugStatementForLogging =  compileSqlStatementForLogging();
+            return mDebugStatementForLogging;
+        } catch (SQLiteException e) {
+            Log.e(TAG, "Failed to open debug table" + e);
+            return null;
+        }
+    }
+
+    void closeDebugStatement() {
+        synchronized (mDebugStatementLock) {
+            if (mDebugStatementForLogging != null) {
+                mDebugStatementForLogging.close();
+                mDebugStatementForLogging = null;
+            }
+        }
+    }
+
+    long reserveDebugDbInsertionPoint() {
+        if (mDebugDbInsertionPoint == -1) {
+            mDebugDbInsertionPoint = calculateDebugTableInsertionPoint();
+            return mDebugDbInsertionPoint;
+        }
+        mDebugDbInsertionPoint = (mDebugDbInsertionPoint + 1) % MAX_DEBUG_DB_SIZE;
+        return mDebugDbInsertionPoint;
+    }
+
     void dumpDebugTable(PrintWriter pw) {
         SQLiteDatabase db = mDeDatabase.getReadableDatabase();
         Cursor cursor = db.query(TABLE_DEBUG, null,

services/tests/servicestests/src/com/android/server/accounts/AccountsDbTest.java

@@ -17,12 +17,21 @@
 
 package com.android.server.accounts;
 
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertFalse;
+import static org.junit.Assert.assertNull;
+import static org.junit.Assert.assertTrue;
+import static org.mockito.Matchers.anyString;
+import static org.mockito.Mockito.times;
+import static org.mockito.Mockito.verify;
+
 import android.accounts.Account;
 import android.content.Context;
 import android.database.Cursor;
+import android.database.sqlite.SQLiteStatement;
+import android.os.Build;
 import android.support.test.InstrumentationRegistry;
 import android.support.test.runner.AndroidJUnit4;
-import android.os.Build;
 import android.test.suitebuilder.annotation.SmallTest;
 import android.util.Pair;
 
@@ -30,17 +39,15 @@ import org.junit.After;
 import org.junit.Before;
 import org.junit.Test;
 import org.junit.runner.RunWith;
+import org.mockito.Mock;
+import org.mockito.MockitoAnnotations;
 
 import java.io.File;
+import java.io.PrintWriter;
 import java.util.Arrays;
 import java.util.List;
 import java.util.Map;
 
-import static org.junit.Assert.assertEquals;
-import static org.junit.Assert.assertFalse;
-import static org.junit.Assert.assertNull;
-import static org.junit.Assert.assertTrue;
-
 /**
  * Tests for {@link AccountsDb}.
  * <p>Run with:<pre>
@@ -63,8 +70,11 @@ public class AccountsDbTest {
     private File deDb;
     private File ceDb;
 
+    @Mock private PrintWriter mMockWriter;
+
     @Before
     public void setUp() {
+        MockitoAnnotations.initMocks(this);
         Context context = InstrumentationRegistry.getContext();
         preNDb = new File(context.getCacheDir(), PREN_DB);
         ceDb = new File(context.getCacheDir(), CE_DB);
@@ -443,4 +453,33 @@ public class AccountsDbTest {
         assertTrue(mAccountsDb.deleteDeAccount(accId)); // Trigger should remove visibility.
         assertNull(mAccountsDb.findAccountVisibility(account, packageName1));
     }
+
+    @Test
+    public void testDumpDebugTable() {
+        long accId = 10;
+        long insertionPoint = mAccountsDb.reserveDebugDbInsertionPoint();
+
+        SQLiteStatement logStatement = mAccountsDb.getStatementForLogging();
+
+        logStatement.bindLong(1, accId);
+        logStatement.bindString(2, "action");
+        logStatement.bindString(3, "date");
+        logStatement.bindLong(4, 10);
+        logStatement.bindString(5, "table");
+        logStatement.bindLong(6, insertionPoint);
+        logStatement.execute();
+
+        mAccountsDb.dumpDebugTable(mMockWriter);
+
+        verify(mMockWriter, times(3)).println(anyString());
+    }
+
+    @Test
+    public void testReserveDebugDbInsertionPoint() {
+        long insertionPoint = mAccountsDb.reserveDebugDbInsertionPoint();
+        long insertionPoint2 = mAccountsDb.reserveDebugDbInsertionPoint();
+
+        assertEquals(0, insertionPoint);
+        assertEquals(1, insertionPoint2);
+    }
 }