Skip to content

Commit

Permalink
fix: update how debug logging works (#174)
Browse files Browse the repository at this point in the history
* fix: update how debug logging works

* fix: add tests for DebugLogger

* test: Add test for network exception logging

* docs: document how logging works
  • Loading branch information
nicklasl authored Jun 28, 2024
1 parent 81f68fb commit bd79fad
Show file tree
Hide file tree
Showing 13 changed files with 283 additions and 170 deletions.
1 change: 1 addition & 0 deletions Confidence/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -58,6 +58,7 @@ dependencies {
testImplementation("org.jetbrains.kotlinx:kotlinx-coroutines-test:${Versions.coroutines}")
testImplementation("org.mockito.kotlin:mockito-kotlin:${Versions.kotlinMockito}")
testImplementation("com.squareup.okhttp3:mockwebserver:${Versions.mockWebServer}")
testImplementation("io.mockk:mockk:1.13.11")
}

publishing {
Expand Down
25 changes: 12 additions & 13 deletions Confidence/src/main/java/com/spotify/confidence/Confidence.kt
Original file line number Diff line number Diff line change
Expand Up @@ -66,9 +66,7 @@ class Confidence internal constructor(

private suspend fun resolve(flags: List<String>): Result<FlagResolution> {
debugLogger?.let {
for (flag in flags) {
debugLogger.logFlags("ResolveFlag", flag)
}
debugLogger.logFlag("Resolve")
}
return flagResolver.resolve(flags, getContext())
}
Expand All @@ -82,7 +80,7 @@ class Confidence internal constructor(

fun apply(flagName: String, resolveToken: String) {
flagApplier.apply(flagName, resolveToken)
debugLogger?.logFlags("ApplyFlag", flagName)
debugLogger?.logFlag("Apply", flagName)
}

fun <T> getValue(key: String, default: T) = getFlag(key, default).value
Expand All @@ -105,15 +103,15 @@ class Confidence internal constructor(
val map = contextMap.value.toMutableMap()
map[key] = value
contextMap.value = map
debugLogger?.logContext(contextMap.value)
debugLogger?.logContext("PutContext", contextMap.value)
}

@Synchronized
override fun putContext(context: Map<String, ConfidenceValue>) {
val map = contextMap.value.toMutableMap()
map += context
contextMap.value = map
debugLogger?.logContext(contextMap.value)
debugLogger?.logContext("PutContext", contextMap.value)
}

fun isStorageEmpty(): Boolean = diskStorage.read() == FlagResolution.EMPTY
Expand All @@ -127,7 +125,7 @@ class Confidence internal constructor(
}
this.removedKeys.addAll(removedKeys)
contextMap.value = map
debugLogger?.logContext(contextMap.value)
debugLogger?.logContext("PutContext", contextMap.value)
}

@Synchronized
Expand All @@ -136,7 +134,7 @@ class Confidence internal constructor(
map.remove(key)
removedKeys.add(key)
contextMap.value = map
debugLogger?.logContext(contextMap.value)
debugLogger?.logContext("RemoveContext", contextMap.value)
}

override fun getContext(): Map<String, ConfidenceValue> =
Expand Down Expand Up @@ -172,7 +170,8 @@ class Confidence internal constructor(
}

private val networkExceptionHandler by lazy {
CoroutineExceptionHandler { _, _ ->
CoroutineExceptionHandler { _, throwable ->
debugLogger?.logMessage("Network error", isWarning = true, throwable = throwable)
// network failed, provider is ready but with default/cache values
}
}
Expand Down Expand Up @@ -251,12 +250,12 @@ object ConfidenceFactory {
initialContext: Map<String, ConfidenceValue> = mapOf(),
region: ConfidenceRegion = ConfidenceRegion.GLOBAL,
dispatcher: CoroutineDispatcher = Dispatchers.IO,
debugLoggerLevel: DebugLoggerLevel = DebugLoggerLevel.NONE
loggingLevel: LoggingLevel = LoggingLevel.WARN
): Confidence {
val debugLogger: DebugLogger? = if (debugLoggerLevel == DebugLoggerLevel.NONE) {
val debugLogger: DebugLogger? = if (loggingLevel == LoggingLevel.NONE) {
null
} else {
DebugLoggerImpl(debugLoggerLevel)
DebugLoggerImpl(loggingLevel)
}
val engine = EventSenderEngineImpl.instance(
context,
Expand All @@ -282,7 +281,7 @@ object ConfidenceFactory {
val visitorId = ConfidenceValue.String(VisitorUtil.getId(context))
val initContext = initialContext.toMutableMap()
initContext[VISITOR_ID_CONTEXT_KEY] = visitorId
debugLogger?.logContext(initContext)
debugLogger?.logContext("InitialContext", initContext)

return Confidence(
clientSecret,
Expand Down
66 changes: 43 additions & 23 deletions Confidence/src/main/java/com/spotify/confidence/DebugLogger.kt
Original file line number Diff line number Diff line change
Expand Up @@ -2,45 +2,65 @@ package com.spotify.confidence

import android.util.Log

private const val TAG = "Confidence"

internal interface DebugLogger {
fun logEvent(tag: String, event: EngineEvent, details: String)
fun logMessage(tag: String, message: String, isWarning: Boolean = false)
fun logFlags(tag: String, flag: String)
fun logContext(context: Map<String, ConfidenceValue>)
fun logEvent(action: String, event: EngineEvent)
fun logMessage(message: String, isWarning: Boolean = false, throwable: Throwable? = null)
fun logFlag(action: String, flag: String? = null)
fun logContext(action: String, context: Map<String, ConfidenceValue>)
}

internal class DebugLoggerImpl(private val level: DebugLoggerLevel) : DebugLogger {
override fun logEvent(tag: String, event: EngineEvent, details: String) {
log(tag, details + event.toString())
internal class DebugLoggerImpl(private val filterLevel: LoggingLevel) : DebugLogger {

override fun logEvent(action: String, event: EngineEvent) {
debug("[$action] $event")
}

override fun logMessage(tag: String, message: String, isWarning: Boolean) {
if (!isWarning) {
log(tag, message)
override fun logMessage(message: String, isWarning: Boolean, throwable: Throwable?) {
if (isWarning) {
warn(message, throwable)
} else if (throwable != null) {
error(message, throwable)
} else {
Log.w(tag, message)
debug(message)
}
}

override fun logFlags(tag: String, flag: String) {
log(tag, flag)
override fun logFlag(action: String, flag: String?) {
verbose("[$action] $flag")
}

override fun logContext(context: Map<String, ConfidenceValue>) {
log("CurrentContext", context.toString())
override fun logContext(action: String, context: Map<String, ConfidenceValue>) {
verbose("[$action] $context")
}

private fun log(tag: String, message: String) {
when (level) {
DebugLoggerLevel.VERBOSE -> Log.v(tag, message)
DebugLoggerLevel.DEBUG -> Log.d(tag, message)
DebugLoggerLevel.NONE -> {
// do nothing
private fun verbose(message: String) = log(LoggingLevel.VERBOSE, message)
private fun debug(message: String) = log(LoggingLevel.DEBUG, message)
private fun warn(message: String, throwable: Throwable?) =
log(LoggingLevel.WARN, throwable?.let { "$message: ${throwable.message}" } ?: message)

private fun error(message: String, throwable: Throwable) = log(LoggingLevel.ERROR, "$message: ${throwable.message}")

private fun log(messageLevel: LoggingLevel, message: String) {
if (messageLevel >= filterLevel) {
when (messageLevel) {
LoggingLevel.VERBOSE -> Log.v(TAG, message)
LoggingLevel.DEBUG -> Log.d(TAG, message)
LoggingLevel.WARN -> Log.w(TAG, message)
LoggingLevel.ERROR -> Log.e(TAG, message)
LoggingLevel.NONE -> {
// do nothing
}
}
}
}
}

enum class DebugLoggerLevel {
VERBOSE, DEBUG, NONE
enum class LoggingLevel {
VERBOSE, // 0
DEBUG, // 1
WARN, // 2
ERROR, // 3
NONE // 4
}
Original file line number Diff line number Diff line change
Expand Up @@ -15,8 +15,6 @@ import kotlinx.coroutines.launch
import okhttp3.OkHttpClient
import java.io.File

private const val className = "ConfidenceEventSender"

internal interface EventSenderEngine {
fun onLowMemoryChannel(): Channel<List<File>>
fun emit(eventName: String, data: ConfidenceFieldsType, context: Map<String, ConfidenceValue>)
Expand Down Expand Up @@ -53,7 +51,7 @@ internal class EventSenderEngineImpl(
if (event.eventDefinition != manualFlushEvent.eventDefinition) {
// skip storing manual flush event
eventStorage.writeEvent(event)
debugLogger?.logEvent(tag = className, event = event, details = "Event written to disk ")
debugLogger?.logEvent(action = "DiskWrite ", event = event)
}
for (policy in flushPolicies) {
policy.hit(event)
Expand All @@ -63,7 +61,6 @@ internal class EventSenderEngineImpl(
for (policy in flushPolicies) {
policy.reset()
debugLogger?.logMessage(
tag = className,
message = "Flush policy $policy triggered to flush. Flushing."
)
}
Expand Down Expand Up @@ -94,7 +91,7 @@ internal class EventSenderEngineImpl(
)
runCatching {
val shouldCleanup = uploader.upload(batch)
debugLogger?.logMessage(tag = className, message = "Uploading batched events")
debugLogger?.logMessage(message = "Uploading events")
if (shouldCleanup) {
readyFile.delete()
}
Expand All @@ -105,7 +102,7 @@ internal class EventSenderEngineImpl(
}

override fun onLowMemoryChannel(): Channel<List<File>> {
debugLogger?.logMessage(tag = className, message = "Low memory", isWarning = true)
debugLogger?.logMessage(message = "LowMemory", isWarning = true)
return eventStorage.onLowMemoryChannel()
}

Expand All @@ -122,21 +119,21 @@ internal class EventSenderEngineImpl(
payload = payload
)
writeReqChannel.send(event)
debugLogger?.logEvent(tag = className, event = event, details = "Emitting event ")
debugLogger?.logEvent(action = "EmitEvent ", event = event)
}
}

override fun flush() {
coroutineScope.launch {
writeReqChannel.send(manualFlushEvent)
debugLogger?.logEvent(tag = className, event = manualFlushEvent, details = "Event flushed ")
debugLogger?.logEvent(action = "Flush ", event = manualFlushEvent)
}
}

override fun stop() {
coroutineScope.cancel()
eventStorage.stop()
debugLogger?.logMessage(tag = className, message = "$className closed ")
debugLogger?.logMessage(message = "EventSenderEngine closed ")
}

companion object {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,7 @@ import org.mockito.kotlin.mock
class ConfidenceContextualTests {
@Test
fun test_forking_context_works() {
val debugLogger = DebugLoggerMock()
val debugLogger = DebugLoggerFake()
val confidence = Confidence(
"",
Dispatchers.IO,
Expand All @@ -29,18 +29,16 @@ class ConfidenceContextualTests {
mutableMap["NN"] = ConfidenceValue.Double(20.0)
mutableMap["my_struct"] = ConfidenceValue.Struct(mapOf("x" to ConfidenceValue.Double(2.0)))
confidence.putContext(mutableMap)
Assert.assertEquals(1, debugLogger.contextLogs)
val eventSender = confidence.withContext(mapOf("my_value" to ConfidenceValue.String("my value")))
Assert.assertEquals(mutableMap, confidence.getContext())
Assert.assertTrue(mutableMap.all { eventSender.getContext().containsKey(it.key) })
Assert.assertTrue(eventSender.getContext().containsKey("my_value"))
Assert.assertTrue(eventSender.getContext()["my_value"] == ConfidenceValue.String("my value"))
Assert.assertEquals(2, debugLogger.contextLogs)
}

@Test
fun removing_context_will_skip_the_context_coming_from_parent() {
val debugLogger = DebugLoggerMock()
val debugLogger = DebugLoggerFake()
val confidence = Confidence(
"",
Dispatchers.IO,
Expand All @@ -61,9 +59,7 @@ class ConfidenceContextualTests {
mutableMap["NN"] = ConfidenceValue.Double(20.0)
mutableMap["my_struct"] = ConfidenceValue.Struct(mapOf("x" to ConfidenceValue.Double(2.0)))
confidence.putContext(mutableMap)
Assert.assertEquals(1, debugLogger.contextLogs)
val eventSender = confidence.withContext(mapOf("my_value" to ConfidenceValue.String("my value")))
Assert.assertEquals(2, debugLogger.contextLogs)
Assert.assertEquals(mutableMap, confidence.getContext())
Assert.assertTrue(mutableMap.all { eventSender.getContext().containsKey(it.key) })
Assert.assertTrue(eventSender.getContext().containsKey("my_value"))
Expand All @@ -72,7 +68,6 @@ class ConfidenceContextualTests {
// remove the screen
Assert.assertTrue(eventSender.getContext().containsKey("screen"))
eventSender.removeContext("screen")
Assert.assertEquals(3, debugLogger.contextLogs)
Assert.assertTrue(!eventSender.getContext().containsKey("screen"))
}
}
Loading

0 comments on commit bd79fad

Please sign in to comment.