From 2df86a73527d3996285b1449c11184ce88e5a770 Mon Sep 17 00:00:00 2001
From: "Andrey S." <andrewbass+saveourtool@gmail.com>
Date: Mon, 11 Nov 2024 15:40:31 +0300
Subject: [PATCH] Improve logging of storage initialization (both reactive and
 suspending parts) (#2991)

---
 .../common/storage/StorageInitializer.kt      | 28 +++++++++++++------
 .../cosv/backend/storage/CosvFileStorage.kt   | 23 ++++++++++++---
 2 files changed, 38 insertions(+), 13 deletions(-)

diff --git a/common/src/jvmMain/kotlin/com/saveourtool/common/storage/StorageInitializer.kt b/common/src/jvmMain/kotlin/com/saveourtool/common/storage/StorageInitializer.kt
index ae031fd6f8..ebde76d111 100644
--- a/common/src/jvmMain/kotlin/com/saveourtool/common/storage/StorageInitializer.kt
+++ b/common/src/jvmMain/kotlin/com/saveourtool/common/storage/StorageInitializer.kt
@@ -3,18 +3,16 @@ package com.saveourtool.common.storage
 import com.saveourtool.common.utils.getLogger
 import com.saveourtool.common.utils.info
 import com.saveourtool.common.utils.isNotNull
-import io.ktor.client.utils.*
-
 import org.slf4j.Logger
 import reactor.core.publisher.Mono
 import reactor.core.scheduler.Scheduler
 import reactor.core.scheduler.Schedulers
-
 import java.util.concurrent.atomic.AtomicBoolean
 import java.util.concurrent.atomic.AtomicInteger
-
 import kotlin.reflect.KClass
-import kotlinx.coroutines.*
+import kotlinx.coroutines.CoroutineDispatcher
+import kotlinx.coroutines.CoroutineScope
+import kotlinx.coroutines.launch
 import kotlinx.coroutines.reactor.asCoroutineDispatcher
 
 /**
@@ -64,7 +62,7 @@ class StorageInitializer(
                 }
                 if (wasDoInitCalled) {
                     log.info {
-                        "Initialization $storageName is done (reactive part)"
+                        "Initialization of $storageName done (reactive part); started: $isInitStarted; finished: ${isDone()}; pending steps: ${pendingStepsCount()}."
                     }
                 }
             }
@@ -76,10 +74,13 @@ class StorageInitializer(
             require(isInitFinishedCount.decrementAndGet() >= 0) {
                 "Init method cannot be called more than 1 time. Initialization $storageName already finished by another run"
             }
-            if (initResult.isNotNull()) {
-                log.info {
-                    "Initialization $storageName is done (suspending part)"
+            log.info {
+                val status = when {
+                    initResult.isNotNull() -> "done"
+                    else -> "ignored"
                 }
+
+                "Initialization of $storageName $status (suspending part); started: $isInitStarted; finished: ${isDone()}; pending steps: ${pendingStepsCount()}."
             }
         }
     }
@@ -122,6 +123,15 @@ class StorageInitializer(
         return action()
     }
 
+    /**
+     * @return the value of [isInitFinishedCount] in a human-readable format.
+     */
+    private fun pendingStepsCount(): String =
+            when (val pendingStepsCount = isInitFinishedCount.get()) {
+                0 -> "0"
+                else -> "\u2264 $pendingStepsCount"
+            }
+
     companion object {
         private val log: Logger = getLogger<StorageInitializer>()
         private val initScheduler: Scheduler = Schedulers.newBoundedElastic(5, Schedulers.DEFAULT_BOUNDED_ELASTIC_QUEUESIZE, "storage-init-")
diff --git a/cosv-backend/src/main/kotlin/com/saveourtool/cosv/backend/storage/CosvFileStorage.kt b/cosv-backend/src/main/kotlin/com/saveourtool/cosv/backend/storage/CosvFileStorage.kt
index 00ed1df33e..38dad590a0 100644
--- a/cosv-backend/src/main/kotlin/com/saveourtool/cosv/backend/storage/CosvFileStorage.kt
+++ b/cosv-backend/src/main/kotlin/com/saveourtool/cosv/backend/storage/CosvFileStorage.kt
@@ -7,11 +7,16 @@ import com.saveourtool.common.storage.ReactiveStorageWithDatabase
 import com.saveourtool.common.storage.deleteUnexpectedKeys
 import com.saveourtool.common.utils.blockingToFlux
 import com.saveourtool.common.utils.blockingToMono
+import com.saveourtool.common.utils.getLogger
+import com.saveourtool.common.utils.info
 import com.saveourtool.common.utils.switchIfEmptyToNotFound
+import org.slf4j.Logger
 import org.springframework.stereotype.Service
 import reactor.core.publisher.Flux
 import reactor.core.publisher.Mono
 import java.nio.ByteBuffer
+import java.util.concurrent.CompletableFuture.runAsync
+import java.util.concurrent.Executor
 
 /**
  * Storage for COSV files.
@@ -31,10 +36,16 @@ class CosvFileStorage(
      * Init method to remove deleted (unexpected) ids which are detected in storage, but missed in database
      */
     override fun doInit(underlying: DefaultStorageProjectReactor<CosvFile>): Mono<Unit> = Mono.fromFuture {
-        s3Operations.deleteUnexpectedKeys(
-            storageName = "${this::class.simpleName}",
-            s3KeyManager = s3KeyManager,
-        )
+        runAsync({ log.info { "COSV file storage: deleting unexpected keys..." } },
+            Executor(Runnable::run),
+        ).thenCompose {
+            s3Operations.deleteUnexpectedKeys(
+                storageName = "${this::class.simpleName}",
+                s3KeyManager = s3KeyManager,
+            )
+        }.thenApply {
+            log.info { "COSV file storage: unexpected keys deleted (if any)." }
+        }
     }.publishOn(s3Operations.scheduler)
 
     /**
@@ -54,4 +65,8 @@ class CosvFileStorage(
             "Not found CosvFile by id $keyId"
         }
         .flatMapMany { download(it) }
+
+    private companion object {
+        private val log: Logger = getLogger<CosvFileStorage>()
+    }
 }