Logging Configuration File
The logging can be customized by providing a configuration file to NLog, e.g. by creating an "nlog.config" file in the same folder as where the executable resides.
This article describes the actionETL specific aspects of logging, and some of the more common logging settings; please also see the NLog configuration, troubleshooting, and overall wiki, which documents its extensive capabilities.
This nlog.config file would replicate the default logging settings, and is described below, together with some optional settings.
<nlog>
This tag controls NLog internal logging, which is useful for troubleshooting NLog itself if logging is not working as expected, e.g. due to configuration errors. In particular:
throwExceptions
controls whether NLog should throw exceptions when there is a logging issue. It is good practice to set this totrue
in Dev and Test environments; consider what the appropriate setting is for production - is it more important to know how the application ran (true
), or is it more important to complete execution even if the logs won't be complete (false
).internalLogLevel
defaults to warnings and above - increase NLog internal logging toInfo
orDebug
when troubleshooting NLog issues
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://www.nlog-project.org/schemas/NLog.xsd NLog.xsd"
autoReload="false"
throwExceptions="true"
internalLogFile="nlog-internal.log"
internalLogLevel="Warn"
internalLogToConsole="true"
>
<extensions>
actionETL adds two extensions to NLog.
<extensions>
<add assembly="actionETL" />
</extensions>
${currenttaskid}
Specifying ${currenttaskid}
in a layout outputs the Task.CurrentId
value
(if available) of the logging call. This can be used together with the
${threadid}
layout
to trace how threads and tasks are used, e.g. when developing a new worker
that internally runs multiple threads, but is otherwise rarely needed.
Important
Avoid using the default BufferingWrapper
asynchronous logging target
together with the ${threadid}
layout, since that logs the wrong thread id.
Instead use a synchronous logging target, e.g. the File
target, while
troubleshooting with the ${threadid}
layout.
ThrottleTargetWrapper
An optional wrapper target that aggregates similar consecutive log messages, which can be
useful when enabling Debug
or Trace
logging with high volume data.
The aggregation only applies to messages that have the same:
Log level, Locator, Category, ThreadId (if present), and Message.
Syntax:
<target name="ToFile" xsi:type="ThrottleTargetWrapper" TimeoutSeconds="5" MaxThrottled="10000">
... insert actual target here ...
</target>
Where:
TimeoutSeconds
- Maximum time before outputting currently aggregated messagesMaxThrottled
- Maximum number of aggregated messages before outputting them
<variable>
and Layouts
Declaring variables simplifies using the same layout with multiple targets.
Layouts define what to output to the logging targets, and the formatting of this output.
In particular:
${logger}
- The logger name, which is normally populated by aLocator
string, e.g. Locator. This makes it easy to adjust logging for whole sub trees of the worker hierarchy, see <rules> below.${event-properties:item=Category}
- Category is a string that classifies log messages, see Logging Messages
<variable name="header-layout"
value="DateTime | Level | Locator | Category | Message"/>
<variable name="file-body-layout-stacktrace"
value="${longdate} | ${level:uppercase=true} | ${logger} | ${event-properties:item=Category} | ${message}${onexception:${literal:text= }EXCEPTION OCCURRED\: ${exception:format=tostring,data,method:maxInnerExceptionLevel=10:innerFormat=tostring,data,method:maxInnerExceptionLevel=10}}"/>
<variable name="console-body-layout"
value="${longdate} | ${level:uppercase=true} | ${logger} | ${event-properties:item=Category} | ${message}${onexception:${literal:text= }EXCEPTION OCCURRED\: ${exception:format=type,message,data,method:maxInnerExceptionLevel=10:innerFormat=shorttype,message,data,method:maxInnerExceptionLevel=10}}"/>
<targets>
Targets define the available logging destinations, and are controlled via attributes:
name
- The target name, used by<rules>
xsi:type
- specifies which one of the many available targets is usedlayout
- Controls what to output, and its formatting
Most targets will also have their own target specific attributes to control how they work.
This example logs to a "File" target, wrapped in a "BufferingWrapper" target for improved performance. It also logs to the "ColoredConsole" target.
<targets>
<target name="ToFile" xsi:type="BufferingWrapper" bufferSize="100" flushTimeout="1000"
slidingTimeout="false">
<target xsi:type="File" fileName="${processname}.log" deleteOldFileOnStartup="true"
header="${var:header-layout}"
layout="${var:file-body-layout-stacktrace}"/>
</target>
<target name="ToConsole" xsi:type="ColoredConsole" header="${var:header-layout}"
layout="${var:console-body-layout}"/>
</targets>
<rules>
The rules section controls which log messages get sent to one or more targets, or get discarded.
Each <logger>
routes log messages from log sources to targets:
name
- Specifies which logger names (i.e. the worker and worker system Locator as well as input and output and error outputLocator
strings) should be included. It supports*
wild-cards, but only at the start and end, not in the middle of theLocator
name. Some examples:"*"
- All loggers"*Sales*"
- Only affect workers and ports with "Sales" somewhere in theirLocator
"*.Inputs[*"
- Only affect all input ports. You can replace "Inputs" with "Outputs" or "ErrorOutputs" to instead affect those ports."/Root/Extracts/Sales*"
- Only affect workers and ports beginning with "/Root/Extracts/Sales", including any descendant workers"/Root/Extracts/Sales/*"
- Only affect workers and ports that are descendants of the "/Root/Extracts/Sales" worker"/Root/Extracts/Sales"
- Only affect the "/Root/Extracts/Sales" worker, but not its ports"/Root/Extracts/Sales.*"
- Only affect the ports of the "/Root/Extracts/Sales" worker"/Root/Extracts/Sales.Inputs*"
- Only affect the input ports of the "/Root/Extracts/Sales" worker. You can replace "Inputs" with "Outputs" or "ErrorOutputs" to instead affect those ports."/Root/Extracts/Sales.Inputs[LeftInput]"
- Only affect the "LeftInput" input port of the "/Root/Extracts/Sales" worker. You can replace "Inputs" with "Outputs" or "ErrorOutputs" to instead affect those ports."/UniqueName*"
- Only affect worker system named "UniqueName", useful when multiple worker systems use the same configuration
minlevel
- Minimal log level for this rule to matchmaxlevel
- Maximum log level for this rule to matchlevel
- Single log level for this rule to matchlevels
- Comma separated list of log levels for this rule to matchwriteTo
- Comma separated list of targets that should be written to when this rule matchesfinal
- Make this rule final. Rules are processed sequentially in the order they appear in the configuration file. No further rules are processed when any final rule matches.enabled
- Setting enabled to false disables this rule. Disabled rules are ignored.
<filters>
allow including or excluding log messages based on expressions, and are more flexible
(but have a higher overhead) than the above name
and wild-card filtering. You can also combine
name
and - <filters>
in the same rule. See
filtering for more details.
Examples rules:
<rules>
<!-- Log "Info" and higher events from all loggers to the "ToFile" target -->
<logger name="*" minlevel="Info" writeTo="ToFile" />
<!-- Log "Info" and higher events from all loggers to the "ToConsole" target,
except "Info" events where the "Category" does not start with 'System.' -->
<logger name="*" minlevel="Info" writeTo="ToConsole">
<filters>
<when condition="level == LogLevel.Info and not starts-with('${event-properties:item=Category}','System.')"
action="Ignore" />
</filters>
</logger>
<!-- Log "Debug" and "Trace" events from all descendants of "/Root/Extracts/Sales" to
the "ToFile" target. Marked as "final" to avoid double logging with later rules. -->
<logger name="/Root/Extracts/Sales/*" levels="Debug,Trace" writeTo="ToFile" final="true" />
<!-- Log "Debug" events from all input ports to the "ToFile" target.
Marked as "final" to avoid double logging with later rules. -->
<logger name="*.Inputs[*" level="Debug" writeTo="ToFile" final="true" />
<!-- Log "Debug" events from "/Root/Extracts/Budget*" and descendants to the
"ToFile" target, except if the logger (i.e. Locator) contains 'Metadata'. -->
<logger name="/Root/Extracts/Budget*" level="Debug" writeTo="ToFile">
<filters>
<when condition="contains('${logger}','Metadata')" action="Ignore" />
</filters>
</logger>
</rules>
<time>
By default, log message timestamps have an accuracy of about 16 milliseconds. This means consecutive log messages might have the same timestamp even though they occurred up to 16 milliseconds apart. This is in most cases perfectly adequate; the accuracy can however be increased to 1 millisecond, which can be useful when comparing order of events logged by different workers.
The default timestamps use local time, this can be changed to UTC.
Please see NLog Time Source for how
to configure the <time>
tag, and the trade-offs involved.
Note
Irrespective of the <time>
configuration, the UTC time is always logged at the start, with
category "System.Environment".