Add some logs to help debug test failures.

Bug: 154274672
Test: atest --test-mapping apex/blobstore
Change-Id: If51e92bac0b23824b953159d2ec5b028fb549464
diff --git a/tests/BlobStore/helper-app/src/com/android/cts/blob/helper/BlobStoreTestService.java b/tests/BlobStore/helper-app/src/com/android/cts/blob/helper/BlobStoreTestService.java
index a29fe58..362da8f 100644
--- a/tests/BlobStore/helper-app/src/com/android/cts/blob/helper/BlobStoreTestService.java
+++ b/tests/BlobStore/helper-app/src/com/android/cts/blob/helper/BlobStoreTestService.java
@@ -17,6 +17,7 @@
 
 import static android.os.storage.StorageManager.UUID_DEFAULT;
 
+import static com.android.utils.blob.Utils.TAG;
 import static com.android.utils.blob.Utils.writeToSession;
 
 import static com.google.common.truth.Truth.assertThat;
@@ -34,6 +35,7 @@
 import android.os.ParcelFileDescriptor;
 import android.os.Process;
 import android.os.RemoteException;
+import android.util.Log;
 
 import com.android.cts.blob.ICommandReceiver;
 import com.android.utils.blob.Utils;
@@ -64,6 +66,7 @@
                         session.allowPublicAccess();
                     }
 
+                    Log.d(TAG, "Committing session: " + sessionId + "; blob: " + blobHandle);
                     final CompletableFuture<Integer> callback = new CompletableFuture<>();
                     session.commit(getMainExecutor(), callback::complete);
                     return callback.get(timeoutSec, TimeUnit.SECONDS);
diff --git a/tests/BlobStore/src/com/android/cts/blob/BlobStoreManagerTest.java b/tests/BlobStore/src/com/android/cts/blob/BlobStoreManagerTest.java
index bb86844..86e0347 100644
--- a/tests/BlobStore/src/com/android/cts/blob/BlobStoreManagerTest.java
+++ b/tests/BlobStore/src/com/android/cts/blob/BlobStoreManagerTest.java
@@ -222,10 +222,7 @@
                 blobData.readFromSessionAndVerifyBytes(session,
                         202 /* offset */, 2002 /* length */);
 
-                final CompletableFuture<Integer> callback = new CompletableFuture<>();
-                session.commit(mContext.getMainExecutor(), callback::complete);
-                assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                        .isEqualTo(0);
+                commitSession(sessionId, session, blobData.getBlobHandle());
             }
         } finally {
             blobData.delete();
@@ -597,10 +594,7 @@
                 assertThat(pfd).isNotNull();
                 blobData.writeToFd(pfd.getFileDescriptor(), 0 /* offset */, 100 /* length */);
 
-                final CompletableFuture<Integer> callback = new CompletableFuture<>();
-                session.commit(mContext.getMainExecutor(), callback::complete);
-                assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                        .isEqualTo(0);
+                commitSession(sessionId, session, blobData.getBlobHandle());
 
                 // Verify that writing to the session after commit will throw.
                 assertThrows(IOException.class, () -> blobData.writeToFd(
@@ -623,10 +617,7 @@
             try (BlobStoreManager.Session session = mBlobStoreManager.openSession(sessionId)) {
                 blobData.writeToSession(session, 0, blobData.getFileSize() - 2);
 
-                final CompletableFuture<Integer> callback = new CompletableFuture<>();
-                session.commit(mContext.getMainExecutor(), callback::complete);
-                assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                        .isEqualTo(1);
+                commitSession(sessionId, session, blobData.getBlobHandle(), 1 /* expectedResult */);
             }
         } finally {
             blobData.delete();
@@ -648,10 +639,7 @@
                     out.write("wrong_data".getBytes(StandardCharsets.UTF_8));
                 }
 
-                final CompletableFuture<Integer> callback = new CompletableFuture<>();
-                session.commit(mContext.getMainExecutor(), callback::complete);
-                assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                        .isEqualTo(1);
+                commitSession(sessionId, session, blobData.getBlobHandle(), 1 /* expectedResult */);
             }
         } finally {
             blobData.delete();
@@ -723,6 +711,8 @@
             try (BlobStoreManager.Session session = mBlobStoreManager.openSession(sessionId)) {
                 blobData.writeToSession(session);
 
+                Log.d(TAG, "Committing session: " + sessionId
+                        + "; blob: " + blobData.getBlobHandle());
                 final CompletableFuture<Integer> callback = new CompletableFuture<>();
                 session.commit(mContext.getMainExecutor(), callback::complete);
                 assertThat(callback.get(commitTimeoutSec, TimeUnit.SECONDS))
@@ -804,10 +794,7 @@
                         blobData.readFromSessionAndVerifyBytes(session, partialFileSizeBytes,
                                 (int) (blobData.getFileSize() - partialFileSizeBytes));
 
-                        final CompletableFuture<Integer> callback = new CompletableFuture<>();
-                        session.commit(mContext.getMainExecutor(), callback::complete);
-                        assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                                .isEqualTo(0);
+                        commitSession(sessionId, session, blobData.getBlobHandle());
                     }
 
                     // Verify that blob can be accessed after committing.
@@ -849,10 +836,7 @@
                 assertThrows(SecurityException.class,
                         () -> mBlobStoreManager.openBlob(blobData.getBlobHandle()));
 
-                final CompletableFuture<Integer> callback = new CompletableFuture<>();
-                session.commit(mContext.getMainExecutor(), callback::complete);
-                assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                        .isEqualTo(0);
+                commitSession(sessionId, session, blobData.getBlobHandle());
             }
 
             // Verify that blob can be accessed after committing.
@@ -1066,10 +1050,7 @@
         try (BlobStoreManager.Session session = mBlobStoreManager.openSession(sessionId)) {
             blobData.writeToSession(session, partialFileSize,
                     session.getSize() - partialFileSize, blobData.getFileSize());
-            final CompletableFuture<Integer> callback = new CompletableFuture<>();
-            session.commit(mContext.getMainExecutor(), callback::complete);
-            assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                    .isEqualTo(0);
+            commitSession(sessionId, session, blobData.getBlobHandle());
         }
 
         acquireLease(mContext, blobData.getBlobHandle(), R.string.test_desc);
@@ -1119,10 +1100,7 @@
             blobData.writeToSession(session);
             session.allowPublicAccess();
 
-            final CompletableFuture<Integer> callback = new CompletableFuture<>();
-            session.commit(mContext.getMainExecutor(), callback::complete);
-            assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                    .isEqualTo(0);
+            commitSession(sessionId, session, blobData.getBlobHandle());
         }
 
         StorageStats afterStatsForPkg = storageStatsManager
@@ -1481,10 +1459,7 @@
         try (BlobStoreManager.Session session = mBlobStoreManager.openSession(sessionId)) {
             blobData.writeToSession(session, partialFileSize,
                     blobData.getFileSize() - partialFileSize, blobData.getFileSize());
-            final CompletableFuture<Integer> callback = new CompletableFuture<>();
-            session.commit(mContext.getMainExecutor(), callback::complete);
-            assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                    .isEqualTo(0);
+            commitSession(sessionId, session, blobData.getBlobHandle());
         }
     }
 
@@ -1751,14 +1726,25 @@
             if (accessModifier != null) {
                 accessModifier.modify(session);
             }
-            final CompletableFuture<Integer> callback = new CompletableFuture<>();
-            session.commit(mContext.getMainExecutor(), callback::complete);
-            assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
-                    .isEqualTo(expectedResult);
+            commitSession(sessionId, session, blobData.getBlobHandle(), expectedResult);
         }
         return sessionId;
     }
 
+    private void commitSession(long sessionId, BlobStoreManager.Session session,
+            BlobHandle blobHandle) throws Exception {
+        commitSession(sessionId, session, blobHandle, 0 /* expectedResult */);
+    }
+
+    private void commitSession(long sessionId, BlobStoreManager.Session session,
+            BlobHandle blobHandle, int expectedResult) throws Exception {
+        Log.d(TAG, "Committing session: " + sessionId + "; blob: " + blobHandle);
+        final CompletableFuture<Integer> callback = new CompletableFuture<>();
+        session.commit(mContext.getMainExecutor(), callback::complete);
+        assertThat(callback.get(TIMEOUT_COMMIT_CALLBACK_SEC, TimeUnit.SECONDS))
+                .isEqualTo(expectedResult);
+    }
+
     private interface AccessModifier {
         void modify(BlobStoreManager.Session session) throws Exception;
     }