Logging Metadata

[cedrickcooke]

Example Use

object ExampleKey : Key<ExampleData>
data class ExampleData(val foo: String, val bar: Boolean)

class CustomLogger : Logger {
    // ...
    override fun verbose(tag: String, message: String, metadata: ReadMetadata, throwable: Throwable?) {
        val example = metadata[ExampleKey]
        if (example?.bar == true) {
            println(example.foo)
        }
    }
}

fun elsewhere() {
    Log.verbose { metadata ->
        metadata[ExampleKey] = ExampleData("test", true)
        "Logged from `elsewhere`"
    }
}

Breaking Changes

• Implementors of Logger will need to add a new parameter.
• Direct calls with Logger will need to supply metadata.
• Calls to Log.xyz will likely work (in source), but there are some edge cases where they'll need to be updated (such as if you pass a function reference, instead of lambda).

[twyatt]

Does the queue (as apposed to an atomic) protect against someone logging from within a log lambda?
Otherwise, would an atomic have sufficed?

[cedrickcooke]

Re. ArrayDeque, I just default to it instead of List when I'm doing stack/queue operations, since it's more explicit. For stack operations (like here) it's basically the same.

Re. atomic, it doesn't work for the high throughput, low-allocation goal of this pool. In DispatchLogger, for example, we're using consumers.update { it + consumer } -- which allocates a new list and copies all the plus the new one (I'm not worried about the O(N^2) inefficiency here, because N is super small and setup only happens once). We have to do that copy for two reasons.

1. update is loop based. It gets the current value, performs the update function, then does a compareAndSet to make sure nothing else changed the value. This means that the block can be called more than once, so it's not safe to mutate the value. But even if it wasn't a loop...
2. atomic is basically a pointer. While it's okay to change what it points at (from any thread), in Kotlin/Native the thing pointed at is still frozen. This would also prevent us from mutating a list.

The solution here, albeit ugly, should be fast on every platform. Effectively...

• On JVM: we're using one pool shared by all threads. Getting a value from the pool and returning a value to it holds the lock, but everything else can live outside it. Realistically, there should be very little contention and when there is, it should resolve itself quickly.
• On JS: the lock is implemented as a no-op.
• On Native: the Pool itself is @ThreadLocal, so the lock/cache are each per-thread. As such there will never be any contention on the lock and it will always happy-path, and the cache won't freeze.

[twyatt]

Thanks for the incredibly thorough explanation. Super clever approach with the @ThreadLocal. 👍

[cedrickcooke]

And yet, somehow, despite writing a small essay, I managed to miss the original question.

It should be safe to nest log calls, both inside a Logger (although it will need conditional logic, or else it will infinitely loop) and within a Log call such as Log.verbose { Log.debug { "a" }; "b" }. I'll admit I haven't tested either of these cases.

[codecov]

Codecov Report

Merging #52 (04319f0) into main (0e576bf) will decrease coverage by 0.10%.
The diff coverage is 96.22%.

@@             Coverage Diff              @@
##               main      #52      +/-   ##
============================================
- Coverage     94.50%   94.40%   -0.11%     
- Complexity       41       52      +11     
============================================
  Files            11       13       +2     
  Lines            91      125      +34     
  Branches          8        8              
============================================
+ Hits             86      118      +32     
- Misses            5        6       +1     
- Partials          0        1       +1     

Impacted Files	Coverage Δ	Complexity Δ
logging/src/commonMain/kotlin/Metadata.kt	77.77% <77.77%> (ø)	7.00 <7.00> (?)
logging/src/commonMain/kotlin/DispatchLogger.kt	100.00% <100.00%> (ø)	11.00 <7.00> (ø)
logging/src/commonMain/kotlin/Log.kt	100.00% <100.00%> (ø)	28.00 <6.00> (ø)
logging/src/commonMain/kotlin/Pool.kt	100.00% <100.00%> (ø)	4.00 <4.00> (?)

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 0e576bf...04319f0. Read the comment docs.

[twyatt]

Thoroughly impressed with how elegant of an API and streamlined the internals of this are! Really awesome stuff! 💯 🚀 🤯

[twyatt]

TIL of ::<class_name> constructor syntax, so cool!