CachedLayoutRenderWrapper missing AmbientProperty attribute

[Quergo]

Class CachedLayoutRendererWrapper has a missing AmbientProperty attribute for property 'ClearCache'. In consequence the value of parameter 'ClearCache' in a config file is never applied to this property because parameter is not parsed.

[304NotModified]

Thanks for this report.

I'm not sure if AmbientProperty is needed there. AFAIK all public properties are parsed? See

NLog/tests/NLog.UnitTests/LayoutRenderers/Wrappers/CachedTests.cs

Line 66 in 67ce7be

l = "${cached:${guid}:cached=true:clearcache=none}";

[Quergo]

Config parameter is parsed but it seems that it is never assigned to the CachedLayoutRendererWrappers property.

My config entry for the file target:

 <target name="default_logfile"
            xsi:type="File"
            fileName="C:\somePath\${date:cached=True:clearCache=None:format=yyyy-MM-dd_HH-mm-ss}_Log.txt"
            layout="|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}" />

In

NLog/src/NLog/Layouts/LayoutParser.cs

Line 335 in 67ce7be

if (configurationItemFactory.AmbientProperties.TryGetDefinition(parameterName, out wrapperType))

there is a lookup to get the corresponding WrapperType for an AmbientProperty.

When AmbientProperty is missing the setter is just called once to assign default value in the constructor. When I add the AmbientProperty , ClearCache value is correctly set. It is set one time to the default value defined in constructor and second time to the value from config file.

Note: I also changed the fileName attribute of my FileTarget in a way that it corresponds to the test you have linked.

 <target name="default_logfile"
            xsi:type="File"
            fileName="C:\somePath\{cached:${date}:cached=True:clearCache=None:format=yyyy-MM-dd_HH-mm-ss}_Log.txt"
            layout="|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}" />

This resulted in assigning the ClearCache value correctly. But now its cutting of year and month from the log file name and uses them to extend the path. So I get C:\somePath\year\month\trimmedDate_Log.txt instead of C:\somePath\Date_Log.txt

[Quergo]

Found my fault:

Changed

fileName="C:\somePath{cached:${date}:cached=True:clearCache=None:format=yyyy-MM-dd_HH-mm-ss}_Log.txt"

to

fileName="C:\somePath${cached:${date:format=yyyy-MM-dd_HH-mm-ss}:cached=True:clearCache=None}_Log.txt"

I think https://github.com/NLog/NLog/wiki/Cached-Layout-Renderer should mention this in some way.

[304NotModified]

Thanks for the examples!

Which NLog version is this? Did you checked the internal log for the first case?

[304NotModified]

@Quergo can you give us some more info?

[Quergo]

I'm on vacation until 14th of Jan. Will provide more info when I am back.

[304NotModified]

Thanks for the feedback and have a nice vacation!

[Quergo]

So, I have new info:

All I did was following documentation under https://github.com/nlog/nlog/wiki/Cached-Layout-Renderer . The logfile snippets I posted cover just the initialization part of NLog.

My original FileTarget was:

    <target name="default_logfile"
            xsi:type="File"
            fileName="C:\Log\${date:cached=True:format=yyyy-MM-dd_HH-mm-ss}_Log.txt"
            layout="|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}" />

This works correctly until I reconfigure LogConfiguration at runtime which triggers an update of the cached value.

Internal Logfile:

2016-01-11 15:14:28.3808 Debug ScanAssembly('NLog, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null')
2016-01-11 15:14:28.4198 Debug Start auto loading, location: C:\Workspace\bin\Debug
2016-01-11 15:14:28.4198 Debug Auto loading done
2016-01-11 15:14:28.4378 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:14:28.4478 Debug Setting 'FileTarget.name' to 'default_logfile'
2016-01-11 15:14:28.4478 Debug Setting 'FileTarget.fileName' to 'C:\Log\${date:cached=True:format=yyyy-MM-dd_HH-mm-ss}_Log.txt'
2016-01-11 15:14:28.4478 Debug Setting 'CachedLayoutRendererWrapper.cached' to 'True'
2016-01-11 15:14:28.4478 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd_HH-mm-ss'
2016-01-11 15:14:28.4478 Debug Setting 'FileTarget.layout' to '|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}'
2016-01-11 15:14:28.4478 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:14:28.4478 Debug Setting 'LoggerNameLayoutRenderer.shortName' to 'true'
2016-01-11 15:14:28.4478 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd HH:mm:ss'
2016-01-11 15:14:28.4618 Debug Setting 'ExceptionLayoutRenderer.format' to 'tostring, stacktrace'
2016-01-11 15:14:28.4618 Debug Setting 'ExceptionLayoutRenderer.separator' to '*'
2016-01-11 15:14:28.4618 Info Adding target File Target[default_logfile]
2016-01-11 15:14:28.4618 Debug Registering target default_logfile: NLog.Targets.FileTarget
2016-01-11 15:14:28.4618 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:14:28.4618 Debug Setting 'DebuggerTarget.name' to 'default_debugger'
2016-01-11 15:14:28.4618 Debug Setting 'DebuggerTarget.layout' to '|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}'
2016-01-11 15:14:28.4618 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:14:28.4618 Debug Setting 'LoggerNameLayoutRenderer.shortName' to 'true'
2016-01-11 15:14:28.4618 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd HH:mm:ss'
2016-01-11 15:14:28.4778 Debug Setting 'ExceptionLayoutRenderer.format' to 'tostring, stacktrace'
2016-01-11 15:14:28.4778 Debug Setting 'ExceptionLayoutRenderer.separator' to '*'
2016-01-11 15:14:28.4778 Info Adding target Debugger Target[default_debugger]
2016-01-11 15:14:28.4778 Debug Registering target default_debugger: NLog.Targets.DebuggerTarget
2016-01-11 15:14:28.4778 Info Configured from an XML element in C:\Workspace\bin\Debug\NLog.config...
2016-01-11 15:14:28.4778 Debug --- NLog configuration dump ---
2016-01-11 15:14:28.4778 Debug Targets:
2016-01-11 15:14:28.4928 Debug File Target[default_logfile]
2016-01-11 15:14:28.4928 Debug Debugger Target[default_debugger]
2016-01-11 15:14:28.4928 Debug Rules:
2016-01-11 15:14:28.4928 Debug logNamePattern: (:All) levels: [ ] appendTo: [ default_logfile ]
2016-01-11 15:14:28.4928 Debug logNamePattern: (:All) levels: [ ] appendTo: [ default_debugger ]
2016-01-11 15:14:28.4928 Debug --- End of NLog configuration dump ---
2016-01-11 15:14:28.4928 Info Found 36 configuration items
2016-01-11 15:14:28.5128 Info Configuration initialized.

To avoid cache reset I tried to use FileTarget with clearCache=None :

  <target name="default_logfile"
            xsi:type="File"
            fileName="C:\Log\${date:cached=True:clearCache=None:format=yyyy-MM-dd_HH-mm-ss}_Log.txt"
            layout="|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}" />

Unfortunately this does not work as it still triggers an update of the cached value. In the following logfile section on can see that the clearCache value is never set when NLog initializes and will stay on it's default value (OnInit,OnClose).

Internal Logfile:

2016-01-11 15:03:01.0014 Debug ScanAssembly('NLog, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null')
2016-01-11 15:03:01.0395 Debug Start auto loading, location: C:\Workspace\bin\Debug
2016-01-11 15:03:01.0395 Debug Auto loading done
2016-01-11 15:03:01.0575 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:03:01.0575 Debug Setting 'FileTarget.name' to 'default_logfile'
2016-01-11 15:03:01.0575 Debug Setting 'FileTarget.fileName' to 'C:\Log\${date:cached=True:clearCache=None:format=yyyy-MM-dd_HH-mm-ss}_Log.txt'
2016-01-11 15:03:01.0705 Debug Setting 'CachedLayoutRendererWrapper.cached' to 'True'
2016-01-11 15:03:01.0705 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd_HH-mm-ss'
2016-01-11 15:03:01.0705 Debug Setting 'FileTarget.layout' to '|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}'
2016-01-11 15:03:01.0705 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:03:01.0705 Debug Setting 'LoggerNameLayoutRenderer.shortName' to 'true'
2016-01-11 15:03:01.0705 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd HH:mm:ss'
2016-01-11 15:03:01.0705 Debug Setting 'ExceptionLayoutRenderer.format' to 'tostring, stacktrace'
2016-01-11 15:03:01.0705 Debug Setting 'ExceptionLayoutRenderer.separator' to '*'
2016-01-11 15:03:01.0705 Info Adding target File Target[default_logfile]
2016-01-11 15:03:01.0865 Debug Registering target default_logfile: NLog.Targets.FileTarget
2016-01-11 15:03:01.0865 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:03:01.0865 Debug Setting 'DebuggerTarget.name' to 'default_debugger'
2016-01-11 15:03:01.0865 Debug Setting 'DebuggerTarget.layout' to '|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}'
2016-01-11 15:03:01.0865 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:03:01.0865 Debug Setting 'LoggerNameLayoutRenderer.shortName' to 'true'
2016-01-11 15:03:01.0865 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd HH:mm:ss'
2016-01-11 15:03:01.0865 Debug Setting 'ExceptionLayoutRenderer.format' to 'tostring, stacktrace'
2016-01-11 15:03:01.0865 Debug Setting 'ExceptionLayoutRenderer.separator' to '*'
2016-01-11 15:03:01.0865 Info Adding target Debugger Target[default_debugger]
2016-01-11 15:03:01.1015 Debug Registering target default_debugger: NLog.Targets.DebuggerTarget
2016-01-11 15:03:01.1015 Info Configured from an XML element in C:\Workspace\bin\Debug\NLog.config...
2016-01-11 15:03:01.1015 Debug --- NLog configuration dump ---
2016-01-11 15:03:01.1015 Debug Targets:
2016-01-11 15:03:01.1015 Debug File Target[default_logfile]
2016-01-11 15:03:01.1015 Debug Debugger Target[default_debugger]
2016-01-11 15:03:01.1015 Debug Rules:
2016-01-11 15:03:01.1175 Debug logNamePattern: (:All) levels: [ ] appendTo: [ default_logfile ]
2016-01-11 15:03:01.1175 Debug logNamePattern: (:All) levels: [ ] appendTo: [ default_debugger ]
2016-01-11 15:03:01.1175 Debug --- End of NLog configuration dump ---
2016-01-11 15:03:01.1175 Info Found 36 configuration items
2016-01-11 15:03:01.1175 Info Configuration initialized.

My solution was to add [AmbientProperty("ClearCache")] to CachedLayoutRendererWrapper class and everything works correctly. The following log shows that clearCache is now assigned a value of None.

Internal Logfile:

2016-01-11 15:23:19.8505 Debug ScanAssembly('NLog, Version=0.0.0.0, Culture=neutral, PublicKeyToken=null')
2016-01-11 15:23:19.8885 Debug Start auto loading, location: C:\Workspace\bin\Debug
2016-01-11 15:23:19.8885 Debug Auto loading done
2016-01-11 15:23:19.9075 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:23:19.9165 Debug Setting 'FileTarget.name' to 'default_logfile'
2016-01-11 15:23:19.9165 Debug Setting 'FileTarget.fileName' to 'C:\Log\${date:cached=True:clearCache=None:format=yyyy-MM-dd_HH-mm-ss}_Log.txt'
2016-01-11 15:23:19.9165 Debug Setting 'CachedLayoutRendererWrapper.cached' to 'True'
2016-01-11 15:23:19.9165 Debug Setting 'CachedLayoutRendererWrapper.clearCache' to 'None'
2016-01-11 15:23:19.9165 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd_HH-mm-ss'
2016-01-11 15:23:19.9165 Debug Setting 'FileTarget.layout' to '|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}'
2016-01-11 15:23:19.9165 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:23:19.9165 Debug Setting 'LoggerNameLayoutRenderer.shortName' to 'true'
2016-01-11 15:23:19.9305 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd HH:mm:ss'
2016-01-11 15:23:19.9305 Debug Setting 'ExceptionLayoutRenderer.format' to 'tostring, stacktrace'
2016-01-11 15:23:19.9305 Debug Setting 'ExceptionLayoutRenderer.separator' to '*'
2016-01-11 15:23:19.9305 Info Adding target File Target[default_logfile]
2016-01-11 15:23:19.9305 Debug Registering target default_logfile: NLog.Targets.FileTarget
2016-01-11 15:23:19.9305 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:23:19.9305 Debug Setting 'DebuggerTarget.name' to 'default_debugger'
2016-01-11 15:23:19.9305 Debug Setting 'DebuggerTarget.layout' to '|${level:uppercase=true} @ ${logger:shortName=true}|:${date:format=yyyy-MM-dd HH\:mm\:ss} ${message} ${exception:format=tostring, stacktrace:separator=*}'
2016-01-11 15:23:19.9305 Debug Setting 'UppercaseLayoutRendererWrapper.uppercase' to 'true'
2016-01-11 15:23:19.9465 Debug Setting 'LoggerNameLayoutRenderer.shortName' to 'true'
2016-01-11 15:23:19.9465 Debug Setting 'DateLayoutRenderer.format' to 'yyyy-MM-dd HH:mm:ss'
2016-01-11 15:23:19.9465 Debug Setting 'ExceptionLayoutRenderer.format' to 'tostring, stacktrace'
2016-01-11 15:23:19.9465 Debug Setting 'ExceptionLayoutRenderer.separator' to '*'
2016-01-11 15:23:19.9465 Info Adding target Debugger Target[default_debugger]
2016-01-11 15:23:19.9465 Debug Registering target default_debugger: NLog.Targets.DebuggerTarget
2016-01-11 15:23:19.9465 Info Configured from an XML element in C:\Workspace\bin\Debug\NLog.config...
2016-01-11 15:23:19.9616 Debug --- NLog configuration dump ---
2016-01-11 15:23:19.9616 Debug Targets:
2016-01-11 15:23:19.9616 Debug File Target[default_logfile]
2016-01-11 15:23:19.9616 Debug Debugger Target[default_debugger]
2016-01-11 15:23:19.9616 Debug Rules:
2016-01-11 15:23:19.9616 Debug logNamePattern: (:All) levels: [ ] appendTo: [ default_logfile ]
2016-01-11 15:23:19.9616 Debug logNamePattern: (:All) levels: [ ] appendTo: [ default_debugger ]
2016-01-11 15:23:19.9616 Debug --- End of NLog configuration dump ---
2016-01-11 15:23:19.9776 Info Found 36 configuration items
2016-01-11 15:23:19.9776 Info Configuration initialized.

In a previous post I also mentioned an other solution which does not use AmbientProperty to solve this issue.

fileName="C:\somePath\${cached:${date:format=yyyy-MM-dd_HH-mm-ss}:cached=True:clearCache=None}_Log.txt"

But this is not like it is stated in the docs. Docs explicitly name the use of AmbientProperty which seems not to be supported for clearCache parameter.

[304NotModified]

Thanks for all the info!

This is fixed in NLog 4.3 :)