Chronicles is a library for structured logging. It adheres to the philosophy that log files shouldn't be based on formatted text strings, but rather on well-defined event records with arbitrary properties that are easy to read for both humans and machines. Let's illustrate this with an example:
import net, chronicles socket.accept(...) ... debug "Client PSK", psk = client.getPskIdentity info "New incoming connection", remoteAddr = ip, remotePort = port
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
and it looks like this:
Alternatively, you can use a multi-line format called
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:
At first, switching to JSON may look like a daunting proposition, but
Chronicles provides a customized log tailing program called
which is able to transform the JSON stream back into the familiar 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.
In the introduction, we saw
info as examples for logging
statements. Other similar statements include
fatal. All of these statements accept arbitrary key-value pairs.
As a short-cut, you are also allowed to specify only the name of a particular
variable and Chronicles will create a key with the same name (i.e. passing
a local variable named
foo will be translated to the pair
foo = foo).
A common practice enforced in other logging libraries is to associate
the logging records with the name of the component that produced them
or with a particular run-time property such as
provides two general-purpose facilities for assigning such properties
in an automated way:
logScope can be used to introduce additional properties that will be
automatically attached to all logging statements in the current lexical
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 # statements 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
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 demonstrated here is important
for the log filtering mechanism, which will be explained in more details
later. If present, this property will always appear first in the formatted
logScope affects only the current module, a
allows you to specify a set of custom properties that may affect your
entire program. For example, if you have an application running in a
server cluster, you may want to assign a property such as
to every record. To achieve this, create a proxy logging module
chronicles and setting up a
# logging.nim import chronicles proc getServerId*() publicLogScope: serverId = getServerId()
Every other module importing the proxy module will be able to use the
entire Chronicles API and will be affected by the public scope.
In fact, you should not import
chronicles from such modules, because
this will lead to ambiguous symbols such as
--import: option may be a good way to enforce the use of
the proxy module in your entire program.
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
If you still find the distinction between lexical and dynamic scopes confusing, reading the following explanation may help you:
A dynamic scope is usually used to track 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):
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 previously demonstrated, all expressions at the beginning of a dynamic scope will be eagerly evaluated before the block is entered.
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
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 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 illustrated by the following examples:
Write JSON-records to stdout
Write JSON-records to a file in the current directory named after the application itself.
Use the 'textblocks' format and send the output both to stdout and to a file with an absolute path /var/log/myapp.log
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.
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 myapp.json file will be truncated on each program execution.
The built-in formats include
support options for specifying the use of colors and timestamps (for more
The possible log destinations are
Please note that Chronicles also allows you to implement custom logging
formats through the use of the
While having multiple log sinks enables you to record the same stream of
events in multiple formats and destinations,
you to define additional independent streams of events 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:
This will create two streams, called
The former will be considered the default stream associated with unqualified
logging statements, but each of the streams will exist as a separate symbol
in the code, supporting the full set of logging operations:
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
All logging statements may be associated with a statically known list of
topics. Usually, this is done by specifying the
topics property in a
logScope, but you can also specify it for individual log
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 at compile-time from the final code.
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.
In the list of topics, you can also optionally provide a log level after the
topic, separated with a colon from the topic. If a log level is provided it will
chronicles_log_level setting. The log level can be defined as
LogLevel values or directly as the corresponding integer values.
chronicles_enabled_topics, but requires the logging statements
to have all of the topics specified in this list.
You cannot specify
at the same time.
The dual of
chronicles_enabled_topics. This option specifies a black-list
of topics for which the associated logging statements should be erased from
chronicles_disabled_topics have precedence over the ones in
This option can be used to erase at compile-time all log statements, not matching the specified minimum log level.
Possible values are
NONE. The default value is
DEBUG in debug builds and
This option enables the run-filtering capabilities of Chronicles.
The run-time filtering is controlled through the procs
type LogLevel = enum NONE, TRACE, DEBUG, INFO, NOTICE, WARN, ERROR, FATAL proc setLogLevel*(level: LogLevel) type TopicState = enum Normal, Enabled, Required, Disabled proc setTopicState*(name: string, newState: TopicState, logLevel = LogLevel.NONE): bool
The log levels available at runtime - and therefor to
setLogLevel() - are
those greater than or equal to the one set at compile time by
It is also possible for a specific topic to overrule the global
setLogLevel, by setting the optional
logLevel parameter in
setTopicState to a valid
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 the option to
to enable it.
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
Chronicles will write a single float value for the number of seconds since the "Unix epoch"
Chronicles will not include timestamps in the log output.
Please note that the timestamp format can also be specified
for individual sinks (see
This option, disabled by default, enables the display of filename and line number
where each record was instantiated. It adds a property
file to the output, for example:
chronicles_line_numbers sets the default option for all records, it is
also possible to control the same property in a lexical scope or for a particular
log statement with
chroniclesLineNumbers, which can be either
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:
NativeColors(used by default)
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.
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.
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)
This option sets the desired number of spaces that Chronicles should
use as indentation in the
All of the discussed options are case-insensitive and accept a number of
truthy and falsy values such as
When a stream has
file outputs, you may choose to provide the log file
location at run-time. Chronicles will create each log file lazily when the
first log record is written. This gives you a chance to modify the default
compile-time path associated with each file output by calling the
proc on an
output symbol associated with the stream:
# my_program.nim var config = loadConfiguration() let success = defaultChroniclesStream.output.open(config.logFile, fmAppend) info "APPLICATION STARTED"
nim c -d:chronicles_sinks=textlines[file] my_program.nim
As you can see above, the default stream in Chronicles is called
defaultChroniclesStream. If the stream had multiple file outputs,
they would have been accessible separately as
and so on.
output is a simple short-cut referring to the first of them.
When the compile-time configuration doesn't specify a default file name for a particular file output, Chronicles will use the following rules for picking the default automatically:
The log file is created in the current working directory and its name matches the name of the stream (plus a
.logextension). The exception for this rule is the default stream, for which the log file will be assigned the name of the application binary.
If more than one unnamed file outputs exist for a given stream, chronicles will add an index such as
.N.logto the final file name.
Teaching Chronicles about your types
Chronicles can output log records in any of the formats supported by the Nim
When you specify a named format such as
json, Chronicles will expect that
your project also depends on the respective serialization package (e.g.
In the text formats (
textblocks), the Nim's standard
operator will be used to convert the logged properties to strings.
You can instruct Chronicles to alter this default behavior for a particular
type by providing a
type Dollar = distinct int chronicles.formatIt(Dollar): "$" & $(it.int)
formatIt block can evaluate to any expression that will be then
subjected to the standard serialization logic described above.
expandIt override can be used to turn any logged property of a
particular type into multiple properties:
chronicles.expandIt(EncryptedEnvelope): peer = it.fromAddress msg = it.decryptMsg ... var e = EncryptedEnvelope(...) # The following two statements are equivalent: info "Received message", e info "Received message", peer = e.fromAddress, msg = e.decryptMsg
You can also derive the names of the expanded properties from the name of the original logged property. This is achieved by using the Nim's backticks syntax to construct the expanded property names:
chronicles.expandIt(User): # You can use both identifiers and string literals: `it Name` = it.name `it "LastSeen"` = it.lastSeen ... var alice = User(name: "Alice", ...) # The following two statements are equivalent: info "Sending message", recipient = alice info "Sending message", recipientName = alice.name, recipientLastSeen = alice.lastSeen
Custom Log 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
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
After importing the proxy module, you'll be able to create records with any of the logging statements in the usual way:
import transactions_log ... transactions.error "payment gateway time-out", orderId, networkStatus = obtainNetworkStatus()
customLogStream enables you to implement arbitrary log formats and
Each logging statement is translated to a set of calls operating over a structure called "Log Record" (with one instance created per logging statement). New log formats can be implemented by defining a suitable log record type. Let's demonstrate this by implementing a simple XML logger:
import xmltree, chronicles type XmlRecord[Output] = object output: Output template initLogRecord*(r: var XmlRecord, lvl: LogLevel, topics: string, name: string) = r.output.append "<event name=\"", escape(name), "\" severity=\"", $lvl, "\">\n" template setProperty*(r: var XmlRecord, key: string, val: auto) = r.output.append textBlockIndent, "<", key, ">", escape($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 xmlout[XmlRecord[StdOutOutput]] publicLogScope: stream = xmlout info "New Video", franchise = "Tom & Jerry", episode = "Smarty Cat"
The produced output from the example will be:
<event name="New Video" severity="INFO"> <tid>0</tid> <episode>Smarty Cat</episode> <franchise>Tom & Jerry</franchise> </event>
As you can see,
customLogStream looks similar to a regular
but it expects a log record type as its only argument.
The record type is implemented by providing suitable definitons for
We recommend defining these operations as templates because this will
facilitate the aggressive constant-folding employed by Chronicles (discussed
in more details in the next section). We also recommend making your log
record types parametric on an
Output type, because this will allow the
users of the code to specify any of the output types defined in Chronicles
itself (see the module
log_output for a list of those).
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.
Cost of Abstractions and Implementation Details
Chronicles makes use of advanced compile-time programming techniques to produce very efficient run-time code with minimal footprint.
The properties from lexical scopes are merged at compile-time with the
log statement arguments and if any constant variables are about to be
sent to the log output, they will be first concatenated by the compiler
in order to issue the minimum number of
write operations possible.
The dynamic scopes store their run-time bindings on the stack, in special frame structures forming a linked list. This list is traversed on each log statement and each active property leads to one dynamically dispatched call.
To support constant-time topic filtering and property overriding in dynamic scopes, Chronicles consumes a large amount of thread-local memory, roughly proportional to the number of unique topic names and property names used in the program.
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
and sending your log output to
stdout. It should be the responsibility
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.