Merge "Lazely initialize AccountManager debug table."
diff --git a/services/core/java/com/android/server/accounts/AccountManagerService.java b/services/core/java/com/android/server/accounts/AccountManagerService.java
index 426a0c15..d313c5e 100644
--- a/services/core/java/com/android/server/accounts/AccountManagerService.java
+++ b/services/core/java/com/android/server/accounts/AccountManagerService.java
@@ -241,9 +241,6 @@
         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 @@
                 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 @@
         if (accounts != null) {
             synchronized (accounts.dbLock) {
                 synchronized (accounts.cacheLock) {
-                    accounts.statementForLogging.close();
+                    accounts.accountsDb.closeDebugStatement();
                     accounts.accountsDb.close();
                 }
             }
@@ -5121,41 +5117,36 @@
 
             @Override
             public void run() {
-                SQLiteStatement logStatement = userAccount.statementForLogging;
-                logStatement.bindLong(1, accountId);
-                logStatement.bindString(2, action);
-                logStatement.bindString(3, mDateFormat.format(new Date()));
-                logStatement.bindLong(4, callingUid);
-                logStatement.bindString(5, tableName);
-                logStatement.bindLong(6, userDebugDbInsertionPoint);
-                try {
-                    logStatement.execute();
-                } catch (IllegalStateException e) {
-                    // Guard against crash, DB can already be closed
-                    // since this statement is executed on a handler thread
-                    Slog.w(TAG, "Failed to insert a log record. accountId=" + accountId
-                            + " action=" + action + " tableName=" + tableName + " Error: " + e);
-                } finally {
-                    logStatement.clearBindings();
+                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()));
+                    logStatement.bindLong(4, callingUid);
+                    logStatement.bindString(5, tableName);
+                    logStatement.bindLong(6, userDebugDbInsertionPoint);
+                    try {
+                        logStatement.execute();
+                    } catch (IllegalStateException e) {
+                        // Guard against crash, DB can already be closed
+                        // since this statement is executed on a handler thread
+                        Slog.w(TAG, "Failed to insert a log record. accountId=" + accountId
+                                + " action=" + action + " tableName=" + tableName + " Error: " + e);
+                    } finally {
+                        logStatement.clearBindings();
+                    }
                 }
             }
         }
-
-        LogRecordTask logTask = new LogRecordTask(action, tableName, accountId, userAccount,
-                callingUid, userAccount.debugDbInsertionPoint);
-        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();
+        long insertionPoint = userAccount.accountsDb.reserveDebugDbInsertionPoint();
+        if (insertionPoint != -1) {
+            LogRecordTask logTask = new LogRecordTask(action, tableName, accountId, userAccount,
+                    callingUid, insertionPoint);
+            mHandler.post(logTask);
+        }
     }
 
     public IBinder onBind(@SuppressWarnings("unused") Intent intent) {
diff --git a/services/core/java/com/android/server/accounts/AccountsDb.java b/services/core/java/com/android/server/accounts/AccountsDb.java
index 0c3d268..9fffc61 100644
--- a/services/core/java/com/android/server/accounts/AccountsDb.java
+++ b/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 @@
     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 @@
     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,31 +1283,72 @@
      * 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() {
-        SQLiteDatabase db = mDeDatabase.getReadableDatabase();
-        String queryCountDebugDbRows = "SELECT COUNT(*) FROM " + TABLE_DEBUG;
-        int size = (int) DatabaseUtils.longForQuery(db, queryCountDebugDbRows, null);
-        if (size < MAX_DEBUG_DB_SIZE) {
-            return size;
-        }
+    long calculateDebugTableInsertionPoint() {
+        try {
+            SQLiteDatabase db = mDeDatabase.getReadableDatabase();
+            String queryCountDebugDbRows = "SELECT COUNT(*) FROM " + TABLE_DEBUG;
+            int size = (int) DatabaseUtils.longForQuery(db, queryCountDebugDbRows, null);
+            if (size < MAX_DEBUG_DB_SIZE) {
+                return size;
+            }
 
-        // This query finds the smallest timestamp value (and if 2 records have
-        // same timestamp, the choose the lower id).
-        queryCountDebugDbRows = "SELECT " + DEBUG_TABLE_KEY +
-                " FROM " + TABLE_DEBUG +
-                " ORDER BY "  + DEBUG_TABLE_TIMESTAMP + "," + DEBUG_TABLE_KEY +
-                " LIMIT 1";
-        return (int) DatabaseUtils.longForQuery(db, queryCountDebugDbRows, null);
+            // This query finds the smallest timestamp value (and if 2 records have
+            // same timestamp, the choose the lower id).
+            queryCountDebugDbRows =
+                    "SELECT " + DEBUG_TABLE_KEY
+                    + " FROM " + TABLE_DEBUG
+                    + " ORDER BY "  + DEBUG_TABLE_TIMESTAMP + ","
+                    + 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,
diff --git a/services/tests/servicestests/src/com/android/server/accounts/AccountsDbTest.java b/services/tests/servicestests/src/com/android/server/accounts/AccountsDbTest.java
index ce9b552..65920fd 100644
--- a/services/tests/servicestests/src/com/android/server/accounts/AccountsDbTest.java
+++ b/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.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 @@
     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 @@
         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);
+    }
 }