WIP README file

README.md

@@ -1,2 +1,511 @@
+nim-chronicles
+==============
+
+[![Build Status](https://travis-ci.org/status-im/nim-chronicles.svg?branch=master)](https://travis-ci.org/status-im/nim-chronicles)
+[![License: Apache](https://img.shields.io/badge/License-Apache%202.0-blue.svg)](https://opensource.org/licenses/Apache-2.0)
+[![License: MIT](https://img.shields.io/badge/License-MIT-yellow.svg)](https://opensource.org/licenses/MIT)
+
+```
+nimble install chronicles
+```
+
+## Introduction
+
+nim-chronicles is a logging library that adheres to the philosophy that
+you shouldn't be logging formatted text strings, instead you should be
+logging well-defined structured records featuring arbitrary properties.
+Let's illustate this with an example:
 
 
+``` nim
+import net, chronicles
+
+socket.accept(...)
+...
+debug "Client PSK", psk = client.getPskIdentity
+info "New icoming connection", remoteAddr = ip, remotePort = port
+
+```
+
+Here, `debug` and `info` are logging statements, corresponding to different
+severity levels. You can think of their first argument as the name of a
+particular event that happened during the execution of the program, while
+the rest of the arguments are the properties of this event.
+
+From these logging statements, Chronicles can be configured to produce log
+output in various structured formats. The default format is called `textblocks` and it looks like this:
+
+![textblocks format example](media/textblocks.svg)
+
+Alternatively, you can use another human-readable format called `textlines`:
+
+![textblocks format example](media/textlines.svg)
+
+While these human-readable formats provide a more traditional and familiar
+experience of using a logging library, the true power of Chronicles is
+unlocked only after switching to the `JSON` format. Then, the same log output
+will look like this:
+
+![json format example](media/json.svg)
+
+At first, switching to JSON may look like a dounting proposition, but
+Chronicles provides a customized log tailing program called `chronicles-tail`
+which is able to transofm the JSON stream back into human-readable form,
+while also providing additional advanced features such as on on-the-fly
+filtering, sound alerts and more.
+
+The main advantage of using JSON logging is that this facilitates the storage
+of the log records in specialized databases which are usually able to provide
+search and filtering capabilities and allow you to compute various aggregated
+metrics and time-series data from the accumulated logs.
+
+Typical log storage choices for the above are open-source search engines such
+as [ElasticSearch][1] or specilized providers such as [Loggly][2].
+
+[1]: https://www.elastic.co/
+[2]: https://www.loggly.com/
+
+## Logging Scopes
+
+In the introduction, we saw `debug` and `info` as examples for logging
+statements. Other similar statements include `notice`, `warn`, `error`
+and `fatal`. All of these statements accept arbitrary key-value pairs,
+but you can also specify only the name of a local variable, which will
+create a key will the same name (i.e. passing a local varialbe named
+`foo` will be translated to the pair `foo = foo`).
+
+A typical practice enforced in other logging libraries is to associate
+the logging recrods with the name of the component that produced them
+or with a particular run-time property such as `RequestID`. Chronicles
+provides two general-purspose facilities for assigning such properties
+in an automated way:
+
+### `logScope`
+
+`logScope` can be used to introduce additional properties that will be
+automatically attached to all logging statements in the current lexical
+scope:
+
+``` nim
+logScope:
+  # Lexical properties are typically assigned to a constant:
+  topics = "rendering opengl"
+
+  # But you can also assign an expression that will be
+  # evaluated on every log statement:
+  memoryUsage = currentMemUsage()
+
+proc renderFrame(...) =
+  inc frameCounter
+
+  logScope:
+    # You can add additional properties in any scope. Only logging
+    # stetements that are in the same lexical scope will be affected:
+    frame = frameCounter
+
+  var t = startTimer()
+  debug "Frame started"
+
+  ...
+
+  glFinish()
+  debug "Frame finished", totalPrimitives, frameTime = t.elapsed
+```
+
+A `logScope` is usually put near the top of a Nim module and used to
+specify statically assigned properties such as message origin, component
+name, etc. The special `topics` property demostrated here is important
+for the log filtering mechanism, which will be exlained in more details
+later.
+
+If you want to have a program-wide set of custom properties that should be
+attached to all log statements (e.g. a `serverId`), you can create a global
+variable or a proc obtaining the property and then reference it from a
+`logScope` created inside a module that proxies the import of `chronicles`:
+
+``` nim
+# logging.nim
+
+import chronicles
+export chronicles
+
+proc getServerId()
+
+logScope:
+  serverId = getServerId()
+
+```
+
+Using Nim's `--import:` option may be a good way to enforce the use of
+this proxy module in your entire program.
+
+### `dynamicLogScope`
+
+A `dynamicLogScope` is a construct accepting a block of code that can be
+used to attach properties to all logging statements that will be executed
+anywhere within the tree of calls originating from the said block. The key
+difference with the lexically bound properties is that this includes
+logging statements from other modules, which are not within the lexical
+scope of the `dynamicLogScope` statement.
+
+If you still find the distinction between lexical and dynamic scopes confusing,
+reading the following explanation may help you:
+
+http://wiki.c2.com/?DynamicScoping
+
+A dynamic scope is usually used to track what is the reason why a particular
+library function is being called (e.g. you are opening a file as a result of
+a particular network request):
+
+``` nim
+proc onNewRequest(req: Request) =
+  inc reqID
+  info "request received", reqID, origin = req.remoteAddress
+  dynamicLogScope(reqID):
+    # All logging statements triggered before the current block returns
+    # will feature the reqID property. This includes logging statements
+    # from other modules.
+    handleRequest(req)
+```
+
+Just like regular log statements, `dynamicLogScope` accepts a list of arbitrary
+key-value pairs. The use of `reqID` in the example above is a convenient short
+form for specifying the pair `reqID = reqID`.
+
+While the properties associated with lexical scopes are lazily evaluated as
+demostrated previously, all expressions at the begining of a dynamic scope
+will be eagerly evaluated before the block is entered.
+
+## Compile-Time Configuration
+
+Almost everything about Chronicles in configured at compile-time, through the
+mechanism of Nim's `-d:` flags. For example, you can completely remove all of
+the code related to logging by simply setting `chronicles_enabled` to `off`:
+
+```
+nim c -d:chronicles_enabled=off myprogram.nim
+```
+
+Chronicles comes with a very reasonable default configuration, but let's look
+at some of the other supported options:
+
+### chronicles_sinks
+
+Chronicles supports producing log records in multiple formats and writing
+those to various destinations such as the std streams, the system's syslog
+daemon, or to one or more log files.
+
+The combination of a log format and one or more associated log destinations
+is called a 'sink'. You can use the `chronicles_sinks` option to provide the
+list of sinks that will be used in your program.
+
+The sinks are specified as a comma-separated list of valid Nim expressions
+that will be better illustated by the following examples:
+
+- `json`
+
+  Write JSON-records to stdout
+
+- `json[file]`
+
+  Write JSON-records to a file in the current directory named after the
+  application itself.
+
+- `textblocks[stdout,file(/var/log/myapp.log)]`
+
+  Use the 'textblocks' format and send the output both to stdout and
+  to a file with an absolute path /var/log/myapp.log
+
+- `textlines[notimestamps,file(myapp.txt),syslog]`
+
+  Use the 'textlines' format, but don't include timestamps and write
+  both to a file named 'myapp.txt' with a relative path to the current
+  working directory and also to syslog.
+
+- `textlines[nocolors],json[file(logs/myapp.json)]`
+
+  Send the output both in the 'textlines' format to stdout (but without
+  using colors) and to a JSON file named myapp.json in the relative
+  directory 'logs'.
+
+The built-in formats include `json`, `textlines` and `textblocks`, which
+support options for specifying the use of colors and timestamps (for more
+info see `chronicles_colors` and `chronicles_timestamps`).
+
+The possible log destinations are `stdout`, `stderr`, `file` and `syslog`.
+
+Please note that Chronicles also allows you to implement custom logging
+formats thought the use of the `customLogStream` facility.
+
+### chronicles_streams
+
+While having multiple log sinks enables you to record the same stream of
+events in multiple formats and destinations, `chronicles_streams` allows
+you to define additional independent streams identified by their name.
+In the code, each logging statement is associated with exactly one log
+stream, which in turn has an associated list of sinks.
+
+The syntax for defining streams closely resembles the syntax for defining
+sinks:
+
+- `textlog[textlines],transactions[json[file(transactions.json)]]`
+
+This will create two streams, called `textlog` and `transactions`.
+The former will be considered the default stream associated with unqualified
+logging statements, but each of the strams will exist as a separate symbol
+in the code featuring the full set of logging operations:
+
+``` nim
+textlog.debug "about to create a transaction"
+transactions.info "transaction created", buyer = alice, seller = bob
+```
+
+The streams created through `chronicles_streams` will be exported by the
+`chronicles` module itself, but you can also introduce additional streams
+in your own modules by using the helpers `logStream` and `customLogStream`.
+
+### chronicles_enabled_topics
+
+All logging statements may be associated with a statically known list of
+topics. Usually, this is done by specifying the `topics` property in a
+particular `logScope`, but you can also specify it for individual log
+statements.
+
+You can use the `chronicles_enabled_topics` option to specify the list of
+topics for which the logging statements should produce output. All other
+logging statements will be erased from the final code at compile time.
+When the list includes multiple topics, any of them is considered a match.
+
+> In both contexts, the list of topics is written as a comma or space-separated
+string of case-sensitive topic names.
+
+### chronicles_required_topics
+
+Similar to `chronicles_enabled_topics`, but requires the logging statements
+to have all of the topics specified in this list.
+
+### chronicles_disabled_topics
+
+The dual of `chronicles_enabled_topics`. This option specifies a black-list
+of topics for which the associated logging statements should be erased from
+the program.
+
+### chronicles_log_level
+
+This option can be used to erase all log statements, not matching the
+specified minimum log level at compile-time.
+
+Possible values are 'DEBUG', 'INFO', 'NOTICE', 'WARN', 'ERROR', 'FATAL',
+and 'NONE'. The default value is 'DEBUG' in debug builds and `INFO` in
+release mode.
+
+### chronicles_runtime_filtering
+
+This option enables the run-filtering capabilities of Chronicles.
+The run-time filtering is controlled through the procs `setLogLevel`
+and `setTopicState`:
+
+```nim
+type LogLevel = enum
+  DEBUG, INFO, NOTICE, WARN, ERROR, FATAL, NONE
+
+proc setLogLevel*(level: LogLevel)
+
+type TopicState = enum
+  Normal, Enabled, Reqired, Disabled
+
+proc setTopicState*(topicName: string, state: TopicState): bool
+```
+
+The option is disabled by default, because we recommend filtering the
+log output in a tailing program. This allows you to still look at all
+logged events in case this becomes necessary. Set to `on` to enable.
+
+### chronicles_timestamps
+
+This option controls the use of timestamps in the log output.
+Possible values are:
+
+- `RfcTime` (used by default)
+
+  Chronicles will use the human-readable format specified in
+  RFC 3339: Date and Time on the Internet: Timestamps
+
+  https://tools.ietf.org/html/rfc3339
+
+- `UnixTime`
+
+  Chronicles will write a single float value for the number
+  of seconds since the "Unix epoch"
+
+  https://en.wikipedia.org/wiki/Unix_time
+
+- `None`
+
+  Chronicles will not include timestamps in the log output.
+
+Please note that the timestamp format can also be specified
+for individual sinks (see `chronicles_sinks`).
+
+### chronicles_colors
+
+This option controls the default color scheme used by Chronicles for
+its human-readable text formats when sent to the standard output streams.
+
+Possible values are:
+
+- `AnsiColors` (used by default)
+
+  Output suitable for terminals supporting the standard ANSI escape codes:
+  https://en.wikipedia.org/wiki/ANSI_escape_code
+
+  This includes most terminal emulators on modern Unix-like systems,
+  Windows console replacements such as ConEmu, and the native Console
+  and PowerShell applications on Windows 10.
+
+- `NativeColors` (affects Windows only)
+
+  In this mode, Windows builds will produce output suitable for the console
+  application in older versions of Windows. On Unix-like systems, ANSI codes
+  are still used.
+
+- `None`
+
+  Chronicles will produce color-less output. Please note that this is the
+  default mode for sinks logging only to files or for sinks using the json
+  format.
+
+Current known limitations:
+
+- Chronicles will not try to detect if the standard outputs
+  of the program are being redirected to another program or a file.
+  It's typical for the colored output to be disabled in such circumstances.
+  ([issue](issues/1))
+
+### chronicles_indent
+
+This option sets the desired number of spaces that Chronicles should
+use as indentation in the `textblocks` format.
+
+-----------------
+
+> All options are case-insensitive and accept a number of truthy
+and falsy values such as `on`, `off`, `true`, `false`, `0`, `1`,
+`yes`, `no` or `none`.
+
+## Custom Streams
+
+As an alternative to specifying multiple output streams with the
+`chronicles_streams` option, you can also introduce additional
+streams within the code of your program. A typical way to do this
+would be to introduce a proxy module that imports and re-exports
+`chronicles` while adding additional streams with `logStream`:
+
+``` nim
+import chronicles
+export chronicles
+
+logStream transactions[json[file(transactions.json)]]
+```
+
+The expression expected by `logStream` has exactly the same format
+as the compile-time option and produces the same effect. In this particular
+example, it will create a new stream called `transactions` that will be sent
+to a JSON file named `transactions.json`.
+
+After importing the proxy module, you'll be able to create records with any
+of the logging statements in the usual way:
+
+``` nim
+import transactions_log
+
+...
+
+transactions.error "payment gateway time-out", orderId,
+                    networkStatus = obtainNetworkStatus()
+```
+
+### Implementing new Log Formats
+
+TBD
+
+``` nim
+import xmldom, chronicles
+export chronicles
+
+type XmlRecord[Output] = object
+  output: Output
+
+template initLogRecord*(r: var XmlRecord, lvl: LogLevel, name: string) =
+  r.output.append "<event name=\"", escapeXml(name), "\" severity=\"", $lvl, "\">\n"
+
+template setProperty*(r: var XmlRecord, key: string, val: auto) =
+  r.output.append textBlockIndent, "<", key, ">", escapeXml($val), "</", key, ">\n"
+
+template setFirstProperty*(r: var XmlRecord, key: string, val: auto) =
+  r.setProperty key, val
+
+template flushRecord*(r: var XmlRecord) =
+  r.output.append "</event>\n"
+  r.output.flushOutput
+
+customLogStream xmlStream[XmlRecord[StdOutOutput]]
+
+logScope:
+  stream = xmlout
+
+info "New Video", franchise = "Tom & Jerry", episode = "Smarty Cat"
+```
+
+As demonstrated in the example above, you can set the `stream` property in
+a Chronicles lexical scope to redirect all unqualified log statements to a
+particular default stream.
+
+The produced output from the example will be:
+
+``` xml
+<event name="New Video" severity="INFO">
+  <thread>0</thread>
+  <episode>Smarty Cat</episode>
+  <franchise>Tom &amp; Jerry</franchise>
+</event>
+```
+
+## Cost of Abstractions and Implementation Details
+
+
+
+## Future Directions
+
+At the moment, Chronicles intentionally omits certain features expected
+from a logging library such as log rotation and archival. We recommend
+following the guidelines set in the [12-factor app methodology][12F-LOGS]
+and sending your log output to `stdout`. It should be the responsibity
+of the supervising daemon of the app to implement log rotation and archival.
+
+We understand that certain users would want to take advantage of the
+file sinks provided by Chronicles and these users may benefit from the
+aforementioned features. If the Nim community provides a package for
+a low-level abstraction of an automatically rotated and archived log
+file, Chronicles will provide options for using it.
+
+[12F-LOGS]: https://12factor.net/logs
+
+## Contributing
+
+The development of Chronicles is Sponsored by [Status.im](https://status.im/)
+through the [OpenBounty](https://openbounty.status.im/) initiative. Please
+take a look at our tracker for any issues having the [bounty][Bounties] tag.
+
+When submitting pull requests, please add test cases for any new features
+or fixed bugs and make sure `nimble test` is still able to execute the
+entire test suite successfully.
+
+[Bounties]: https://github.com/status-im/nim-chronicles/issues?q=is%3Aissue+is%3Aopen+label%3Abounty
+
+## License
+
+Licensed at your option under either of:
+
+ * Apache License, Version 2.0, ([LICENSE-APACHE](LICENSE-APACHE) or http://www.apache.org/licenses/LICENSE-2.0)
+ * MIT license ([LICENSE-MIT](LICENSE-MIT) or http://opensource.org/licenses/MIT)

chronicles.nim

@@ -6,23 +6,24 @@ export
   dynamic_scope, log_output, options
 
 template chroniclesLexScopeIMPL* =
-  0 # scope revision number
+  0 # track the scope revision
 
 macro mergeScopes(prevScopes: typed, newBindings: untyped): untyped =
   var
-    bestScope = prevScopes.lastScopeHolder
+    bestScope = prevScopes.lastScopeBody
     bestScopeRev = bestScope.scopeRevision
 
   var finalBindings = initTable[string, NimNode]()
-  for k, v in assignments(bestScope.getImpl.actualBody, skip = 1):
+  for k, v in assignments(bestScope.scopeAssignments):
     finalBindings[k] = v
 
-  for k, v in assignments(newBindings):
+  for k, v in assignments(newBindings, false):
     finalBindings[k] = v
 
   result = newStmtList()
+  var newRevision = newLit(bestScopeRev + 1)
+  var newAssingments = newStmtList()
 
-  var newScopeDefinition = newStmtList(newLit(bestScopeRev + 1))
   for k, v in finalBindings:
     if k == "stream":
       let streamId = newIdentNode($v)
@@ -31,14 +32,16 @@ macro mergeScopes(prevScopes: typed, newBindings: untyped): untyped =
         when not declared(`streamId`):
           # XXX: how to report the proper line info here?
           {.error: `errorMsg`.}
-        elif not isStreamSymbolIMPL(`streamId`):
-          {.error: `errorMsg`.}
+        #elif not isStreamSymbolIMPL(`streamId`):
+        #  {.error: `errorMsg`.}
         template chroniclesActiveStreamIMPL: typedesc = `streamId`
     else:
-      newScopeDefinition.add newAssignment(newIdentNode(k), v)
+      newAssingments.add newAssignment(newIdentNode(k), v)
 
   result.add quote do:
-    template chroniclesLexScopeIMPL = `newScopeDefinition`
+    template chroniclesLexScopeIMPL =
+      `newRevision`
+      `newAssingments`
 
 template logScope*(newBindings: untyped) {.dirty.} =
   bind bindSym, mergeScopes, brForceOpen
@@ -113,13 +116,19 @@ macro logIMPL(recordType: typedesc,
               logStmtBindings: varargs[untyped]): untyped =
   if not loggingEnabled or severity < enabledLogLevel: return
 
+  # Nim will sometimes do something silly - it will convert our varargs
+  # into an empty array. We need to detect this case and handle it:
+  if logStmtBindings.len == 1 and
+     logStmtBindings[0].kind == nnkHiddenStdConv:
+    logStmtBindings.del 0
+
   let lexicalBindings = scopes.finalLexicalBindings
   var finalBindings = initOrderedTable[string, NimNode]()
 
-  for k, v in assignments(lexicalBindings, skip = 1):
+  for k, v in assignments(lexicalBindings):
     finalBindings[k] = v
 
-  for k, v in assignments(logStmtBindings, skip = 1):
+  for k, v in assignments(logStmtBindings):
     finalBindings[k] = v
 
   finalBindings.sort(system.cmp)

chronicles/dynamic_scope.nim

@@ -38,7 +38,7 @@ macro dynamicLogScopeIMPL*(recordType: typedesc,
     error "dynamicLogScope expects a block", body
 
   var stream = config.streams[0]
-  for k, v in assignments(lexicalScopes.finalLexicalBindings, skip = 1):
+  for k, v in assignments(lexicalScopes.finalLexicalBindings):
     if k == "stream":
       stream = handleUserStreamChoice(v)
 

chronicles/log_output.nim

@@ -5,14 +5,17 @@ export
   LogLevel
 
 type
-  FileOutput[outputId: static[int]] = object
-  StdOutOutput = object
-  StdErrOutput = object
-  SysLogOutput = object
+  FileOutput*[outputId: static[int]] = object
+  StdOutOutput* = object
+  StdErrOutput* = object
+  SysLogOutput* = object
 
-  BufferedOutput[FinalOutputs: tuple] = object
+  BufferedOutput*[FinalOutputs: tuple] = object
     buffer: string
 
+  AnyOutput = FileOutput|StdOutOutput|StdErrOutput|
+              SysLogOutput|BufferedOutput
+
   TextLineRecord[Output;
                  timestamps: static[TimestampsScheme],
                  colors: static[ColorScheme]] = object
@@ -88,28 +91,37 @@ var
 # The LogRecord types are parametric on their Output and this is how we
 # can support arbitrary combinations of log formats and destinations.
 
-template append(o: var FileOutput, s: string) = fileOutputs[o.outputId].write s
-template flushOutput(o: var FileOutput)       = fileOutputs[o.outputId].flushFile
+template append*(o: var FileOutput, s: string) = fileOutputs[o.outputId].write s
+template flushOutput*(o: var FileOutput)       = fileOutputs[o.outputId].flushFile
 
-template append(o: var StdOutOutput, s: string) = stdout.write s
-template flushOutput(o: var StdOutOutput)       = stdout.flushFile
+template append*(o: var StdOutOutput, s: string) = stdout.write s
+template flushOutput*(o: var StdOutOutput)       = stdout.flushFile
 
-template append(o: var StdErrOutput, s: string) = stderr.write s
-template flushOutput(o: var StdOutOutput)       = stdout.flushFile
+template append*(o: var StdErrOutput, s: string) = stderr.write s
+template flushOutput*(o: var StdErrOutput)       = stderr.flushFile
 
 # The buffered Output works in a very simple way. The log message is first
 # buffered into a sting and when it needs to be flushed, we just instantiate
 # each of the Output types and call `append` and `flush` on the instance:
 
-template append(o: var BufferedOutput, s: string) =
+template append*(o: var BufferedOutput, s: string) =
   o.buffer.add(s)
 
-template flushOutput(o: var BufferedOutput) =
+template flushOutput*(o: var BufferedOutput) =
   var finalOuputs: o.FinalOutputs
   for finalOutput in finalOuputs.fields:
     append(finalOutput, o.buffer)
     flushOutput(finalOutput)
 
+macro append*(o: var AnyOutput,
+              arg1, arg2: untyped,
+              restArgs: varargs[untyped]): untyped =
+  # Allow calling append with many arguments
+  result = newStmtList()
+  result.add newCall("append", o, arg1)
+  result.add newCall("append", o, arg2)
+  for arg in restArgs: result.add newCall("append", o, arg)
+
 # The formatting functions defined for each LogRecord type are carefully
 # written to expand to multiple calls to `append` that can be merged by
 # a simple term-rewriting rule. In the final code, any consequtive appends
@@ -153,8 +165,8 @@ template appendLogLevelMarker(r: var auto, lvl: LogLevel) =
 
   when r.colors == AnsiColors:
     let (color, bright) = case lvl
-                          of DEBUG: (fgGreen, false)
-                          of INFO:  (fgGreen, true)
+                          of DEBUG: (fgGreen, true)
+                          of INFO:  (fgGreen, false)
                           of NOTICE:(fgYellow, false)
                           of WARN:  (fgYellow, true)
                           of ERROR: (fgRed, false)

chronicles/options.nim

@@ -2,76 +2,38 @@ import
   macros, strutils, strformat, sequtils, ospaths
 
 # The default behavior of Chronicles can be configured through a wide-range
-# of compile-time -d: switches. This module implements the validation of all
-# specified options and reducing them to a `Configuration` constant that can
-# be accessed from the rest of the modules.
+# of compile-time -d: switches (for more information, see the README).
+# This module implements the validation of all specified options and reduces
+# them to a `Configuration` constant that can be accessed from the rest of
+# the modules.
 
 const
   chronicles_enabled {.strdefine.} = "on"
-    ## Disabling this option will competely remove all chronicles-related code
-    ## from the target binary.
-
-  chronicles_enabled_topics {.strdefine.} = ""
-    ## You can use this option to specify a comma-separated list of topics for
-    ## which the logging statements should produce output. All other logging
-    ## statements will be erased from the final code at compile time.
-    ## When the list includes multiple topics, any of them is considered a match.
-
-  chronicles_required_topics {.strdefine.} = ""
-    ## Similar to `chronicles_enabled_topics`, but requires the logging statements
-    ## to have all topics specified in the list.
-
-  chronicles_disabled_topics {.strdefine.} = ""
-    ## The dual of `chronicles_enabled_topics`. The option specifies a black-list
-    ## of topics for which the associated logging statements should be erased from
-    ## the program.
-
-  chronicles_log_level {.strdefine.} = when defined(debug): "ALL"
-                                       else: "INFO"
-    ## This option can be used to erase all log statements, not matching the
-    ## specified minimum log level at compile-time.
-
-  chronicles_runtime_filtering {.strdefine.} = "off"
-    ## This option enables the run-filtering capabilities of chronicles.
-    ## The run-time filtering is controlled through the procs `setLogLevel`
-    ## and `setTopicState`.
-
-  chronicles_timestamps {.strdefine.} = "RfcTime"
-    ## This option controls the use of timestamps in the log output.
-    ## Possible values are:
-    ##
-    ## - RfcTime (used by default)
-    ##
-    ##   Chronicles will use the human-readable format specified in
-    ##   RFC 3339: Date and Time on the Internet: Timestamps
-    ##
-    ##   https://tools.ietf.org/html/rfc3339
-    ##
-    ## - UnixTime
-    ##
-    ##   Chronicles will write a single float value for the number
-    ##   of seconds since the "Unix epoch"
-    ##
-    ##   https://en.wikipedia.org/wiki/Unix_time
-    ##
-    ## - NoTimestamps
-    ##
-    ##   Chronicles will not include timestamps in the log output.
-    ##
-    ## Please note that the timestamp format can also be specified
-    ## for individual sinks (see `chronicles_sinks`).
-
   chronicles_sinks* {.strdefine.} = ""
   chronicles_streams* {.strdefine.} = ""
+
+  chronicles_enabled_topics {.strdefine.} = ""
+  chronicles_required_topics {.strdefine.} = ""
+  chronicles_disabled_topics {.strdefine.} = ""
+  chronicles_runtime_filtering {.strdefine.} = "off"
+  chronicles_log_level {.strdefine.} = when defined(debug): "ALL"
+                                       else: "INFO"
+
+  chronicles_timestamps {.strdefine.} = "RfcTime"
+  chronicles_colors* {.strdefine.} = "AnsiColors"
+
   chronicles_indent {.intdefine.} = 2
-  chronicles_colors* {.strdefine.} = "on"
+
+  truthySwitches = ["yes", "1", "on", "true"]
+  falsySwitches = ["no", "0", "off", "false", "none"]
+    # You can use any of these values when specifying on/off options.
+    # They are case-insensitive.
 
 when chronicles_streams.len > 0 and chronicles_sinks.len > 0:
   {.error: "Please specify only one of the options 'chronicles_streams' and 'chronicles_sinks'." }
 
 type
   LogLevel* = enum
-    ALL,
     DEBUG,
     INFO,
     NOTICE,
@@ -126,9 +88,9 @@ type
 proc handleYesNoOption(optName: string,
                        optValue: string): bool {.compileTime.} =
   let canonicalValue = optValue.toLowerAscii
-  if canonicalValue in ["yes", "1", "on", "true"]:
+  if canonicalValue in truthySwitches:
     return true
-  elif canonicalValue in ["no", "0", "off", "false"]:
+  elif canonicalValue in falsySwitches:
     return false
   else:
     error &"A non-recognized value '{optValue}' for option '{optName}'. " &
@@ -143,7 +105,12 @@ proc enumValues(E: typedesc[enum]): string =
 proc handleEnumOption(E: typedesc[enum],
                       optName: string,
                       optValue: string): E {.compileTime.} =
-  try: return parseEnum[E](optValue)
+  try:
+    if optValue.toLowerAscii in falsySwitches:
+      type R = type(result)
+      return R(0)
+    else:
+      return parseEnum[E](optValue)
   except: error &"'{optValue}' is not a recognized value for '{optName}'. " &
                 &"Allowed values are {enumValues E}"
 
@@ -204,9 +171,7 @@ proc logDestinationFromNode(n: NimNode): LogDestination =
            "Please refer to the documentation for the supported options."
 
 const
-  defaultColorScheme = when handleYesNoOption(chronicles_colors): AnsiColors
-                       else: NoColors
-
+  defaultColorScheme = handleEnumOption(ColorScheme, chronicles_colors)
   defaultTimestamsScheme = handleEnumOption(TimestampsScheme, chronicles_timestamps)
 
 proc syntaxCheckStreamExpr*(n: NimNode) =

chronicles/scope_helpers.nim

@@ -5,47 +5,46 @@ type
   BindingsSet* = Table[string, NimNode]
   FinalBindingsSet* = OrderedTable[string, NimNode]
 
-iterator assignments*(n: NimNode, skip = 0): (string, NimNode) =
+iterator assignments*(n: NimNode, liftIdentifiers = true): (string, NimNode) =
   # extract the assignment pairs from a block with assigments
   # or a call-site with keyword arguments.
-  for i in skip ..< n.len:
-    let child = n[i]
+  for child in n:
     if child.kind in {nnkAsgn, nnkExprEqExpr}:
       let name = $child[0]
       let value = child[1]
       yield (name, value)
+    elif child.kind == nnkIdent and liftIdentifiers:
+      yield ($child, child)
     else:
       error "A scope definitions should consist only of key-value assignments"
 
-proc actualBody*(n: NimNode): NimNode =
-  # skip over the double StmtList node introduced in `mergeScopes`
-  result = n.body
-  if result.kind == nnkStmtList and result[0].kind == nnkStmtList:
-    result = result[0]
+proc scopeAssignments*(scopeBody: NimNode): NimNode =
+  if scopeBody.len > 1:
+    result = scopeBody[1]
+  else:
+    result = newStmtList()
 
-proc scopeRevision*(scopeSymbol: NimNode): int =
-  # get the revision number from a `chroniclesLexScopeIMPL` sym
-  assert scopeSymbol.kind == nnkSym
-  var revisionNode = scopeSymbol.getImpl.actualBody[0]
+proc scopeRevision*(scopeBody: NimNode): int =
+  # get the revision number from a `chroniclesLexScopeIMPL` body
+  var revisionNode = scopeBody[0]
   result = int(revisionNode.intVal)
 
-proc lastScopeHolder*(scopes: NimNode): NimNode =
-  # get the most recent `chroniclesLexScopeIMPL` from a symChoice node
+proc lastScopeBody*(scopes: NimNode): NimNode =
+  # get the most recent `chroniclesLexScopeIMPL` body from a symChoice node
   if scopes.kind in {nnkClosedSymChoice, nnkOpenSymChoice}:
     var bestScopeRev = 0
     assert scopes.len > 0
     for scope in scopes:
-      let rev = scope.scopeRevision
+      let scopeBody = scope.getImpl.body
+      let rev = scopeBody.scopeRevision
       if result == nil or rev > bestScopeRev:
-        result = scope
+        result = scopeBody
         bestScopeRev = rev
   else:
-    result = scopes
-
-  assert result.kind == nnkSym
+    result = scopes.getImpl.body
 
 template finalLexicalBindings*(scopes: NimNode): NimNode =
-  scopes.lastScopeHolder.getImpl.actualBody
+  scopes.lastScopeBody.scopeAssignments
 
 proc handleUserStreamChoice*(n: NimNode): StreamSpec =
   # XXX: This proc could use a lent result once the compiler supports it

media/json.svg

@@ -0,0 +1 @@
+<svg xmlns="http://www.w3.org/2000/svg" xmlns:xlink="http://www.w3.org/1999/xlink" width="910" height="194"><rect width="910" height="194" rx="5" ry="5" class="a"/><svg y="0%" x="0%"><circle cx="20" cy="20" r="6" fill="#ff5f58"/><circle cx="40" cy="20" r="6" fill="#ffbd2e"/><circle cx="60" cy="20" r="6" fill="#18c132"/></svg><svg height="803.27" viewBox="0 0 87 80.327" width="870" x="15" xmlns="http://www.w3.org/2000/svg" xmlns:xlink="http://www.w3.org/1999/xlink" y="50"><style>.a{fill:#282d35}.h,.i,.j,.k{fill:#e88388;font-weight:700}.i,.j,.k{fill:#66c2cd}.j,.k{fill:#71bef2}.k{fill:#dbab79}.l{fill:#b9c0cb}</style><g font-size="1.67" font-family="Monaco,Consolas,Menlo,'Bitstream Vera Sans Mono','Powerline Symbols',monospace"><defs><symbol id="a"><path fill="transparent" d="M0 0h87v37H0z"/></symbol><symbol id="b"><path fill="#6f7683" d="M0 0h1.102v2.171H0z"/></symbol></defs><path class="a" d="M0 0h87v80.327H0z"/><svg width="87"><svg><use xlink:href="#a"/><use xlink:href="#b" x="23.996" y="10.83"/><text y="1.67" class="h">➜</text><text x="3.006" y="1.67" class="i">tests</text><text x="9.018" y="1.67" class="j">git:(</text><text x="14.028" y="1.67" class="h">master</text><text x="20.04" y="1.67" class="j">)</text><text x="22.044" y="1.67" class="k">✗</text><text x="24.048" y="1.67" class="l">./sockets-json</text><text y="3.841" class="l">{&quot;msg&quot;:</text><text x="8.016" y="3.841" class="l">&quot;Client</text><text x="16.032" y="3.841" class="l">PSK&quot;,</text><text x="22.044" y="3.841" class="l">&quot;lvl&quot;:</text><text x="29.058" y="3.841" class="l">&quot;DEBUG&quot;,</text><text x="38.076" y="3.841" class="l">&quot;ts&quot;:</text><text x="44.088" y="3.841" class="l">&quot;2018-05-01</text><text x="56.112" y="3.841" class="l">18:56:14&quot;,</text><text x="67.134" y="3.841" class="l">&quot;thread&quot;:</text><text x="77.154" y="3.841" class="l">0,</text><text x="80.16" y="3.841" class="l">&quot;psk&quot;:</text><text y="6.012" class="l">&quot;5125debc6b736dbfcf68527f05d006479e5e62892c071782c0acda67a60e6e2f&quot;}</text><text y="8.183" class="l">{&quot;msg&quot;:</text><text x="8.016" y="8.183" class="l">&quot;New</text><text x="13.026" y="8.183" class="l">icoming</text><text x="21.042" y="8.183" class="l">connection&quot;,</text><text x="34.068" y="8.183" class="l">&quot;lvl&quot;:</text><text x="41.082" y="8.183" class="l">&quot;INFO&quot;,</text><text x="49.098" y="8.183" class="l">&quot;ts&quot;:</text><text x="55.11" y="8.183" class="l">&quot;2018-05-01</text><text x="67.134" y="8.183" class="l">18:56:14&quot;,</text><text x="78.156" y="8.183" class="l">&quot;thread&quot;:</text><text x="1.002" y="10.354" class="l">0,</text><text x="4.008" y="10.354" class="l">&quot;remoteAddr&quot;:</text><text x="18.036" y="10.354" class="l">&quot;192.168.1.2&quot;,</text><text x="33.066" y="10.354" class="l">&quot;remotePort&quot;:</text><text x="47.094" y="10.354" class="l">26532}</text><text y="12.525" fill="#a8cc8c" font-weight="700">➜</text><text x="3.006" y="12.525" class="i">tests</text><text x="9.018" y="12.525" class="j">git:(</text><text x="14.028" y="12.525" class="h">master</text><text x="20.04" y="12.525" class="j">)</text><text x="22.044" y="12.525" class="k">✗</text></svg></svg></g></svg></svg>

media/textblocks.svg

@@ -0,0 +1 @@
+<svg xmlns="http://www.w3.org/2000/svg" xmlns:xlink="http://www.w3.org/1999/xlink" width="910" height="303"><rect width="910" height="303" rx="5" ry="5" class="a"/><svg y="0%" x="0%"><circle cx="20" cy="20" r="6" fill="#ff5f58"/><circle cx="40" cy="20" r="6" fill="#ffbd2e"/><circle cx="60" cy="20" r="6" fill="#18c132"/></svg><svg height="803.27" viewBox="0 0 87 80.327" width="870" x="15" xmlns="http://www.w3.org/2000/svg" xmlns:xlink="http://www.w3.org/1999/xlink" y="50"><style>.a{fill:#282d35}.f,.g,.j,.k,.l{fill:#71bef2}.g,.j,.k,.l{font-weight:700}.j,.k,.l{fill:#e88388}.k,.l{fill:#66c2cd}.l{fill:#dbab79}.m{fill:#b9c0cb}.n{fill:#a8cc8c}.o{fill:#b9c0cb;font-weight:700}</style><g font-size="1.67" font-family="Monaco,Consolas,Menlo,'Bitstream Vera Sans Mono','Powerline Symbols',monospace"><defs><symbol id="1"><text x="2.004" y="1.67" class="f">thread:</text><text x="10.02" y="1.67" class="g">0</text></symbol><symbol id="a"><path fill="transparent" d="M0 0h87v37H0z"/></symbol><symbol id="b"><path fill="#6f7683" d="M0 0h1.102v2.171H0z"/></symbol></defs><path class="a" d="M0 0h87v80.327H0z"/><svg width="87"><svg><use xlink:href="#a"/><use xlink:href="#b" x="23.996" y="21.685"/><text y="1.67" class="j">➜</text><text x="3.006" y="1.67" class="k">tests</text><text x="9.018" y="1.67" class="g">git:(</text><text x="14.028" y="1.67" class="j">master</text><text x="20.04" y="1.67" class="g">)</text><text x="22.044" y="1.67" class="l">✗</text><text x="24.048" y="1.67" class="m">./sockets-textblocks</text><text y="3.841" class="m">[2018-05-01</text><text x="12.024" y="3.841" class="m">18:59:21]</text><text x="22.044" y="3.841" class="m">[</text><text x="23.046" y="3.841" class="n">DEBUG</text><text x="28.056" y="3.841" class="m">]</text><text x="30.06" y="3.841" class="o">Client</text><text x="37.074" y="3.841" class="o">PSK</text><use xlink:href="#1" y="4.342"/><text x="2.004" y="8.183" class="f">psk:</text><text x="7.014" y="8.183" class="g">5125debc6b736dbfcf68527f05d006479e5e62892c071782c0acda67a60e6e2f</text><text y="12.525" class="m">[2018-05-01</text><text x="12.024" y="12.525" class="m">18:59:21]</text><text x="22.044" y="12.525" class="m">[</text><text x="23.046" y="12.525" class="n">INFO</text><text x="27.054" y="12.525" class="m">]</text><text x="29.058" y="12.525" class="o">New</text><text x="33.066" y="12.525" class="o">icoming</text><text x="41.082" y="12.525" class="o">connection</text><use xlink:href="#1" y="13.026"/><text x="2.004" y="16.867" class="f">remoteAddr:</text><text x="14.028" y="16.867" class="g">192.168.1.2</text><text x="2.004" y="19.038" class="f">remotePort:</text><text x="14.028" y="19.038" class="g">26532</text><text y="23.38" fill="#a8cc8c" font-weight="700">➜</text><text x="3.006" y="23.38" class="k">tests</text><text x="9.018" y="23.38" class="g">git:(</text><text x="14.028" y="23.38" class="j">master</text><text x="20.04" y="23.38" class="g">)</text><text x="22.044" y="23.38" class="l">✗</text></svg></svg></g></svg></svg>

media/textlines.svg

@@ -0,0 +1 @@
+<svg xmlns="http://www.w3.org/2000/svg" xmlns:xlink="http://www.w3.org/1999/xlink" width="910" height="193"><rect width="910" height="193" rx="5" ry="5" class="a"/><svg y="0%" x="0%"><circle cx="20" cy="20" r="6" fill="#ff5f58"/><circle cx="40" cy="20" r="6" fill="#ffbd2e"/><circle cx="60" cy="20" r="6" fill="#18c132"/></svg><svg height="803.27" viewBox="0 0 87 80.327" width="870" x="15" xmlns="http://www.w3.org/2000/svg" xmlns:xlink="http://www.w3.org/1999/xlink" y="50"><style>.a{fill:#282d35}.h,.i,.j,.k{fill:#e88388;font-weight:700}.i,.j,.k{fill:#66c2cd}.j,.k{fill:#71bef2}.k{fill:#dbab79}.l{fill:#b9c0cb}.m{fill:#a8cc8c}.n{fill:#b9c0cb;font-weight:700}.o{fill:#71bef2}</style><g font-size="1.67" font-family="Monaco,Consolas,Menlo,'Bitstream Vera Sans Mono','Powerline Symbols',monospace"><defs><symbol id="a"><path fill="transparent" d="M0 0h87v37H0z"/></symbol><symbol id="b"><path fill="#6f7683" d="M0 0h1.102v2.171H0z"/></symbol></defs><path class="a" d="M0 0h87v80.327H0z"/><svg width="87"><svg><use xlink:href="#a"/><use xlink:href="#b" x="23.996" y="10.83"/><text y="1.67" class="h">➜</text><text x="3.006" y="1.67" class="i">tests</text><text x="9.018" y="1.67" class="j">git:(</text><text x="14.028" y="1.67" class="h">master</text><text x="20.04" y="1.67" class="j">)</text><text x="22.044" y="1.67" class="k">✗</text><text x="24.048" y="1.67" class="l">./sockets-textlines</text><text y="3.841" class="l">[2018-05-01</text><text x="12.024" y="3.841" class="l">18:58:23]</text><text x="22.044" y="3.841" class="l">[</text><text x="23.046" y="3.841" class="m">DEBUG</text><text x="28.056" y="3.841" class="l">]</text><text x="30.06" y="3.841" class="n">Client</text><text x="37.074" y="3.841" class="n">PSK</text><text x="41.082" y="3.841" class="l">(</text><text x="42.084" y="3.841" class="o">thread=</text><text x="49.098" y="3.841" class="j">0</text><text x="50.1" y="3.841" class="l">,</text><text x="52.104" y="3.841" class="o">psk=</text><text x="56.112" y="3.841" class="j">5125debc6b736dbfcf68527f05d0064</text><text y="6.012" class="j">79e5e62892c071782c0acda67a60e6e2f</text><text x="33.066" y="6.012" class="l">)</text><text y="8.183" class="l">[2018-05-01</text><text x="12.024" y="8.183" class="l">18:58:23]</text><text x="22.044" y="8.183" class="l">[</text><text x="23.046" y="8.183" class="m">INFO</text><text x="27.054" y="8.183" class="l">]</text><text x="29.058" y="8.183" class="n">New</text><text x="33.066" y="8.183" class="n">icoming</text><text x="41.082" y="8.183" class="n">connection</text><text x="52.104" y="8.183" class="l">(</text><text x="53.106" y="8.183" class="o">thread=</text><text x="60.12" y="8.183" class="j">0</text><text x="61.122" y="8.183" class="l">,</text><text x="63.126" y="8.183" class="o">remoteAddr=</text><text x="74.148" y="8.183" class="j">192.168.1.2</text><text x="85.17" y="8.183" class="l">,</text><text y="10.354" class="o">remotePort=</text><text x="11.022" y="10.354" class="j">26532</text><text x="16.032" y="10.354" class="l">)</text><text y="12.525" fill="#a8cc8c" font-weight="700">➜</text><text x="3.006" y="12.525" class="i">tests</text><text x="9.018" y="12.525" class="j">git:(</text><text x="14.028" y="12.525" class="h">master</text><text x="20.04" y="12.525" class="j">)</text><text x="22.044" y="12.525" class="k">✗</text></svg></svg></g></svg></svg>

tests/custom_stream.nim

@@ -32,7 +32,7 @@ proc main =
 
   info "inside main"
 
-info "before main"
+info("before main", a = 1, b = 3)
 
 main()
 

tests/xml_stream.nim

@@ -0,0 +1,24 @@
+import xmldom, chronicles
+export chronicles
+
+type XmlRecord[Output] = object
+  output: Output
+
+template initLogRecord*(r: var XmlRecord, lvl: LogLevel, name: string) =
+  r.output.append "<event type=\"", escapeXml(name), "\" severity=\"", $lvl, "\">\n"
+
+template setProperty*(r: var XmlRecord, key: string, val: auto) =
+  r.output.append textBlockIndent, "<", key, ">", escapeXml($val), "</", key, ">\n"
+
+template setFirstProperty*(r: var XmlRecord, key: string, val: auto) =
+  r.setProperty key, val
+
+template flushRecord*(r: var XmlRecord) =
+  r.output.append "</event>\n"
+  r.output.flushOutput
+
+customLogStream xmlStream[XmlRecord[StdOutOutput]]
+
+logScope:
+  stream = xmlStream
+

tests/xml_stream_usage.nim

@@ -0,0 +1,9 @@
+import xml_stream
+
+logScope:
+  stream = xmlStream
+
+# echo isStreamSymbolIMPL(xmlStream)
+
+info("New Stream", franchise = "Tom & Jerry", episode = "Smarty Cat")
+