refac: add debug loggings and refactor outputLogger (#377)

Add more debug loggings and refactor outputLogger with more information

src/main/kotlin/com/statsig/sdk/Evaluator.kt

@@ -43,6 +43,7 @@ internal class Evaluator(
     private var layerOverrides: MutableMap<String, Map<String, Any>> = HashMap()
     private var hashLookupTable: MutableMap<String, ULong> = HashMap()
     private val gson = Utils.getGson()
+    private val logger = options.customLogger
 
     private val calendarOne = Calendar.getInstance()
     private val calendarTwo = Calendar.getInstance()
@@ -245,12 +246,14 @@ internal class Evaluator(
 
         if (specStore.getEvaluationReason() == EvaluationReason.UNINITIALIZED) {
             ctx.evaluation.evaluationDetails = createEvaluationDetails(EvaluationReason.UNINITIALIZED)
+            logger.debug("SpecStore is uninitialized, returning UNINITIALIZED evaluation for layer: $layerName")
             return
         }
 
         val layer = specStore.getLayerConfig(layerName)
         if (layer == null) {
             ctx.evaluation = this.getUnrecognizedEvaluation()
+            logger.debug("Layer not found: $layerName, returning unrecognized evaluation")
             return
         }
         this.evaluateLayer(ctx, layer)
@@ -271,12 +274,14 @@ internal class Evaluator(
         }
 
         if (specStore.getEvaluationReason() == EvaluationReason.UNINITIALIZED) {
+            logger.debug("SpecStore is uninitialized, returning UNINITIALIZED evaluation for gate: $gateName")
             ctx.evaluation.evaluationDetails = createEvaluationDetails(EvaluationReason.UNINITIALIZED)
             return
         }
 
         val gate = specStore.getGate(gateName)
         if (gate == null) {
+            logger.debug("Gate not found: $gateName, returning unrecognized evaluation")
             ctx.evaluation = this.getUnrecognizedEvaluation()
             return
         }
@@ -308,6 +313,7 @@ internal class Evaluator(
 
         val stickyValues = userPersistedValues[config.name]
         if (stickyValues != null) {
+            logger.debug("Sticky Evaluation found for experiment: ${config.name} with value: $stickyValues")
             val stickyEvaluation = ConfigEvaluation.fromStickyValues(stickyValues, this.specStore.getInitTime())
             ctx.evaluation = stickyEvaluation
             return
@@ -337,6 +343,7 @@ internal class Evaluator(
         }
         val stickyValues = userPersistedValues[config.name]
         if (stickyValues != null) {
+            logger.debug("Sticky Evaluation found for layer: ${config.name} with value: $stickyValues")
             val stickyEvaluation = ConfigEvaluation.fromStickyValues(stickyValues, this.specStore.getInitTime())
             val delegate = stickyEvaluation.configDelegate
             val delegateSpec = if (delegate != null) this.specStore.getConfig(delegate) else null
@@ -370,6 +377,7 @@ internal class Evaluator(
         ctx.evaluation.evaluationDetails = createEvaluationDetails(specStore.getEvaluationReason())
 
         if (!config.enabled) {
+            logger.debug("${config.name} is not enabled.")
             ctx.evaluation.booleanValue = false
             ctx.evaluation.jsonValue = config.defaultValue
             ctx.evaluation.ruleID = Const.DISABLED
@@ -482,7 +490,7 @@ internal class Evaluator(
                 conditionFromString(condition.type.lowercase())
             } catch (e: java.lang.IllegalArgumentException) {
                 errorBoundary.logException("evaluateCondition:condition", e)
-                options.customLogger.warning("[Statsig]: An exception was caught:  $e")
+                logger.error("An exception was caught when evaluating conditions:  $e")
                 null
             }
 
@@ -983,7 +991,7 @@ internal class Evaluator(
             false
         } catch (e: Exception) {
             errorBoundary.logException("versionCompareHelper", e)
-            options.customLogger.warning("[Statsig]: An exception was caught:  $e")
+            logger.warn("An exception was caught:  $e")
             false
         }
     }

src/main/kotlin/com/statsig/sdk/SpecStore.kt

@@ -194,7 +194,7 @@ internal class SpecStore(
             configString = gson.toJson(configSpecs)
         } catch (e: Exception) {
             errorBoundary.logException("fireRulesUpdatedCallback", e)
-            options.customLogger.warning("[Statsig]: An exception was caught:  $e")
+            options.customLogger.error("An exception was caught when fire callback:  $e")
         }
 
         if (configString.isEmpty()) {
@@ -335,7 +335,7 @@ internal class SpecStore(
             )
         } catch (e: Exception) {
             errorBoundary.logException("downloadIDList", e)
-            options.customLogger.warning("[Statsig]: An exception was caught:  $e")
+            options.customLogger.error("An exception was caught when downloading ID lists:  $e")
             maybeDiagnostics?.markEnd(
                 KeyType.GET_ID_LIST,
                 false,

src/main/kotlin/com/statsig/sdk/SpecUpdater.kt

@@ -29,6 +29,7 @@ internal class SpecUpdater(
     private var idListCallback: suspend (config: Map<String, IDList>) -> Unit = { }
     private var backgroundDownloadConfigs: Job? = null
     private var backgroundDownloadIDLists: Job? = null
+    private val logger = options.customLogger
 
     private val gson = Utils.getGson()
     private inline fun <reified T> Gson.fromJson(json: String) = fromJson<T>(json, object : TypeToken<T>() {}.type)
@@ -149,7 +150,7 @@ internal class SpecUpdater(
             return Pair(gson.fromJson(specs, APIDownloadedConfigs::class.java), null)
         } catch (e: JsonSyntaxException) {
             errorBoundary.logException("parseConfigSpecs", e)
-            options.customLogger.warning("[Statsig]: An exception was caught:  $e")
+            logger.error("An exception was caught when parsing config specs:  $e")
             return Pair(null, FailureDetails(FailureReason.PARSE_RESPONSE_ERROR, exception = e))
         }
     }
@@ -166,7 +167,7 @@ internal class SpecUpdater(
             return Pair(configs, null)
         } catch (e: Exception) {
             errorBoundary.logException("downloadConfigSpecs", e)
-            options.customLogger.warning("[Statsig]: An exception was caught:  $e")
+            logger.warn("An exception was caught:  $e")
             return Pair(null, FailureDetails(FailureReason.PARSE_RESPONSE_ERROR, exception = e))
         }
     }
@@ -179,7 +180,7 @@ internal class SpecUpdater(
             return gson.fromJson<Map<String, IDList>>(lists)
         } catch (e: JsonSyntaxException) {
             errorBoundary.logException("parseIDLists", e)
-            options.customLogger.warning("[Statsig]: An exception was caught:  $e")
+            logger.warn("An exception was caught when parsing ID lists:  $e")
         }
         return null
     }

src/main/kotlin/com/statsig/sdk/Statsig.kt

@@ -752,9 +752,9 @@ class Statsig {
             val initialized = isInitialized()
             if (!initialized) {
                 if (::statsigServer.isInitialized) {
-                    statsigServer.getCustomLogger().warning("Call and wait for initialize to complete before calling SDK methods.")
+                    statsigServer.getCustomLogger().warn("Call and wait for initialize to complete before calling SDK methods.")
                 } else {
-                    println("Call and wait for initialize to complete before calling SDK methods.")
+                    println("[Statsig] Call and wait for initialize to complete before calling SDK methods.") // this happened before we init so use println
                 }
             }
             return initialized

src/main/kotlin/com/statsig/sdk/StatsigLogger.kt

@@ -57,6 +57,8 @@ internal class StatsigLogger(
     private val gson = Utils.getGson()
     internal var diagnostics: Diagnostics? = null
     private var eventQueueSize: Int? = null
+    private val logger = statsigOptions.customLogger
+
     fun log(event: StatsigEvent) {
         if (statsigOptions.disableAllLogging) {
             return
@@ -208,6 +210,7 @@ internal class StatsigLogger(
             addDiagnostics(ContextType.API_CALL)
             addDiagnostics(ContextType.GET_CLIENT_INITIALIZE_RESPONSE)
             if (events.size() == 0) {
+                logger.debug("Event queue is empty.")
                 return@withContext
             }
 

src/main/kotlin/com/statsig/sdk/StatsigOptions.kt

@@ -5,19 +5,89 @@ import com.statsig.sdk.datastore.IDataStore
 import com.statsig.sdk.network.STATSIG_API_URL_BASE
 import com.statsig.sdk.persistent_storage.IUserPersistentStorage
 import com.statsig.sdk.persistent_storage.UserPersistedValues
+import java.time.Instant
+import java.time.format.DateTimeFormatter
+import java.time.temporal.ChronoUnit
 
 private const val TIER_KEY: String = "tier"
 private const val DEFAULT_INIT_TIME_OUT_MS: Long = 3000L
 private const val CONFIG_SYNC_INTERVAL_MS: Long = 10 * 1000
 private const val ID_LISTS_SYNC_INTERVAL_MS: Long = 60 * 1000
+
+enum class LogLevel(val value: Int) {
+    NONE(0),
+    DEBUG(1),
+    INFO(2),
+    WARN(3),
+    ERROR(4);
+
+    fun getLevelString(): String {
+        return when (this) {
+            ERROR -> "ERROR"
+            WARN -> "WARN"
+            INFO -> "INFO"
+            DEBUG -> "DEBUG"
+            NONE -> ""
+        }
+    }
+}
+
+object OutputLogger {
+    var logLevel: LogLevel = LogLevel.WARN
+
+    fun error(message: String) {
+        logMessage(LogLevel.ERROR, message)
+    }
+
+    fun warn(message: String) {
+        logMessage(LogLevel.WARN, message)
+    }
+
+    fun info(message: String) {
+        logMessage(LogLevel.INFO, message)
+    }
+
+    fun debug(message: String) {
+        logMessage(LogLevel.DEBUG, message)
+    }
+
+    private fun logMessage(level: LogLevel, message: String) {
+        if (level.value < logLevel.value) return
+
+        val timestamp = DateTimeFormatter.ISO_INSTANT.format(Instant.now().truncatedTo(ChronoUnit.MILLIS))
+        println("$timestamp ${level.getLevelString()} [Statsig] $message")
+    }
+}
+
+// Example Logger Interface you might use
+interface LoggerInterface {
+    fun error(message: String)
+    fun warn(message: String)
+    fun info(message: String)
+    fun debug(message: String)
+    fun setLogLevel(level: LogLevel)
+}
+
+// Example implementation of LoggerInterface
 private val defaultLogger = object : LoggerInterface {
+    override fun error(message: String) {
+        OutputLogger.error(message)
+    }
 
-    override fun warning(message: String) {
-        println(message)
+    override fun warn(message: String) {
+        OutputLogger.warn(message)
     }
 
     override fun info(message: String) {
-        println(message)
+        OutputLogger.info(message)
+    }
+
+    override fun debug(message: String) {
+        OutputLogger.debug(message)
+    }
+
+    override fun setLogLevel(level: LogLevel) {
+        OutputLogger.logLevel = LogLevel.WARN
     }
 }
 
@@ -29,11 +99,6 @@ fun interface RulesUpdatedCallback {
     fun accept(rules: String)
 }
 
-interface LoggerInterface {
-    fun warning(message: String)
-    fun info(message: String)
-}
-
 /**
  * An object of properties for initializing the sdk with advanced options
  * @property api the api endpoint to use for initialization and logging

src/main/kotlin/com/statsig/sdk/StatsigServer.kt

@@ -271,6 +271,7 @@ private class StatsigServerImpl() :
     private lateinit var logger: StatsigLogger
     private lateinit var evaluator: Evaluator
     private lateinit var diagnostics: Diagnostics
+    private lateinit var outputLogger: LoggerInterface
     private var options: StatsigOptions = StatsigOptions()
     private val mutex = Mutex()
     private val statsigMetadata = StatsigMetadata()
@@ -290,6 +291,7 @@ private class StatsigServerImpl() :
         statsigScope = CoroutineScope(statsigJob + coroutineExceptionHandler)
         transport = StatsigTransport(serverSecret, options, statsigMetadata, statsigScope, errorBoundary, sdkConfigs)
         logger = StatsigLogger(statsigScope, transport, statsigMetadata, options, sdkConfigs)
+        options.customLogger.also { outputLogger = it }
         this.options = options
     }
 
@@ -307,6 +309,7 @@ private class StatsigServerImpl() :
             {
                 mutex.withLock { // Prevent multiple coroutines from calling this at once.
                     if (this::evaluator.isInitialized && evaluator.isInitialized) {
+                        outputLogger.warn("Cannot re-initialize server that has shutdown. Please recreate the server connection.")
                         throw StatsigIllegalStateException(
                             "Cannot re-initialize server that has shutdown. Please recreate the server connection.",
                         )
@@ -328,6 +331,7 @@ private class StatsigServerImpl() :
                         dataStoreSetUp()
                     }
                     endInitDiagnostics(failureDetails == null)
+                    outputLogger.info("Statsig Server has been successfully initialized.")
                     return@capture InitializationDetails(
                         System.currentTimeMillis() - setupStartTime,
                         isSDKReady = true,
@@ -337,6 +341,7 @@ private class StatsigServerImpl() :
                 }
             },
             {
+                outputLogger.warn("Statsig Server has not been successfully initialized.")
                 return@capture InitializationDetails(
                     System.currentTimeMillis() - setupStartTime,
                     false,
@@ -1188,15 +1193,15 @@ private class StatsigServerImpl() :
 
     private fun isSDKInitialized(): Boolean {
         if (!isInitialized()) { // for multi-instance, if the server has not been initialized
-            getCustomLogger().warning("Call and wait for initialize StatsigServer to complete before calling SDK methods.")
+            getCustomLogger().warn("Call and wait for initialize StatsigServer to complete before calling SDK methods.")
             return false
         }
         if (statsigJob.isCancelled || statsigJob.isCompleted) {
-            options.customLogger.info("StatsigServer was shutdown")
+            outputLogger.info("StatsigServer was shutdown.")
             return false
         }
         if (!this::evaluator.isInitialized || !evaluator.isInitialized) { // If the server was never initialized
-            options.customLogger.warning("Must initialize a server before calling other APIs")
+            outputLogger.warn("Must initialize a server before calling other APIs.")
             return false
         }
         return true
@@ -1252,7 +1257,7 @@ private class StatsigServerImpl() :
                 throw e
             }
             server.getCustomLogger()
-                .info("[Statsig]: Shutting down Statsig because of unhandled exception from your server")
+                .info("Shutting down Statsig because of unhandled exception from your server")
             server.shutdown()
             throw e
         }

src/main/kotlin/com/statsig/sdk/datastore/LocalFileDataStore.kt

@@ -24,6 +24,7 @@ class LocalFileDataStore @JvmOverloads constructor(
     var autoUpdate: Boolean = false,
 ) : IDataStore() {
     private lateinit var options: StatsigOptions
+
     override var dataStoreKey: String
         get() = filePath
         set(value) {
@@ -50,14 +51,14 @@ class LocalFileDataStore @JvmOverloads constructor(
 
                 file.createNewFile()
             } catch (e: Exception) {
-                options.customLogger.warning("[Statsig]: An error occurred while creating the file: ${e.message}")
+                options.customLogger.error("An error occurred while creating the file: ${e.message}")
             }
         }
     }
 
     override fun get(key: String): String? {
         if (key != dataStoreKey) {
-            options.customLogger.warning("[Statsig]: Please provide the correct file path.")
+            options.customLogger.warn("Please provide the correct file path.")
         }
 
         return try {
@@ -69,7 +70,7 @@ class LocalFileDataStore @JvmOverloads constructor(
 
     override fun set(key: String, value: String) {
         if (key != dataStoreKey) {
-            options.customLogger.warning("[Statsig]: Please provide the correct file path.")
+            options.customLogger.warn("Please provide the correct file path.")
         }
 
         File(key).writeText(value)