count total optout files downloaded

Author: lizk886

src/main/java/com/uid2/shared/store/salt/RotatingSaltProvider.java

@@ -77,6 +77,7 @@ public long getVersion(JsonObject metadata) {
 
     @Override
     public long loadContent(JsonObject metadata) throws Exception {
+        final long saltLoadingStart = System.currentTimeMillis();
         final JsonArray salts = metadata.getJsonArray("salts");
         final String firstLevelSalt = metadata.getString("first_level");
         final SaltFileParser saltFileParser = new SaltFileParser(
@@ -99,6 +100,10 @@ public long loadContent(JsonObject metadata) throws Exception {
                 .sorted(Comparator.comparing(SaltSnapshot::getEffective))
                 .collect(Collectors.toList()));
 
+        final long saltLoadingEnd = System.currentTimeMillis();
+        LOGGER.info("Salt loading completed in {} ms, {} snapshots loaded, {} total salts", 
+                saltLoadingEnd - saltLoadingStart, snapshots.size(), saltCount);
+
         return saltCount;
     }
 
@@ -129,9 +134,14 @@ private SaltSnapshot loadSnapshot(JsonObject spec, String firstLevelSalt, SaltFi
 
         final String path = spec.getString("location");
         Integer size = spec.getInteger("size");
+        
+        final long downloadStart = System.currentTimeMillis();
         SaltEntry[] entries = readInputStream(this.contentStreamProvider.download(path), saltFileParser, size);
-
-        LOGGER.info("Loaded {} salts", size);
+        final long downloadEnd = System.currentTimeMillis();
+        
+        // Only log filename portion to avoid potential presigned URL exposure
+        String fileName = path.substring(path.lastIndexOf('/') + 1);
+        LOGGER.info("Salt file {} downloaded in {} ms, loaded {} salts", fileName, downloadEnd - downloadStart, size);
         return new SaltSnapshot(effective, expires, entries, firstLevelSalt);
     }
 

src/main/java/com/uid2/shared/vertx/CloudSyncVerticle.java

@@ -65,6 +65,9 @@ public class CloudSyncVerticle extends AbstractVerticle {
     private WorkerExecutor uploadExecutor = null;
 
     private boolean isRefreshing = false;
+    
+    private long optoutTotalStart = 0;
+    private final Counter optoutFileCounter;
 
     public CloudSyncVerticle(String name, ICloudStorage cloudStorage, ICloudStorage localStorage,
                              ICloudSync cloudSync, JsonObject jsonConfig) {
@@ -148,6 +151,11 @@ public CloudSyncVerticle(String name, ICloudStorage cloudStorage, ICloudStorage
             .tag("store", name)
             .description("gauge for number of consecutive " + name + " store refresh failures")
             .register(Metrics.globalRegistry);
+
+        this.optoutFileCounter = "optout".equals(name) ? Counter
+            .builder("uid2_optout_files_downloaded_total")
+            .description("counter for total optout files downloaded from S3")
+            .register(Metrics.globalRegistry) : null;
     }
 
     @Override
@@ -223,6 +231,10 @@ private Future<Void> cloudRefresh() {
             return Future.succeededFuture();
         }
 
+        if ("optout".equals(this.name)) {
+            this.optoutTotalStart = System.currentTimeMillis();
+        }
+
         Promise<Void> refreshPromise = Promise.promise();
         this.isRefreshing = true;
         vertx.<Void>executeBlocking(blockBromise -> {
@@ -233,6 +245,13 @@ private Future<Void> cloudRefresh() {
         return refreshPromise.future()
             .onComplete(v -> {
                 this.isRefreshing = false;
+                if ("optout".equals(this.name) && this.optoutTotalStart > 0) {
+                    long totalDuration = System.currentTimeMillis() - this.optoutTotalStart;
+                    LOGGER.info("Optout sync completed in {} ms", totalDuration);
+                    Gauge.builder("uid2_optout_total_sync_duration_ms", () -> (double) totalDuration)
+                        .description("Total time taken for complete optout sync operation")
+                        .register(Metrics.globalRegistry);
+                }
                 emitRefreshedEvent();
             });
     }
@@ -373,6 +392,9 @@ private Future<Void> cloudDownloadFile(String s3Path) {
                 if (ar.succeeded()) {
                     vertx.eventBus().publish(this.eventDownloaded, this.cloudSync.toLocalPath(s3Path));
                     this.counterDownloaded.increment();
+                    if (optoutFileCounter != null) {
+                        optoutFileCounter.increment();
+                    }
                     LOGGER.info("S3 download completed: {} in {} ms", cloudStorage.mask(s3Path), downloadTimeMs);
                 } else {
                     this.counterDownloadFailures.increment();
@@ -391,11 +413,22 @@ private Future<Void> cloudDownloadFile(String s3Path) {
     }
 
     private void cloudDownloadBlocking(Promise<Void> promise, String s3Path) {
+        final long fileDownloadStart = System.currentTimeMillis();
         try {
             String localPath = this.cloudSync.toLocalPath(s3Path);
             try (InputStream cloudInput = this.cloudStorage.download(s3Path)) {
                 this.localStorage.upload(cloudInput, localPath);
             }
+            
+            // Log individual file download timing for optout files (avoid logging full path for security)
+            if ("optout".equals(this.name)) {
+                final long fileDownloadEnd = System.currentTimeMillis();
+                final long fileDownloadTime = fileDownloadEnd - fileDownloadStart;
+                // Only log filename portion to avoid potential presigned URL exposure
+                String fileName = s3Path.substring(s3Path.lastIndexOf('/') + 1);
+                LOGGER.info("Optout file {} downloaded in {} ms", fileName, fileDownloadTime);
+            }
+            
             promise.complete();
         } catch (Exception ex) {
             // Be careful as the s3Path may contain the pre-signed S3 token, so do not log the whole path

src/main/java/com/uid2/shared/vertx/RotatingStoreVerticle.java

@@ -78,8 +78,13 @@ public void start(Promise<Void> startPromise) throws Exception {
     }
 
     private void startRefresh(Promise<Void> promise) {
-        LOGGER.info("Starting " + this.storeName + " loading");
-        LOGGER.info("Starting {} store initial S3 loading", this.storeName);
+        // Only log detailed startup messages for salt stores (which are slow)
+        if ("salt".equals(this.storeName)) {
+            LOGGER.info("Starting {} store initial S3 loading", this.storeName);
+        } else {
+            // Fast stores: just log minimal startup message
+            LOGGER.info("Starting {} loading", this.storeName);
+        }
         final long startupRefreshStart = System.nanoTime();
 
         vertx.executeBlocking(p -> {
@@ -96,9 +101,15 @@ private void startRefresh(Promise<Void> promise) {
             if (ar.succeeded()) {
                 this.healthComponent.setHealthStatus(true);
                 promise.complete();
-                LOGGER.info("Successful " + this.storeName + " loading. Starting Background Refresh");
-                LOGGER.info("Successful {} store initial S3 loading in {} ms. Starting Background Refresh", 
-                    this.storeName, startupRefreshTimeMs);
+                
+                // Only log detailed timing for salt stores (which are slow), keep other stores minimal
+                if ("salt".equals(this.storeName)) {
+                    LOGGER.info("Successful {} store initial S3 loading in {} ms. Starting Background Refresh", 
+                        this.storeName, startupRefreshTimeMs);
+                } else {
+                    // Fast stores: just log completion without timing details to reduce noise
+                    LOGGER.info("Successful {} loading. Starting Background Refresh", this.storeName);
+                }
 
                 // Record startup-specific S3 store loading metric
                 Gauge.builder("uid2_operator_startup_store_refresh_duration_ms", () -> (double) startupRefreshTimeMs)