Pudu programming language
Menu
Package

@chrismichaelps / pudu-lang-log

Structured event logging for Pudu: message templates, enrichment, filtering, formatting, and sinks

0.1.0Apache-2.01

InstallClose

TopologyTest.pudu

Pudu194 lines12.2 KB

GitHub ↗
1/** @Test.Topology.Suite — sink wrappers, sub-loggers, enrichers, filters, and lifecycle */2module PuduLangLog.TopologyTest34import Std.Io as Io5import Std.Sync as Sync6import Std.Test as Test7import PuduLangLog.Clock as Clock8import PuduLangLog.Configuration as Configuration9import PuduLangLog.Context as Context10import PuduLangLog.Enricher as Enricher11import PuduLangLog.Event as Event12import PuduLangLog.Failure as Failure13import PuduLangLog.Filter as Filter14import PuduLangLog.LevelSwitch as LevelSwitch15import PuduLangLog as Log16import PuduLangLog.Logger as Logger17import PuduLangLog.Sink as Sink18import PuduLangLog.Sinks.Memory as Memory19import PuduLangLog.Value as Value2021/// The moment every event in this suite carries.22const NOW: Log.Timestamp = Log.Timestamp{millis: 0, offset: 0}2324/// A configuration with a fixed clock.25fn base() -> Configuration.Configuration { Configuration.create().clock(Clock.fixed(NOW)) }2627/// A sink that always fails.28fn broken() -> Sink.Sink { Sink.of(fn(_event: &Log.Event) -> Result[(), Str] { Err("disk full") }) }2930/// A counter held in a cell.31fn counter() -> Sync.Cell[Int] { Sync.cell(0) }3233/// The counter's value.34fn countOf(cell: &Sync.Cell[Int]) -> Int {35  match Sync.get(cell) {36    case Ok(value) => value37    case Err(_) => -138  }39}4041/// Adds one to a counter.42fn bump(cell: &Sync.Cell[Int]) -> () {43  let _stored = Sync.set(cell, countOf(cell) + 1)44}4546/// Runs the suite.47fn main() -> Int {48  let all = Memory.create()49  let errors = Memory.create()50  let when = Memory.create()51  let layered = base().minimumLevel(Log.Debug).writeTo(Memory.sink(&all)).writeToAtLeast(Memory.sink(&errors), Log.Error).writeToWhen(Filter.withProperty("Audit"), Memory.sink(&when)).createLogger()52  layered.debug("d", [])53  layered.error("e", [])54  layered.forContext("Audit", Value.bool(true)).information("audited", [])5556  let sinkSwitch = LevelSwitch.create(Log.Warning)57  let controlled = Memory.create()58  let switched = base().writeToControlled(Memory.sink(&controlled), &sinkSwitch).createLogger()59  switched.information("quiet", [])60  LevelSwitch.set(&sinkSwitch, Log.Information)61  switched.information("heard", [])6263  let parent = Memory.create()64  let child = Memory.create()65  let subLogger = Configuration.nested().enrichWithProperty("Child", Value.bool(true)).filterExcluding(Filter.fromSource("App.Secret")).writeTo(Memory.sink(&child)).createLogger()66  let topLevel = base().writeTo(Memory.sink(&parent)).writeToLogger(&subLogger).createLogger()67  topLevel.information("shared", [])68  topLevel.forSource("App.Secret").information("secret", [])6970  let survivors = Memory.create()71  let audits = Memory.create()72  let audited = base().writeTo(broken()).writeTo(Memory.sink(&survivors)).auditTo(Memory.sink(&audits)).createLogger()73  let normal = audited.tryWrite(Log.Information, None, "kept", [])74  let failingAudit = base().auditTo(broken()).auditTo(Memory.sink(&audits)).createLogger()75  let refused = failingAudit.tryWrite(Log.Information, None, "refused", [])7677  let fallback = Memory.create()78  let chained = base().writeToFallbackChain([broken(), Memory.sink(&fallback)]).createLogger()79  chained.information("fell back", [])80  let reports = counter()81  let fallible = base().writeToFallible(broken(), fn(report: &Sink.Report) -> () {82      if report.kind == Sink.Permanent && report.events.length() == 1 { bump(&reports) }83    }).createLogger()84  fallible.information("lost", [])8586  let enriched = Memory.create()87  let enrichers = base().minimumLevel(Log.Verbose).writeTo(Memory.sink(&enriched)).enrichWith(Enricher.atLevel(Log.Error, Enricher.property("Alert", Value.bool(true)))).enrichWith(Enricher.when(Filter.withProperty("User"), Enricher.computed("UserLength", fn(event: &Log.Event) -> Log.Value {88          match Event.property(event, "User") {89            case Some(Log.Scalar(Log.Text(name))) => Value.int(name.length())90            case _ => Value.nothing()91          }92        }, false))).enrichWith(Enricher.from(fn(event: Log.Event) -> Log.Event { Event.withoutProperty(&event, "Secret") })).enrichWith(Enricher.destructured("Build", Value.structure("Build", [("Number", Value.int(42))]))).createLogger()93  enrichers.error("boom \{User\} \{Secret\}", [Value.text("ada"), Value.text("hunter2")])94  enrichers.verbose("fine", [])95  let enrichedFirst = Memory.events(&enriched)[0]9697  let filtered = Memory.create()98  let filtering = base().writeTo(Memory.sink(&filtered)).filterIncludingOnly(Filter.anyOf([Filter.atLeast(Log.Warning), Filter.withPropertyValue("Keep", Value.bool(true))])).filterExcluding(Filter.withPropertyWhere("Size", fn(held: &Log.Value) -> Bool { held == &Value.int(0) })).createLogger()99  filtering.information("dropped", [])100  filtering.information("kept \{Keep\}", [Value.bool(true)])101  filtering.warning("warned \{Size\}", [Value.int(1)])102  filtering.warning("empty \{Size\}", [Value.int(0)])103104  let ambient = Context.create()105  let ambientMemory = Memory.create()106  let ambientLogger = base().writeTo(Memory.sink(&ambientMemory)).enrichWith(Context.enricher(&ambient)).createLogger()107  let outer = Context.pushProperty(&ambient, "Request", Value.text("r1"))108  let inner = Context.pushProperty(&ambient, "Request", Value.text("r2"))109  ambientLogger.information("inner", [])110  Context.restore(&ambient, inner)111  ambientLogger.information("outer", [])112  let copy = Context.clone(&ambient)113  Context.restore(&ambient, outer)114  let answered = Context.using(&ambient, "Scope", Value.int(1), fn() -> Int {115      ambientLogger.information("scoped", [])116      5117    })118  ambientLogger.information("bare", [])119  let _cloned = Context.pushDestructured(&copy, "Extra", Value.int(9))120  let suspended = Context.suspend(&copy)121  let emptied = Context.pushProperty(&ambient, "Temporary", Value.int(1))122  Context.reset(&ambient)123  ambientLogger.information("reset", [])124  let ambientEvents = Memory.events(&ambientMemory)125126  let lifecycle = counter()127  let lifecycleSink = Sink.Sink{..Sink.none(), flush: fn() -> () { bump(&lifecycle) }, close: fn() -> () { bump(&lifecycle) }}128  let closing = base().writeTo(lifecycleSink).createLogger()129  Logger.close(&closing)130131  let first = Memory.create()132  let second = Memory.create()133  let reloadable = Logger.reloadable(Configuration.pipelineOf(&base().writeTo(Memory.sink(&first))))134  let derived = reloadable.forContext("Derived", Value.bool(true))135  derived.information("one", [])136  let reloaded = Logger.reload(&reloadable, Configuration.pipelineOf(&base().writeTo(Memory.sink(&second))))137  derived.information("two", [])138139  let traced = Memory.create()140  let tracing = base().writeTo(Memory.sink(&traced)).createLogger().withTrace("abc", "def")141  tracing.writeFailure(Log.Error, Failure.of("IoError", "full"), "failed", [])142  let manual = Event.create(NOW, Log.Debug, "manual", [])143  let dropped = tracing.emit(manual)144  let accepted = tracing.emit(Log.Event{..manual, level: Log.Warning})145  let (template, bound) = tracing.bindTemplate("\{A\}", [Value.int(1)])146147  let destructured = Memory.create()148  let destructuring = base().writeTo(Memory.sink(&destructured)).destructureByTransforming("Card", fn(_held: Log.Value) -> Log.Value { Value.structure("Card", [("Last4", Value.text("1234"))]) }).destructureAsScalar("Token").maximumStringLength(4).maximumCollectionCount(2).maximumDepth(3).destructureWithRule(fn(held: &Log.Value) -> Option[Log.Value] { if held == &Value.object([]) { Some(Value.text("empty")) } else { None } }).createLogger()149  destructuring.information("\{@Card\} \{@Token\} \{Name\} \{List\} \{@Nothing\}", [Value.structure("Card", [("Number", Value.text("4111111111111111"))]), Value.structure("Token", []), Value.text("abcdef"), Value.list([Value.int(1), Value.int(2), Value.int(3)]), Value.object([])])150151  let checks = Test.suite("Topology", &[152      Test.equals("every sink sees what passes the pipeline", &Memory.messages(&all), &["d", "e", "audited"]),153      Test.equals("a restricted sink sees its levels", &Memory.messages(&errors), &["e"]),154      Test.equals("a conditional sink sees what its condition accepts", &Memory.messages(&when), &["audited"]),155      Test.equals("a controlled sink follows its switch", &Memory.messages(&controlled), &["heard"]),156      Test.equals("the parent sees every event", &Memory.messages(&parent), &["shared", "secret"]),157      Test.equals("a sub-logger applies its own filters", &Memory.messages(&child), &["shared"]),158      Test.equals("sub-logger enrichment stays in the sub-logger", &(Event.property(&Memory.events(&child)[0], "Child"), Event.property(&Memory.events(&parent)[0], "Child")), &(Some(Value.bool(true)), None)),159      Test.equals("a failing sink does not stop the others", &Memory.messages(&survivors), &["kept"]),160      Test.equals("a successful audit answers Ok", &normal, &Ok(())),161      Test.equals("a failing audit sink is reported to the caller", &refused, &Err("disk full")),162      Test.equals("every audit sink is still tried", &Memory.messages(&audits), &["kept", "refused"]),163      Test.equals("a fallback chain uses the next sink", &Memory.messages(&fallback), &["fell back"]),164      Test.equals("a fallible sink reports its failure", &countOf(&reports), &1),165      Test.equals("level-gated enrichment", &(Event.property(&enrichedFirst, "Alert"), Event.property(&Memory.events(&enriched)[1], "Alert")), &(Some(Value.bool(true)), None)),166      Test.equals("conditional computed enrichment", &Event.property(&enrichedFirst, "UserLength"), &Some(Value.int(3))),167      Test.equals("an enricher can remove properties", &Event.property(&enrichedFirst, "Secret"), &None),168      Test.equals("a destructured enricher keeps structure", &Event.property(&enrichedFirst, "Build"), &Some(Value.structure("Build", [("Number", Value.int(42))]))),169      Test.equals("filters combine", &Memory.messages(&filtered), &["kept true", "warned 1"]),170      Test.equals("the innermost ambient property wins", &Event.property(&ambientEvents[0], "Request"), &Some(Value.text("r2"))),171      Test.equals("restoring a bookmark pops the inner push", &Event.property(&ambientEvents[1], "Request"), &Some(Value.text("r1"))),172      Test.equals("using pushes for the action and answers its value", &(Event.property(&ambientEvents[2], "Scope"), answered, Event.property(&ambientEvents[3], "Scope")), &(Some(Value.int(1)), 5, None)),173      Test.equals("a restored outer bookmark empties the stack", &ambientEvents[3].properties, &[]),174      Test.equals("reset empties the stack", &(ambientEvents[4].properties, emptied.frames.length()), &([], 0)),175      Test.equals("a clone is independent", &(suspended.frames.length(), Context.enricher(&copy)(manual, &Configuration.create().policy).properties), &(2, [])),176      Test.equals("close flushes and closes", &countOf(&lifecycle), &2),177      Test.equals("a reload redirects derived loggers", &(Memory.messages(&first), Memory.messages(&second), reloaded), &(["one"], ["two"], true)),178      Test.equals("a reloaded pipeline keeps the context", &Event.property(&Memory.events(&second)[0], "Derived"), &Some(Value.bool(true))),179      Test.that("a fixed logger does not reload", !Logger.reload(&tracing, Configuration.pipelineOf(&base()))),180      Test.equals("trace and span identifiers", &(Memory.events(&traced)[0].traceId, Memory.events(&traced)[0].spanId), &(Some("abc"), Some("def"))),181      Test.equals("failures travel with the event", &Memory.events(&traced)[0].failure, &Some(Failure.of("IoError", "full"))),182      Test.equals("emit checks the level", &(dropped, accepted, Memory.messages(&traced)), &(Ok(()), Ok(()), ["failed", "manual"])),183      Test.equals("templates bind without writing", &(template.text, bound), &("\{A\}", [Value.property("A", Value.int(1))])),184      Test.equals("properties bind without writing", &(tracing.bindProperty("X", Value.object([]), false), tracing.bindProperty(" ", Value.int(1), false)), &(Some(Value.property("X", Value.text("\{ \}"))), None)),185      Test.equals("configured destructuring", &Memory.events(&destructured)[0].properties, &[Value.property("Card", Value.structure("Card", [("Last4", Value.text("1234"))])), Value.property("Token", Value.text("Tok…")), Value.property("Name", Value.text("abc…")), Value.property("List", Value.list([Value.int(1), Value.int(2)])), Value.property("Nothing", Value.text("emp…"))]),186      Test.that("a silent logger writes nothing", !Logger.none().isEnabled(Log.Fatal))187    ])188  let ran = Test.run(&checks)189  for failure in Test.failuresOf(&ran) {190    let _reported = Io.writeErrorLine(failure)191  }192  Test.report(&ran)193}194