Marlowe Runtime logging

[paluh]

I was preparing this intro to the logging discussion and contravariant logging before @shlevy introduction of eventuo11y library to the Dev Team. Because of that it focuses on co-log.

Let's start the discussion by touching three aspects of logging:

• Let's introduce "contravariant" logging. I put it at the end because it is pretty lengthy. It focuses on the co-log lib because I thought we gonna use it ;-)

• "Log entry structure" - do we want to log just Strings or maybe something more.

• Logging monad and code clutter and other monads and more specifically what is co-log LoggerT and what kind of genericity do we want to have.

Log entry structure

Traditionally we use plain String and a bunch of helper functions (which adds severity and probably some additional context like call stack to the log entry etc.) as a way to generate logs. In the cardano-node they use pre defined and system specific types to represent log entries. Let's dicuss pros and cons:

String based logging

• More traditional approach - we turn and format logs in to String on the call site.

• It has low entry point - easy to understand, no extra types needed

• It clutters the code a lot - we format a lot of strings like logDebug . T.pack . mappend "Wallet context:" $ show walletContext etc.

• We fully decide about importance of the messages at the call site.

• We are not able to filter out messages later on based on more specific criteria (output DEBUG messages but only from the component which I'm interested in).

• We are stricly talking about "logging" here - this approach doesn't gives us much in the context of for example metric aggregation or system event tracking (analysys during testing).

Semantic logging tracing

• Logger accepts structured values of types dedicated and defined for that purpose.

• Of course we still are able to include debugging data like code location, default severity etc.

• It requires creation of dedicated type for logging (it can be done incrementatlly - netwtype Entry = Entry String as a first approximation ;-) per application / subsystem etc.

• It can be used for system metric tracking and aggregation - we don't have to introduce another layer for that.

• It can be used for system event flow testing.

• It can downgrade to JSON structures and be accumulated and analysed by more standard tools.

Logging monad

Logging and async IO

The Marlowe Runtime services extensively use threading and async primitives and work directly in IO. Of course we can lift the async primitives to any ReaderT ctx IO monad and lift async primitives to this monad:

type LogAction msg = msg -> IO

type LogIO msg = ReaderT (LogAction msg) IO

forkLogIO :: LogIO () -> LogIO ThreadId
forkLogIO action = ..

forkFinallyLogIO :: LogIO a -> (Either SomeException a -> LogIO ()) -> LogIO ThreadId
forkFinallyLogIO action andThen = ..

concurrentlyLogIO :: LogIO a -> LogIO b -> LogIO (a, b)
concurrentlyLogIO action1 action2 = ..

Using this style we can keep code base simple and readable. Some of this functions could also accept logging context transformation so when we fork a Worker we could embed Worker logs in the App logging context. This can be done when we shift to the more semantic log representation.

I create a bunch of wrappers like that on this branch and migrated most of our services to this representation. For simplicity reasons I started just by defining working monad as LoggerT Message IO which is isomorphic to a ReaderT (I use LoggerT from co-log) wrapper around IO.

Introduction to contravariant logging

EDIT: I've moved this part to a interactive notebook here: https://mybinder.org/v2/gh/paluh/haskell-tutorials/HEAD?labpath=%2Ftutorials%2Fcontravariant-logging.ipynb

[shlevy]

On the question of a logging monad: Instead of an MTL-style approach, eventuo11y uses value-level records of effects (similar to the channel abstraction in marlowe-protocols). This has many benefits, including generic hoisting between monads (no NxM problem) and non-invasive composition (I can monoidally combine 2 event backends, or modify an event backend to, say, do log sampling, without having to deal with transformer wrapping/unwrapping and lifting all other monadic capabilities into some new monad). Fundamentally this comes down to the fact that the effects we want are not really a property of the specific monad type we're in (e.g. there is and should be no single "canonical" way to log in IO) and so using typeclasses is inappropriate and requires proliferation of newtype wrappers (contrast this with e.g. >>=, where there really is one right way to do it in most given monads).

One way I think about this is on an analogy to ambient authority (the typeclass approach) vs object capabilities (the record of effects approach, which I think of as a capability record). Putting effects into a global namespace makes them uncomposable and harder to reason about.

[paluh]

I think that you are right - in the Runtime we already use capability records and it works nicely - it seems flexible, explicit in nature and easy to reason about. I think we gonna throw away LogIO approach / direction which I liked above.