Merge branch 'tests'

chronicles.nim

@@ -243,7 +243,6 @@ macro logIMPL(lineInfo: static InstInfo,
 
   code.add quote do:
     var `record`: `RecordType`
-    beginRecord(`record`.output, LogLevel(`severity`))
 
   for i in 0 ..< recordArity:
     # We do something complicated here on purpose.
@@ -254,6 +253,7 @@ macro logIMPL(lineInfo: static InstInfo,
                     else: newTree(nnkBracketExpr, record, newLit(i))
     var filename = lineInfo.filename & ":" & $lineInfo.line
     code.add quote do:
+      prepareOutputForRecord(`recordRef`.output, LogLevel(`severity`))
       initLogRecord(`recordRef`, LogLevel(`severity`),
                     `topicsNode`, `eventName`)
       setFirstProperty(`recordRef`, "thread", `threadId`)
@@ -269,6 +269,7 @@ macro logIMPL(lineInfo: static InstInfo,
   code.add newCall("flushRecord", record)
 
   result = newBlockStmt(id"chroniclesLogStmt", code)
+  # echo result.repr
 
 # Translate all the possible overloads to `logIMPL`:
 template log*(severity: LogLevel,

chronicles.nimble

@@ -9,13 +9,7 @@ skipDirs      = @["tests"]
 
 requires "nim >= 0.18.1"
 
-proc configForTests() =
-  --hints: off
-  --debuginfo
-  --path: "."
-  --run
-
 task test, "run CPU tests":
-  configForTests()
-  setCommand "c", "tests/all.nim"
+  cd "tests"
+  exec "nim c -r testrunner ."
 

chronicles/log_output.nim

@@ -199,22 +199,27 @@ proc selectRecordType(s: var StreamCodeNodes, sink: SinkSpec): NimNode =
 # The LogRecord types are parametric on their Output and this is how we
 # can support arbitrary combinations of log formats and destinations.
 
-template beginRecord*(o: var AnyFileOutput, level: LogLevel) = discard
-template beginRecord*(o: var StreamOutputRef, level: LogLevel) = discard
+template prepareOutputForRecord*(o: var AnyFileOutput, level: LogLevel) =
+  discard
 
-template beginRecord*(o: var SysLogOutput, level: LogLevel) =
+template prepareOutputForRecord*(o: var StreamOutputRef, level: LogLevel) =
+  discard
+
+template prepareOutputForRecord*(o: var SysLogOutput, level: LogLevel) =
   o.currentRecordLevel = level
 
-template beginRecord*(o: var BufferedOutput, level: LogLevel) =
+template prepareOutputForRecord*(o: var BufferedOutput, level: LogLevel) =
   for f in o.finalOutputs.fields:
-    beginRecord(f, level)
+    prepareOutputForRecord(f, level)
 
 template append*(o: var FileOutput, s: string) =
   if o.outFile == nil: openOutput(o)
   o.outFile.write s
 
 template flushOutput*(o: var FileOutput) =
-  assert o.outFile != nil
+  # XXX: Uncommenting this triggers a strange compile-time error
+  #      when multiple sinks are used.
+  # assert o.outFile != nil
   o.outFile.flushFile
 
 template append*(o: var StdOutOutput, s: string) = stdout.write s
@@ -483,8 +488,7 @@ template setFirstProperty*(r: var TextBlockRecord, key: string, val: auto) =
     append(r.output, valText)
     append(r.output, "\n")
   else:
-    # XXX: This should be a const, but the compiler fails with an ICE
-    let indent = static(textBlockIndent & repeat(' ', key.len + 2))
+    let indent = textBlockIndent & repeat(' ', key.len + 2)
     var first = true
     for line in splitLines(valText):
       if not first: append(r.output, indent)
@@ -644,6 +648,8 @@ macro createStreamRecordTypes: untyped =
       result.add quote do:
         template activeChroniclesStream*: typedesc = `streamName`
 
+  # echo result.repr
+
 createStreamRecordTypes()
 
 when defined(windows) and false:

chronicles/scope_helpers.nim

@@ -76,7 +76,8 @@ proc handleUserStreamChoice*(n: NimNode): StreamSpec =
 
 proc skipTypedesc*(n: NimNode): NimNode =
   result = n
-  if result.kind == nnkBracketExpr and $result[0] in ["type", "typedesc"]:
+  if result.kind == nnkBracketExpr and result.len == 2 and
+     (eqIdent(result[0], "type") or eqIdent(result[0], "typedesc")):
     result = result[1]
 
 proc clearEmptyVarargs*(args: NimNode) =

tests/README.md

@@ -0,0 +1,57 @@
+# Testrunner
+## Usage
+Command syntax:
+```
+testrunner [options] path
+```
+
+The runner will look recursively for all `*.test` files at given path.
+
+## Test file options
+The test files follow the configuration file syntax (similar as `.ini`), see also
+[nim parsecfg module](https://nim-lang.org/docs/parsecfg.html).
+
+### Required
+- **program**: A test file should have at minimum a program name. This is the name
+of the nim source minus the `.nim` extension.
+
+### Optional
+- **max_size**: To check the maximum size of the binary, in bytes.
+- **timestamp_peg**: If you don't want to use the default timestamps, you can define
+your own timestamp peg here.
+- **compile_error**: When expecting a compilation failure, the error message that
+should be expected.
+- **error_file**: When expecting a compilation failure, the source file where the
+error should occur.
+- **os**: Space and/or comma separated list of operating systems for which the
+test should be run. Defaults to `"linux, macosx, windows"`. Tests meant for a
+different OS than the host will be marked as `SKIPPED`.
+- **--skip**: This will simply skip the test (will not be marked as failure).
+
+### Forwarded Options
+Any other options or key-value pairs will be forwarded to the nim compiler.
+
+A **key-value** pair will become a conditional symbol + value (`-d:SYMBOL(:VAL)`)
+for the nim compiler, e.g. for `-d:chronicles_timestamps="UnixTime"` the test
+file requires:
+```
+chronicles_timestamps="UnixTime"
+```
+If only a key is given, an empty value will be forwarded.
+
+An **option** will be forwarded as is to the nim compiler, e.g. this can be
+added in a test file:
+```
+--opt:size
+```
+
+### Outputs
+For outputs to be compared, the output string should be set to the output
+name (stdout or filename) from within the "Output" section, e.g.:
+```
+[Output]
+stdout="""expected stdout output"""
+file.log="""expected file output"""
+```
+
+Triple quotes can be used for multiple lines.

tests/all.nim

@@ -1,31 +0,0 @@
-import chronicles, strutils, unittest
-
-
-type TestOutput = object
-
-# XXX would be nicer to use something akin to a mock to verify this but 30s of
-#     searching didn't reveal anything
-var v: string
-
-customLogStream s[TextLineRecord[TestOutput, NoTimestamps, NoColors]]
-
-template append*(o: var TestOutput, s: string) = v.add(s)
-template flushOutput*(o: var TestOutput)       = discard
-
-suite "textlines":
-  setup:
-    v = ""
-
-  test "should quote space":
-    s.debug "test", yes = "quote me", no = "noquote"
-
-    check "yes=\"quote me\"" in v
-    check "no=noquote" in v
-
-    test "should escape newlines space lines":
-      const multiline = """quote
-me"""
-
-      s.debug "test", s = multiline
-
-      check "s=\"quote\\nme\"" in v

tests/colors/ansi_colors.test

@@ -0,0 +1,22 @@
+program=long_lines
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=AnsiColors
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF long info                                  thread=0 file=long_lines.nim:10 str="some multiline\nstring\nmore lines"
+WRN long warning                               thread=0 str="some multiline\nstring\nmore lines"
+INF long info
+  thread: 0
+  str: some multiline
+       string
+       more lines
+
+WRN long warning
+  thread: 0
+  str: some multiline
+       string
+       more lines
+  z: 10
+
+"""

tests/colors/native_colors_unix.test

@@ -0,0 +1,26 @@
+; NativeColors on Unix will give AnsiColors
+
+program=long_lines
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=NativeColors
+chronicles_timestamps=None
+
+os="Linux MacOSX"
+
+[Output]
+stdout="""INF long info                                  thread=0 file=long_lines.nim:10 str="some multiline\nstring\nmore lines"
+WRN long warning                               thread=0 str="some multiline\nstring\nmore lines"
+INF long info
+  thread: 0
+  str: some multiline
+       string
+       more lines
+
+WRN long warning
+  thread: 0
+  str: some multiline
+       string
+       more lines
+  z: 10
+
+"""

tests/colors/native_colors_windows.test

@@ -0,0 +1,25 @@
+; NativeColors test for Windows, actually just compares the non colored output
+program=long_lines
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=NativeColors
+chronicles_timestamps=None
+
+os=Windows
+
+[Output]
+stdout="""INF long info                                  thread=0 file=long_lines.nim:10 str="some multiline\nstring\nmore lines"
+WRN long warning                               thread=0 str="some multiline\nstring\nmore lines"
+INF long info
+  thread: 0
+  str: some multiline
+       string
+       more lines
+
+WRN long warning
+  thread: 0
+  str: some multiline
+       string
+       more lines
+  z: 10
+
+"""

tests/colors/no_colors.test

@@ -0,0 +1,22 @@
+program=long_lines
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF long info                                  thread=0 file=long_lines.nim:10 str="some multiline\nstring\nmore lines"
+WRN long warning                               thread=0 str="some multiline\nstring\nmore lines"
+INF long info
+  thread: 0
+  str: some multiline
+       string
+       more lines
+
+WRN long warning
+  thread: 0
+  str: some multiline
+       string
+       more lines
+  z: 10
+
+"""

tests/custom_stream.nim

@@ -2,27 +2,29 @@ import
   chronicles
 
 type
-  MyRecord = object
+  MyRecord[Output] = object
+    output*: Output
 
 template initLogRecord*(r: var MyRecord, lvl: LogLevel,
                         topics: string, name: string) =
-  stdout.write "[", lvl, "] ", name, ": "
+  r.output.append "[", $lvl, "] ", name, ": "
 
 template setPropertyImpl(r: var MyRecord, key: string, val: auto) =
-  stdout.write key, "=", val
+  r.output.append key, "=", $val
 
 template setFirstProperty*(r: var MyRecord, key: string, val: auto) =
-  stdout.write " ("
-  setPropertyImpl(r, key, val)
+  r.output.append " ("
+  r.setPropertyImpl(key, val)
 
 template setProperty*(r: var MyRecord, key: string, val: auto) =
-  stdout.write ", "
-  setPropertyImpl(r, key, val)
+  r.output.append ", "
+  r.setPropertyImpl(key, val)
 
 template flushRecord*(r: var MyRecord) =
-  stdout.write ")\n"
+  r.output.append ")\n"
+  r.output.flushOutput
 
-customLogStream myStream[MyRecord]
+customLogStream myStream[MyRecord[StdOutOutput]]
 
 var x = 10
 

tests/loglevel/info_level.test

@@ -0,0 +1,16 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=INFO
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF after main                                 topics="general" thread=0
+INF exiting                                    thread=0 msg="bye bye"
+"""

tests/loglevel/no_level.test

@@ -0,0 +1,19 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=NONE
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+DBG inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+DBG inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF after main                                 topics="general" thread=0
+INF exiting                                    thread=0 msg="bye bye"
+"""

tests/loglevel/release_build_level.test

@@ -0,0 +1,17 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+release
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF after main                                 topics="general" thread=0
+INF exiting                                    thread=0 msg="bye bye"
+"""

tests/loglevel/topic_log_level1.test

@@ -0,0 +1,15 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_enabled_topics="foo:WARN,bar:INFO,main"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/loglevel/topic_log_level2.test

@@ -0,0 +1,16 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_enabled_topics="foo:INFO,bar:WARN,main"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/loglevel/topic_log_level3.test

@@ -0,0 +1,13 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=WARN
+chronicles_enabled_topics="foo:WARN,bar:INFO,main"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/loglevel/topic_log_level4.test

@@ -0,0 +1,14 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=WARN
+chronicles_enabled_topics="foo:INFO,bar:WARN,main"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/loglevel/topic_log_level_none.test

@@ -0,0 +1,12 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=WARN
+chronicles_enabled_topics="foo:0,main:NONE"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/loglevel/topic_log_level_number.test

@@ -0,0 +1,16 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=WARN
+chronicles_enabled_topics="foo:3,bar:WARN,main:2"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/loglevel/warn_level.test

@@ -0,0 +1,11 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=WARN
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/logscope/dynamic_scopes.test

@@ -0,0 +1,9 @@
+program="dynamic_scopes"
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF test                                       topics="main" thread=0 reqId=10 userId=20
+WRN about to exit                              topics="main" thread=0 timeSpent=2s
+"""

tests/other/indent.test

@@ -0,0 +1,26 @@
+program=lexical_scopes
+chronicles_sinks="textblocks[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_indent=1
+
+[Output]
+stdout="""INF main started topics="main"
+ thread: 0
+ a: 10
+ arg: 50
+ b: inner-b
+ c: 10
+ d: some-d
+ x: 16
+ z: 20
+
+INF exiting
+ thread: 0
+ a: 12
+ b: overriden-b
+ c: 100
+ msg: bye bye
+ x: 16
+
+"""

tests/other/line_numbers.test

@@ -0,0 +1,19 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_line_numbers=on
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 file=topics_and_loglvls.nim:9 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 file=topics_and_loglvls.nim:10 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 file=topics_and_loglvls.nim:11 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 file=topics_and_loglvls.nim:18 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 file=topics_and_loglvls.nim:19 arg=10 b=10
+DBG inside foo                                 topics="foo" thread=0 file=topics_and_loglvls.nim:20 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 file=topics_and_loglvls.nim:27 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 file=topics_and_loglvls.nim:28 arg=20 b=10
+DBG inside foobar                              topics="foo bar" thread=0 file=topics_and_loglvls.nim:29 arg=20 b=10
+INF after main                                 topics="general" thread=0 file=topics_and_loglvls.nim:35
+INF exiting                                    thread=0 file=topics_and_loglvls.nim:36 msg="bye bye"
+"""

tests/other/long_lines.test

@@ -0,0 +1,22 @@
+program=long_lines
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF long info                                  thread=0 file=long_lines.nim:10 str="some multiline\nstring\nmore lines"
+WRN long warning                               thread=0 str="some multiline\nstring\nmore lines"
+INF long info
+  thread: 0
+  str: some multiline
+       string
+       more lines
+
+WRN long warning
+  thread: 0
+  str: some multiline
+       string
+       more lines
+  z: 10
+
+"""

tests/perf/release_opt_size.test

@@ -0,0 +1,13 @@
+program=lexical_scopes
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+max_size=72832
+
+release
+--opt:size
+
+[Output]
+stdout="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/perf/size_check_debug.test

@@ -0,0 +1,109 @@
+program=size
+max_size=1640000
+
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=AnsiColors
+chronicles_timestamps="None"
+
+[Output]
+stdout="""INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+"""

tests/perf/size_check_release.test

@@ -0,0 +1,111 @@
+--skip ; this test takes long indeed, see issue #29
+program=size
+max_size=1
+release
+
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=AnsiColors
+chronicles_timestamps="None"
+
+[Output]
+stdout="""INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+INF hello                                      thread=0 a=1 b=2 c=3 d=4 e=5
+"""

tests/rt_filtering/runtime_filtering.test

@@ -0,0 +1,59 @@
+program="runtime_filtering"
+chronicles_sinks="textlines[stdout,file]"
+chronicles_runtime_filtering="on"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""> start by printing both:
+INF from foo                                   topics="main foo" thread=0
+INF from bar                                   topics="main bar" thread=0
+> disabling main, both should be omitted:
+true
+> set foo to required, only foo should be printed:
+true
+true
+INF from foo                                   topics="main foo" thread=0
+> set bar to enabled, only bar should be printed:
+true
+true
+INF from bar                                   topics="main bar" thread=0
+> disable main again, both should be omitted:
+true
+> try a wrong call to setTopicState, disable bar and print out only foo:
+true
+false
+true
+INF from foo                                   topics="main foo" thread=0
+> restore everything to normal, both should print:
+true
+true
+true
+INF from foo                                   topics="main foo" thread=0
+INF from bar                                   topics="main bar" thread=0
+> set main to WARN, none should print:
+true
+true
+true
+> set foo to INFO, bar to WARN, main back to default, foo should print:
+true
+true
+true
+INF from foo                                   topics="main foo" thread=0
+> set global LogLevel to WARN, set main and foo to INFO, foo should print:
+true
+true
+true
+INF from foo                                   topics="main foo" thread=0
+"""
+
+runtime_filtering.log="""INF from foo                                   topics="main foo" thread=0
+INF from bar                                   topics="main bar" thread=0
+INF from foo                                   topics="main foo" thread=0
+INF from bar                                   topics="main bar" thread=0
+INF from foo                                   topics="main foo" thread=0
+INF from foo                                   topics="main foo" thread=0
+INF from bar                                   topics="main bar" thread=0
+INF from foo                                   topics="main foo" thread=0
+INF from foo                                   topics="main foo" thread=0
+"""

tests/runtime_filtering.nim

@@ -70,7 +70,7 @@ echo setTopicState("bar", Normal)
 foo()
 bar()
 
-echo "> set foo to INFO, main back to default, foo should print:"
+echo "> set foo to INFO, bar to WARN, main back to default, foo should print:"
 echo setTopicState("main", Normal)
 echo setTopicState("foo", Normal, INFO)
 echo setTopicState("bar", Normal, WARN)

tests/sinks/custom_file_nocolors.test

@@ -0,0 +1,8 @@
+program=lexical_scopes
+chronicles_sinks="textlines[nocolors,file(mylog.txt)]"
+chronicles_timestamps=None
+
+[Output]
+mylog.txt="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/sinks/custom_file_notimestamps.test

@@ -0,0 +1,8 @@
+program=lexical_scopes
+chronicles_sinks="textlines[notimestamps,file(mylog.txt)]"
+chronicles_colors=None
+
+[Output]
+mylog.txt="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/sinks/double_sink.test

@@ -0,0 +1,29 @@
+program=lexical_scopes
+chronicles_sinks="textlines[file(lines.txt,truncate)],textblocks[file(blocks.txt,truncate)]"
+chronicles_timestamps=None
+chronicles_colors=None
+
+[Output]
+lines.txt="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+blocks.txt="""INF main started topics="main"
+  thread: 0
+  a: 10
+  arg: 50
+  b: inner-b
+  c: 10
+  d: some-d
+  x: 16
+  z: 20
+
+INF exiting
+  thread: 0
+  a: 12
+  b: overriden-b
+  c: 100
+  msg: bye bye
+  x: 16
+
+"""

tests/sinks/json_file_stdout.test

@@ -0,0 +1,13 @@
+program=lexical_scopes
+chronicles_sinks="json[stdout,file]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""{"msg": "main started", "lvl": "INFO", "topics": "main", "thread": 0, "a": 10, "arg": 50, "b": "inner-b", "c": 10, "d": "some-d", "x": 16, "z": 20}
+{"msg": "exiting", "lvl": "INFO", "thread": 0, "a": 12, "b": "overriden-b", "c": 100, "msg": "bye bye", "x": 16}
+"""
+
+lexical_scopes.log="""{"msg": "main started", "lvl": "INFO", "topics": "main", "thread": 0, "a": 10, "arg": 50, "b": "inner-b", "c": 10, "d": "some-d", "x": 16, "z": 20}
+{"msg": "exiting", "lvl": "INFO", "thread": 0, "a": 12, "b": "overriden-b", "c": 100, "msg": "bye bye", "x": 16}
+"""

tests/sinks/property_per_sink.test

@@ -0,0 +1,27 @@
+program=lexical_scopes
+chronicles_sinks="textlines[file(lines.txt,truncate),nocolors],textblocks[file(blocks.txt,truncate),notimestamps]"
+
+[Output]
+lines.txt="""INF 2018-10-12 12:24:21+02:00 main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF 2018-10-12 12:24:21+02:00 exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+blocks.txt="""INF main started topics="main"
+  thread: 0
+  a: 10
+  arg: 50
+  b: inner-b
+  c: 10
+  d: some-d
+  x: 16
+  z: 20
+
+INF exiting
+  thread: 0
+  a: 12
+  b: overriden-b
+  c: 100
+  msg: bye bye
+  x: 16
+
+"""

tests/sinks/textblocks_file_stdout.test

@@ -0,0 +1,45 @@
+program=lexical_scopes
+chronicles_sinks="textblocks[stdout,file]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF main started topics="main"
+  thread: 0
+  a: 10
+  arg: 50
+  b: inner-b
+  c: 10
+  d: some-d
+  x: 16
+  z: 20
+
+INF exiting
+  thread: 0
+  a: 12
+  b: overriden-b
+  c: 100
+  msg: bye bye
+  x: 16
+
+"""
+
+lexical_scopes.log="""INF main started topics="main"
+  thread: 0
+  a: 10
+  arg: 50
+  b: inner-b
+  c: 10
+  d: some-d
+  x: 16
+  z: 20
+
+INF exiting
+  thread: 0
+  a: 12
+  b: overriden-b
+  c: 100
+  msg: bye bye
+  x: 16
+
+"""

tests/sinks/textlines_file.test

@@ -0,0 +1,9 @@
+program=lexical_scopes
+chronicles_sinks="textlines[file]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+lexical_scopes.log="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/sinks/textlines_file_stdout.test

@@ -0,0 +1,13 @@
+program=lexical_scopes
+chronicles_sinks="textlines[stdout,file]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+lexical_scopes.log="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/sinks/textlines_stdout.test

@@ -0,0 +1,9 @@
+program=lexical_scopes
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/sinks/tripple_sink.test

@@ -0,0 +1,33 @@
+program=lexical_scopes
+chronicles_sinks="textlines[file(lines.txt,truncate)],textblocks[file(blocks.txt,truncate)],json[file(log.json,truncate)]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+lines.txt="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+blocks.txt="""INF main started topics="main"
+  thread: 0
+  a: 10
+  arg: 50
+  b: inner-b
+  c: 10
+  d: some-d
+  x: 16
+  z: 20
+
+INF exiting
+  thread: 0
+  a: 12
+  b: overriden-b
+  c: 100
+  msg: bye bye
+  x: 16
+
+"""
+
+log.json="""{"msg": "main started", "lvl": "INFO", "topics": "main", "thread": 0, "a": 10, "arg": 50, "b": "inner-b", "c": 10, "d": "some-d", "x": 16, "z": 20}
+{"msg": "exiting", "lvl": "INFO", "thread": 0, "a": 12, "b": "overriden-b", "c": 100, "msg": "bye bye", "x": 16}
+"""

tests/size.nim

@@ -0,0 +1,103 @@
+import chronicles
+
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+info "hello", a=1, b=2, c=3, d=4, e=5
+

tests/streams/custom_stream.test

@@ -0,0 +1,11 @@
+program="custom_stream"
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF before main                                thread=0 a=1 b=3
+[INFO] inside main:  (thread=0, key=val)
+INF after main                                 thread=0
+[WARN] exiting:  (thread=0)
+"""

tests/streams/file_log_stream.test

@@ -0,0 +1,11 @@
+program=file_log_stream
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout=""""""
+logger.log="""INF hello
+  thread: 0
+
+"""

tests/streams/runtime_path.test

@@ -0,0 +1,9 @@
+program=runtime_path
+chronicles_sinks="textlines[file]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout=""""""
+mylog.log="""INF log record                                 thread=0 prop=10
+"""

tests/streams/streams.test

@@ -0,0 +1,11 @@
+program=multiple_streams
+chronicles_streams="foo[textlines],default[textlines]"
+chronicles_colors=None
+
+[Output]
+stdout="""INF 2018-10-12 21:15:33+02:00 dynamic scope starts                       thread=0 reqId=10 userId=20
+INF 2018-10-12 21:15:33+02:00 logging to foo                             thread=0
+INF 2018-10-12 21:15:33+02:00 dynamic scope ends                         thread=0 reqId=10 userId=20
+INF 2018-10-12 21:15:33+02:00 logging to foo                             thread=0
+WRN 2018-10-12 21:15:33+02:00 about to exit main                         thread=0
+"""

tests/streams/streams_different_formats.test

@@ -0,0 +1,14 @@
+program=multiple_streams
+chronicles_streams="foo[textlines],default[json[file]]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF logging to foo                             thread=0
+INF logging to foo                             thread=0
+"""
+
+default.log="""{"msg": "dynamic scope starts", "lvl": "INFO", "thread": 0, "reqId": 10, "userId": 20}
+{"msg": "dynamic scope ends", "lvl": "INFO", "thread": 0, "reqId": 10, "userId": 20}
+{"msg": "about to exit main", "lvl": "WARN", "thread": 0}
+"""

tests/streams/streams_different_formats2.test

@@ -0,0 +1,24 @@
+program=multiple_streams
+chronicles_streams="foo[textlines],default[textblocks[file]]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF logging to foo                             thread=0
+INF logging to foo                             thread=0
+"""
+
+default.log="""INF dynamic scope starts
+  thread: 0
+  reqId: 10
+  userId: 20
+
+INF dynamic scope ends
+  thread: 0
+  reqId: 10
+  userId: 20
+
+WRN about to exit main
+  thread: 0
+
+"""

tests/streams/streams_different_property.test

@@ -0,0 +1,12 @@
+program=multiple_streams
+chronicles_streams="foo[textlines[stdout,nocolors]],default[textlines[file,notimestamps]]"
+
+[Output]
+stdout="""INF 2018-10-12 21:56:43+02:00 logging to foo                             thread=0
+INF 2018-10-12 21:56:43+02:00 logging to foo                             thread=0
+"""
+
+default.log="""INF dynamic scope starts                       thread=0 reqId=10 userId=20
+INF dynamic scope ends                         thread=0 reqId=10 userId=20
+WRN about to exit main                         thread=0
+"""

tests/streams/xml_stream_usage.test

@@ -0,0 +1,11 @@
+program=xml_stream_usage
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""<event type="New Stream" severity="INFO">
+  <thread>0</thread>
+  <episode>Smarty Cat</episode>
+  <franchise>Tom &amp; Jerry</franchise>
+</event>
+"""

tests/test_config.nim

@@ -0,0 +1,121 @@
+import os, parsecfg, parseopt, strutils, streams
+
+const
+  Usage = """Usage:
+  testrunner [options] path
+  Run the test(s) specified at path. Will search recursively for test files
+  provided path is a directory.
+Options:
+  --targets:"c c++ js objc" [Not implemented] run tests for specified targets
+  --help                    display this help and exit"""
+
+type
+  TestConfig* = object
+    path*: string
+    includedTests*: seq[string]
+    excludedTests*: seq[string]
+
+  TestSpec* = object
+    name*: string
+    skip*: bool
+    program*: string
+    flags*: string
+    outputs*: seq[tuple[name: string, expectedOutput: string]]
+    timestampPeg*: string
+    errorMsg*: string
+    maxSize*: int64
+    compileError*: string
+    errorFile*: string
+    errorLine*: int
+    errorColumn*: int
+    os*: seq[string]
+
+proc processArguments*(): TestConfig =
+  var opt = initOptParser()
+  var length = 0
+  for kind, key, value in opt.getopt():
+    case kind
+    of cmdArgument:
+      if result.path == "":
+        result.path = key
+    of cmdLongOption, cmdShortOption:
+      inc(length)
+      case key.toLowerAscii()
+        of "help", "h": quit(Usage, QuitSuccess)
+        of "targets", "t": discard # not implemented
+        of "include":
+          result.includedTests.add value.split(Whitespace + {','})
+        of "exclude":
+          result.excludedTests.add value.split(Whitespace + {','})
+        else: quit(Usage)
+    of cmdEnd:
+      quit(Usage)
+
+  if result.path == "":
+    quit(Usage)
+
+proc defaults(result: var TestSpec) =
+  result.os = @["linux", "macosx", "windows"]
+
+proc parseTestFile*(filePath: string): TestSpec =
+  result.defaults()
+  result.name = splitFile(filePath).name
+  var f = newFileStream(filePath, fmRead)
+  var outputSection = false
+  if f != nil:
+    var p: CfgParser
+    open(p, f, filePath)
+    while true:
+      var e = next(p)
+      case e.kind
+      of cfgEof:
+        break
+      of cfgSectionStart:
+        if e.section.cmpIgnoreCase("Output") == 0:
+          outputSection = true
+      of cfgKeyValuePair:
+        if outputSection:
+          result.outputs.add((e.key, e.value))
+        else:
+          case e.key
+          of "program":
+            result.program = e.value
+          of "timestamp_peg":
+            result.timestampPeg = e.value
+          of "max_size":
+            if e.value.isDigit:
+              result.maxSize = parseInt(e.value)
+            else:
+              echo("Parsing warning: value of " & e.key &
+                   " is not a number (value = " & e.value & ").")
+          of "compile_error":
+            result.compileError = e.value
+          of "error_file":
+            result.errorFile = e.value
+          of "os":
+            result.os = e.value.normalize.split({','} + Whitespace)
+          else:
+            result.flags &= ("-d:$#:$#" % [e.key, e.value]).quoteShell & " "
+      of cfgOption:
+        case e.key
+        of "skip":
+          result.skip = true
+        else:
+          result.flags &= ("--$#:$#" % [e.key, e.value]).quoteShell & " "
+      of cfgError:
+        echo("Parsing warning:" & e.msg)
+    close(p)
+    if result.program == "":
+      echo("Parsing error: no program value")
+  else:
+    echo("Parsing error: cannot open " & filePath)
+
+func shouldSkip*(c: TestConfig, testName: string): bool =
+  if testName in c.excludedTests:
+    return true
+
+  if c.includedTests.len > 0:
+    return testName notin c.includedTests
+
+  return false
+

tests/test_helpers.nim

@@ -0,0 +1,90 @@
+import os, osproc, strutils, streams, pegs
+
+type
+  CompileInfo* = object
+    templFile*: string
+    errorFile*: string
+    errorLine*, errorColumn*: int
+    templLine*, templColumn*: int
+    msg*: string
+    fullMsg*: string
+    compileTime*: float
+    exitCode*: int
+
+let
+  # Error pegs, taken from testament tester
+  pegLineTemplate =
+    peg"{[^(]*} '(' {\d+} ', ' {\d+} ') ' 'template/generic instantiation from here'.*"
+  pegLineError =
+    peg"{[^(]*} '(' {\d+} ', ' {\d+} ') ' ('Error') ':' \s* {.*}"
+  pegOtherError = peg"'Error:' \s* {.*}"
+  pegError = pegLineError / pegOtherError
+  pegSuccess = peg"'Hint: operation successful' {[^;]*} '; '  {\d+} '.' {\d+} .*"
+
+  # Timestamp pegs
+  # peg for unix timestamp, basically any float with 6 digits after the decimal
+  # Not ideal - could also improve by checking for the location in the line
+  pegUnixTimestamp = peg"{\d+} '.' {\d\d\d\d\d\d} \s"
+  # peg for timestamp with format yyyy-MM-dd HH:mm:sszzz
+  pegRfcTimestamp = peg"{\d\d\d\d} '-' {\d\d} '-' {\d\d} ' ' {\d\d} ':' {\d\d} ':' {\d\d} {'+' / '-'} {\d\d} ':' {\d\d} \s"
+
+proc cmpIgnorePeg*(a, b: string, peg: Peg): bool =
+  return a.replace(peg, "dummy") == b.replace(peg, "dummy")
+
+proc cmpIgnoreTimestamp*(a, b: string, timestamp = ""): bool =
+  if timestamp.len == 0:
+    return a == b
+  else:
+    if timestamp == "RfcTime":
+      return cmpIgnorePeg(a, b, pegRfcTimestamp)
+    elif timestamp == "UnixTime":
+      return cmpIgnorePeg(a, b, pegUnixTimestamp)
+
+proc cmpIgnoreDefaultTimestamps*(a, b: string): bool =
+  if a == b:
+    return true
+  elif cmpIgnorePeg(a, b, pegRfcTimestamp):
+    return true
+  elif cmpIgnorePeg(a, b, pegUnixTimestamp):
+    return true
+  else: return false
+
+# parsing based on testament tester
+proc parseCompileStream*(p: Process, output: Stream): CompileInfo =
+  result.exitCode = -1
+  var line = newStringOfCap(120).TaintedString
+  var suc, err, tmpl = ""
+
+  while true:
+    if output.readLine(line):
+      if line =~ pegError:
+       # `err` should contain the last error/warning message
+       err = line
+      elif line =~ pegLineTemplate and err == "":
+       # `tmpl` contains the last template expansion before the error
+       tmpl = line
+      elif line =~ pegSuccess:
+       suc = line
+
+      if err != "":
+       result.fullMsg.add(line.string & "\p")
+    else:
+     result.exitCode = peekExitCode(p)
+     if result.exitCode != -1: break
+
+  if tmpl =~ pegLineTemplate:
+    result.templFile = extractFilename(matches[0])
+    result.templLine = parseInt(matches[1])
+    result.templColumn = parseInt(matches[2])
+  if err =~ pegLineError:
+    result.errorFile = extractFilename(matches[0])
+    result.errorLine = parseInt(matches[1])
+    result.errorColumn = parseInt(matches[2])
+    result.msg = matches[3]
+  elif err =~ pegOtherError:
+    result.msg = matches[0]
+  elif suc =~ pegSuccess:
+    result.msg = suc
+    result.compileTime = parseFloat(matches[1] & "." & matches[2])
+
+proc parseExecuteOutput*() = discard

tests/testrunner.nim

@@ -0,0 +1,229 @@
+import os, osproc, re, strutils, terminal, times, pegs
+import test_config, test_helpers
+
+# Testrunner to run tests for chronicles library
+# However, could in theory be used to run any test that needs to check
+# compile time or runtime output
+#
+# The runner will look recursively for all *.test files at given path.
+# A test file should have at minimum a program name. This is the name of the nim
+# source minus the .nim extension)
+#
+# Code is here and there influenced by nim testament tester and unittest module.
+
+const
+  # defaultOptions = "--verbosity:1 --warnings:off --hint[Processing]:off " &
+  #                  "--hint[Conf]:off --hint[XDeclaredButNotUsed]:off " &
+  #                  "--hint[Link]:off --hint[Pattern]:off"
+  defaultOptions = "--verbosity:1 --warnings:off "
+
+type
+  TestStatus* = enum
+    OK,
+    FAILED,
+    SKIPPED,
+    INVALID
+
+# If needed pass more info to the logresult via a TestResult object
+  # TestResult = object
+  #   status: TestStatus
+  #   compileTime: float
+  #   fileSize: uint
+
+  TestError* = enum
+    SourceFileNotFound,
+    ExeFileNotFound,
+    OutputFileNotFound,
+    CompileError,
+    RuntimeError,
+    OutputsDiffer,
+    FileSizeTooLarge,
+    CompileErrorDiffers
+
+proc logFailure(test: TestSpec, error: TestError, data: varargs[string] = [""]) =
+  case error
+    of SourceFileNotFound:
+      styledEcho(fgYellow, styleBright, "source file not found: ",
+                 resetStyle, test.program.addFileExt(".nim"))
+    of ExeFileNotFound:
+      styledEcho(fgYellow, styleBright, "file not found: ",
+                 resetStyle, test.program.addFileExt(ExeExt))
+    of OutputFileNotFound:
+      styledEcho(fgYellow, styleBright, "file not found: ",
+                 resetStyle, data[0])
+    of CompileError:
+      styledEcho(fgYellow, styleBright, "compile error:\p",
+                 resetStyle, data[0])
+    of RuntimeError:
+      styledEcho(fgYellow, styleBright, "runtime error:\p",
+                 resetStyle, data[0])
+    of OutputsDiffer:
+      styledEcho(fgYellow, styleBright, "outputs are different:\p",
+                 resetStyle,"Expected output to $#:\p$#" % [data[0], data[1]],
+                            "Resulted output to $#:\p$#" % [data[0], data[2]])
+    of FileSizeTooLarge:
+      styledEcho(fgYellow, styleBright, "file size is too large: ",
+                 resetStyle, data[0] & " > " & $test.maxSize)
+    of CompileErrorDiffers:
+      styledEcho(fgYellow, styleBright, "compile error is different:\p",
+                 resetStyle, data[0])
+
+  styledEcho(fgCyan, styleBright, "command: ", resetStyle,
+             "nim c $#$#$#" % [defaultOptions, test.flags,
+                                 test.program.addFileExt(".nim")])
+
+proc logResult(testName: string, status: TestStatus, time: float) =
+  var color = case status
+              of OK: fgGreen
+              of FAILED: fgRed
+              of SKIPPED: fgYellow
+              of INVALID: fgRed
+              else: fgWhite
+  styledEcho(styleBright, color, "[", $status, "] ",
+             resetStyle, testName,
+             fgYellow, " ", time.formatFloat(ffDecimal, 3), " s")
+
+template time(duration, body): untyped =
+  let t0 = epochTime()
+  block:
+    body
+  duration =  epochTime() - t0
+
+proc cmpOutputs(test: TestSpec, stdout: string): TestStatus =
+  result = OK
+  for output in test.outputs:
+    var testOutput: string
+    if output.name == "stdout":
+      testOutput = stdout
+    else:
+      if not existsFile(output.name):
+        logFailure(test, OutputFileNotFound, output.name)
+        result = FAILED
+        continue
+
+      testOutput = readFile(output.name)
+
+    # Would be nice to do a real diff here instead of simple compare
+    if test.timestampPeg.len > 0:
+      if not cmpIgnorePeg(testOutput, output.expectedOutput, peg(test.timestampPeg)):
+        logFailure(test, OutputsDiffer, output.name, output.expectedOutput, testOutput)
+        result = FAILED
+    else:
+      if not cmpIgnoreDefaultTimestamps(testOutput, output.expectedOutput):
+        logFailure(test, OutputsDiffer, output.name, output.expectedOutput, testOutput)
+        result = FAILED
+
+    if output.name != "stdout":
+      removeFile(output.name)
+
+proc compile(test: TestSpec): TestStatus =
+  let source = test.program.addFileExt(".nim")
+  if not existsFile(source):
+    logFailure(test, SourceFileNotFound)
+    return FAILED
+
+  let cmd = "nim c $#$#$#" % [defaultOptions, test.flags, source.quoteShell]
+  let c = parseCmdLine(cmd)
+  var p = startProcess(command=c[0], args=c[1.. ^1],
+                       options={poStdErrToStdOut, poUsePath})
+  let compileInfo = parseCompileStream(p, p.outputStream)
+  close(p)
+
+  if compileInfo.exitCode != 0:
+    if test.compileError.len == 0:
+      logFailure(test, CompileError, compileInfo.fullMsg)
+      return FAILED
+    else:
+      if test.compileError == compileInfo.msg and
+         (test.errorFile.len == 0 or test.errorFile == compileInfo.errorFile) and
+         (test.errorLine == 0 or test.errorLine == compileInfo.errorLine) and
+         (test.errorColumn == 0 or test.errorColumn == compileInfo.errorColumn):
+        return OK
+      else:
+        logFailure(test, CompileErrorDiffers, compileInfo.fullMsg)
+        return FAILED
+
+  # Lets also check file size here as it kinda belongs to the compilation result
+  if test.maxSize != 0:
+    var size = getFileSize(test.program.addFileExt(ExeExt))
+    if size > test.maxSize:
+      logFailure(test, FileSizeTooLarge, $size)
+      return FAILED
+
+  return OK
+
+proc execute(test: TestSpec): TestStatus =
+  let program = test.program.addFileExt(ExeExt)
+  if not existsFile(program):
+    logFailure(test, ExeFileNotFound)
+    return FAILED
+
+  let (output, exitCode) = execCmdEx(CurDir & DirSep & program.quoteShell)
+
+  if exitCode != 0:
+    # parseExecuteOutput() # Need to parse the run time failures?
+    logFailure(test, RuntimeError, output)
+    return FAILED
+  else:
+    return test.cmpOutputs(output)
+
+# Get rid of re dependency?
+proc scanTestPath(path: string): seq[string] =
+  result = @[]
+
+  if fileExists(path):
+    result.add(path)
+  else:
+    for file in walkDirRec path:
+      if file.match re".*\.test":
+        result.add(file)
+
+proc test(config: TestConfig, testPath: string): TestStatus =
+  var test: TestSpec
+  var duration: float
+
+  time duration:
+    test = parseTestFile(testPath)
+    if test.program.len == 0: # a program name is bare minimum of a test file
+      result = INVALID
+      break
+    if test.skip or hostOS notin test.os or config.shouldSkip(test.name):
+      result = SKIPPED
+      break
+
+    result = test.compile()
+    if result != OK or test.compileError.len > 0:
+      break
+
+    result = test.execute()
+    removeFile(test.program.addFileExt(ExeExt))
+
+  logResult(test.name, result, duration)
+
+proc main() =
+  let config = processArguments()
+  let testFiles = scanTestPath(config.path)
+  var successful, skipped = 0
+
+  if testFiles.len == 0:
+    styledEcho(styleBright, "No test files found")
+    program_result = 1
+    return
+
+  for testFile in testFiles:
+    # Here we could do multithread or multiprocess
+    # but we will have to work with different nim caches per test
+    # and also the executables have to be in a unique location as several tests
+    # can use the same source
+    var result = test(config, testFile)
+    if result == OK:
+      successful += 1
+    elif result == SKIPPED:
+      skipped += 1
+
+  styledEcho(styleBright, "Finished run: $#/$# tests successful" %
+                          [$successful, $(testFiles.len - skipped)])
+  program_result = testFiles.len - successful - skipped
+
+when isMainModule:
+  main()

tests/timestamps/no_timestamps.test

@@ -0,0 +1,13 @@
+program=lexical_scopes
+chronicles_sinks="textlines[stdout,file]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+[Output]
+stdout="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+lexical_scopes.log="""INF main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/timestamps/ownpeg_timestamps.test

@@ -0,0 +1,16 @@
+program=lexical_scopes
+chronicles_sinks="textlines[stdout,file]"
+chronicles_colors=None
+chronicles_timestamps=UnixTime
+
+; any float
+timestamp_peg=r"{\d+} '.' {\d+} \s"
+
+[Output]
+stdout="""INF 1539371702.190928 main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF 1539371702.191123 exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+lexical_scopes.log="""INF 1539371702.190928 main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF 1539371702.191123 exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/timestamps/rfc_timestamps.test

@@ -0,0 +1,13 @@
+program=lexical_scopes
+chronicles_sinks="textlines[stdout,file]"
+chronicles_colors=None
+chronicles_timestamps=RfcTime
+
+[Output]
+stdout="""INF 2018-10-12 21:15:05+02:00 main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF 2018-10-12 21:15:05+02:00 exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+lexical_scopes.log="""INF 2018-10-12 21:15:05+02:00 main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF 2018-10-12 21:15:05+02:00 exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/timestamps/unix_timestamps.test

@@ -0,0 +1,13 @@
+program=lexical_scopes
+chronicles_sinks="textlines[stdout,file]"
+chronicles_colors=None
+chronicles_timestamps=UnixTime
+
+[Output]
+stdout="""INF 1539371702.190928 main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF 1539371702.191123 exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""
+
+lexical_scopes.log="""INF 1539371702.190928 main started                               topics="main" thread=0 a=10 arg=50 b=inner-b c=10 d=some-d x=16 z=20
+INF 1539371702.191123 exiting                                    thread=0 a=12 b=overriden-b c=100 msg="bye bye" x=16
+"""

tests/topics/disabled.test

@@ -0,0 +1,14 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_disabled_topics:"foo bar"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF after main                                 topics="general" thread=0
+INF exiting                                    thread=0 msg="bye bye"
+"""

tests/topics/enabled.test

@@ -0,0 +1,18 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_enabled_topics:"main foo"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+DBG inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+DBG inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/topics/enabled_vs_disabled.test

@@ -0,0 +1,13 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_enabled_topics:"main foo"
+chronicles_disabled_topics:"foo"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+"""

tests/topics/enabled_vs_required.test

@@ -0,0 +1,10 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+
+chronicles_enabled_topics:"main foo"
+chronicles_required_topics:"main foo"
+
+compile_error="Please specify only one of the options 'chronicles_enabled_topics' and 'chronicles_required_topics'."
+error_file=options.nim

tests/topics/required1.test

@@ -0,0 +1,15 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_required_topics:"foo"
+
+[Output]
+stdout="""WRN inside foo                                 topics="foo" thread=0 arg=10 b=10
+INF inside foo                                 topics="foo" thread=0 arg=10 b=10
+DBG inside foo                                 topics="foo" thread=0 arg=10 b=10
+WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+DBG inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/topics/required2.test

@@ -0,0 +1,12 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_required_topics:"foo bar"
+
+[Output]
+stdout="""WRN inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+INF inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+DBG inside foobar                              topics="foo bar" thread=0 arg=20 b=10
+"""

tests/topics/required_vs_disabled.test

@@ -0,0 +1,10 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_required_topics:"foo bar"
+chronicles_disabled_topics:"foo"
+
+[Output]
+stdout=""""""

tests/topics/required_vs_disabled2.test

@@ -0,0 +1,13 @@
+program=topics_and_loglvls
+chronicles_sinks="textlines[stdout]"
+chronicles_colors=None
+chronicles_timestamps=None
+chronicles_log_level=DEBUG
+chronicles_required_topics:"main"
+chronicles_disabled_topics:"foo bar"
+
+[Output]
+stdout="""WRN inside main                                topics="main" thread=0 a=1 arg=50 b=10
+INF inside main                                topics="main" thread=0 a=1 arg=50 b=10
+DBG inside main                                topics="main" thread=0 a=1 arg=50 b=10
+"""

tests/topics_and_loglvls.nim

@@ -0,0 +1,36 @@
+import chronicles
+
+proc main(arg: int) =
+  logScope:
+    topics = "main"
+    arg
+    a = 1
+
+  warn("inside main", b = 10)
+  info("inside main", b = 10)
+  debug("inside main", b = 10)
+
+proc foo(arg: int) =
+  logScope:
+    topics = "foo"
+    arg
+
+  warn("inside foo", b = 10)
+  info("inside foo", b = 10)
+  debug("inside foo", b = 10)
+
+proc foobar(arg: int) =
+  logScope:
+    topics = "foo bar"
+    arg
+
+  warn("inside foobar", b = 10)
+  info("inside foobar", b = 10)
+  debug("inside foobar", b = 10)
+
+main(50)
+foo(10)
+foobar(20)
+
+info("after main", topics = "general")
+info("exiting", msg = "bye bye")

tests/xml_stream.nim

@@ -1,7 +1,7 @@
 import xmldom, chronicles
 
 type XmlRecord[Output] = object
-  output: Output
+  output*: Output
 
 template initLogRecord*(r: var XmlRecord, lvl: LogLevel,
                         topics: string, name: string) =