[NO ISSUE] Add more logging to cloud-based storage accessors

- user model changes: no
- storage format changes: no
- interface changes: no

Details:
Add more logging when cloud-based accessors are used.

Change-Id: I2e2163755e396678eec87771d70978c6034c9237
Reviewed-on: https://asterix-gerrit.ics.uci.edu/c/asterixdb/+/17744
Integration-Tests: Jenkins <jenkins@fulliautomatix.ics.uci.edu>
Tested-by: Jenkins <jenkins@fulliautomatix.ics.uci.edu>
Reviewed-by: Hussain Towaileb <hussainht@gmail.com>
diff --git a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/AbstractCloudIOManager.java b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/AbstractCloudIOManager.java
index 3288444..0611688 100644
--- a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/AbstractCloudIOManager.java
+++ b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/AbstractCloudIOManager.java
@@ -127,6 +127,7 @@
     private void cleanupLocalFiles() throws HyracksDataException {
         Set<String> cloudFiles = cloudClient.listObjects(bucket, STORAGE_ROOT_DIR_NAME, IoUtil.NO_OP_FILTER);
         if (cloudFiles.isEmpty()) {
+            LOGGER.warn("No files in the cloud. Deleting all local files in partitions {}...", partitions);
             for (FileReference partitionPath : partitionPaths) {
                 if (localIoManager.exists(partitionPath)) {
                     // Clean local dir from all files
diff --git a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/LazyCloudIOManager.java b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/LazyCloudIOManager.java
index 0a83687..94fd5f8 100644
--- a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/LazyCloudIOManager.java
+++ b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/LazyCloudIOManager.java
@@ -97,7 +97,8 @@
             // Everything is cached, no need to invoke cloud-based accessor for read operations
             accessor = new LocalAccessor(cloudClient, bucket, localIoManager);
         }
-        LOGGER.info("The number of uncached files: {}", remainingUncachedFiles);
+
+        LOGGER.info("The number of uncached files: {}. Uncached files: {}", remainingUncachedFiles, cloudFiles);
     }
 
     @Override
@@ -134,10 +135,18 @@
     @Override
     public void delete(FileReference fileRef) throws HyracksDataException {
         accessor.doDelete(fileRef);
+        log("DELETE", fileRef);
     }
 
     @Override
     public void overwrite(FileReference fileRef, byte[] bytes) throws HyracksDataException {
         accessor.doOverwrite(fileRef, bytes);
+        log("WRITE", fileRef);
+    }
+
+    private void log(String op, FileReference fileReference) {
+        if (LOGGER.isDebugEnabled()) {
+            LOGGER.debug("{} {}", op, fileReference.getRelativePath());
+        }
     }
 }
diff --git a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/bulk/DeleteBulkCloudOperation.java b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/bulk/DeleteBulkCloudOperation.java
index c7cea90..f36d594 100644
--- a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/bulk/DeleteBulkCloudOperation.java
+++ b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/bulk/DeleteBulkCloudOperation.java
@@ -26,8 +26,11 @@
 import org.apache.hyracks.api.io.FileReference;
 import org.apache.hyracks.api.io.IIOManager;
 import org.apache.hyracks.control.nc.io.bulk.DeleteBulkOperation;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 
 public class DeleteBulkCloudOperation extends DeleteBulkOperation {
+    private static final Logger LOGGER = LogManager.getLogger();
     private final String bucket;
     private final ICloudClient cloudClient;
 
@@ -44,6 +47,9 @@
          *      Actually, is there a case where we delete multiple directories from the cloud?
          */
         List<String> paths = fileReferences.stream().map(FileReference::getRelativePath).collect(Collectors.toList());
+        if (LOGGER.isDebugEnabled()) {
+            LOGGER.debug("Bulk deleting: {}", paths);
+        }
         cloudClient.deleteObjects(bucket, paths);
 
         // Bulk delete locally as well
diff --git a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/clients/aws/s3/S3BufferedWriter.java b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/clients/aws/s3/S3BufferedWriter.java
index 2efd214..a6579c2 100644
--- a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/clients/aws/s3/S3BufferedWriter.java
+++ b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/clients/aws/s3/S3BufferedWriter.java
@@ -108,6 +108,8 @@
                 }
             }
         }
+
+        log("FINISHED");
     }
 
     @Override
@@ -117,6 +119,7 @@
         }
         s3Client.abortMultipartUpload(
                 AbortMultipartUploadRequest.builder().bucket(bucket).key(path).uploadId(uploadId).build());
+        LOGGER.warn("Multipart upload for {} was aborted", path);
     }
 
     private void completeMultipartUpload(CompleteMultipartUploadRequest request) throws HyracksDataException {
@@ -135,6 +138,13 @@
             CreateMultipartUploadResponse uploadResp = s3Client.createMultipartUpload(uploadRequest);
             uploadId = uploadResp.uploadId();
             partNumber = 1;
+            log("STARTED");
+        }
+    }
+
+    private void log(String op) {
+        if (LOGGER.isDebugEnabled()) {
+            LOGGER.debug("{} multipart upload for {}", op, path);
         }
     }
 }
diff --git a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/LocalAccessor.java b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/LocalAccessor.java
index 6c480ec..5715f43 100644
--- a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/LocalAccessor.java
+++ b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/LocalAccessor.java
@@ -70,7 +70,6 @@
 
     @Override
     public void doDelete(FileReference fileReference) throws HyracksDataException {
-        // Never delete the storage dir in cloud storage
         doCloudDelete(fileReference);
         localIoManager.delete(fileReference);
     }
diff --git a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/ReplaceableCloudAccessor.java b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/ReplaceableCloudAccessor.java
index e36ac66..f30bf82 100644
--- a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/ReplaceableCloudAccessor.java
+++ b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/lazy/accessor/ReplaceableCloudAccessor.java
@@ -71,11 +71,11 @@
             ByteBuffer writeBuffer = writeBufferProvider.getBuffer();
             try {
                 // TODO download for all partitions at once
-                LOGGER.info("Downloading {} from S3..", fileRef.getRelativePath());
+                LOGGER.info("Downloading {} ..", fileRef.getRelativePath());
                 CloudFileUtil.downloadFile(localIoManager, cloudClient, bucket, fileHandle, rwMode, syncMode,
                         writeBuffer);
                 localIoManager.close(fileHandle);
-                LOGGER.info("Finished downloading {} from S3..", fileRef.getRelativePath());
+                LOGGER.info("Finished downloading {}..", fileRef.getRelativePath());
             } finally {
                 writeBufferProvider.recycle(writeBuffer);
             }
@@ -98,7 +98,7 @@
         for (FileReference file : localFiles) {
             String path = file.getRelativePath();
             if (!cloudFiles.contains(path)) {
-                throw new IllegalStateException("Local file is not clean");
+                throw new IllegalStateException("Local file is not clean. Offending path: " + path);
             } else {
                 // No need to re-add it in the following loop
                 cloudFiles.remove(path);
@@ -134,6 +134,7 @@
             byte[] bytes = cloudClient.readAllBytes(bucket, fileRef.getRelativePath());
             if (bytes != null && !partitions.isEmpty()) {
                 // Download the missing file for subsequent reads
+                LOGGER.info("Downloading {} ..", fileRef.getRelativePath());
                 localIoManager.overwrite(fileRef, bytes);
                 decrementNumberOfUncachedFiles();
             }
@@ -162,7 +163,6 @@
         boolean existsLocally = localIoManager.exists(fileReference);
         cloudClient.write(bucket, fileReference.getRelativePath(), bytes);
         localIoManager.overwrite(fileReference, bytes);
-
         if (!existsLocally) {
             decrementNumberOfUncachedFiles();
         }
diff --git a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/util/CloudFileUtil.java b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/util/CloudFileUtil.java
index 79ddba1..4394361 100644
--- a/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/util/CloudFileUtil.java
+++ b/asterixdb/asterix-cloud/src/main/java/org/apache/asterix/cloud/util/CloudFileUtil.java
@@ -33,8 +33,12 @@
 import org.apache.hyracks.api.io.IIOManager;
 import org.apache.hyracks.control.nc.io.FileHandle;
 import org.apache.hyracks.control.nc.io.IOManager;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
 
 public class CloudFileUtil {
+    private static final Logger LOGGER = LogManager.getLogger();
+
     private CloudFileUtil() {
     }
 
@@ -73,6 +77,7 @@
             String path = file.getRelativePath();
             if (!cloudFiles.contains(path)) {
                 // Delete local files that do not exist in cloud storage (the ground truth for valid files)
+                logDeleteFile(file);
                 localFilesIter.remove();
                 ioManager.delete(file);
             } else {
@@ -123,4 +128,10 @@
         writeBuffer.clear();
         return written;
     }
+
+    private static void logDeleteFile(FileReference fileReference) {
+        if (LOGGER.isDebugEnabled()) {
+            LOGGER.debug("Deleting {} from the local cache as it doesn't exists in the cloud", fileReference);
+        }
+    }
 }