NLog 4.3.8 onward writing logs to wrong folder with custom app domain

[Tommyknocker1982]

Type - Bug

NLog version - 4.3.8

Platform: - .Net 4.5

Current NLog config (xml or C#, if relevant)

  <nlog autoReload="true" xmlns="http://www.nlog-project.org/schemas/NLog.xsd" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
    <variable name="layout" value="${longdate:universalTime=true}|${level:uppercase=true}|${threadid}|${logger}|${message}" />
    <targets async="true">
      <target name="debugger" xsi:type="Debugger" layout="${layout}" />
      <target name="logfile" xsi:type="File" fileName="logs\app.log" archiveFileName="logs\app.{###}.log" archiveEvery="Day" archiveAboveSize="1024000" archiveNumbering="Rolling" maxArchiveFiles="10" concurrentWrites="false" keepFileOpen="false" layout="${layout}" />
    </targets>
    <rules>
      <logger name="*" minlevel="Info" writeTo="logfile" />
      <logger name="*" minlevel="Debug" writeTo="debugger" />
    </rules>
  </nlog>

Hi

We recently upgraded from NLog 4.3.3 to 4.3.11, and noticed that the logs for our application started to be written to the wrong folder. I narrowed it down to a change introduced in 4.3.8. The structure of our application is:

AppFolder
  \ Bin
    app.exe
  bootstrapper.exe
  \ Logs

bootstrapper.exe is run first, with a working directory of AppFolder. It creates an app domain, into which it loads and runs Bin\app.exe. app.exe is configured to write logs to Logs\app.log. Up to and including NLog 4.3.7, it would correctly pick up the working directory of the bootstrapper.exe process and write logs fo AppFolder\Logs\app.log. But from NLog 4.3.8, it started writing logs to AppFolder\Bin\Logs\app.log. It seems that instead of using the working directory, it is using the location of the executable which is being loaded and run dynamically at runtime.

I couldn't find anything in the 4.3.8 release notes which suggests this change was intended, so if it is a bug, can it be fixed or reverted?

Thanks very much,

Graham Stoneman.

[304NotModified]

Could you post your config? Especially of the fileTarget?

[Tommyknocker1982]

Hi,

I'd included it but had forgotten to enclose it in markup so it was hidden. I've fixed the post now, sorry about that!

Thanks,

Graham.

[304NotModified]

Thx!

[304NotModified]

summary:

setting: fileName="logs\app.log"
3.4.7: AppFolder\Logs\app.log (correct)
4.3.8: AppFolder\Bin\Logs\app.log (wrong)

changes 4.3.8: https://github.com/NLog/NLog/pulls?utf8=%E2%9C%93&q=%20is%3Aclosed%20milestone%3A4.3.8%20

[snakefoot]

Committed changes 4.3.7 -> 4.3.8:

v4.3.7...v4.3.8

[304NotModified]

I expect that the issue is in filepathlayout

Previous Path.GetFullPath was used, and since 4.3.8 AppDomain.CurrentDomain.BaseDirectory

Dunno why the unit tests won't complain.

@Tommyknocker1982 any idea if "${basedir}\logs\app.log" works?

[304NotModified]

I think this goed wrong with only when app domains are created.

@Tommyknocker1982 could you help us in writing an unit test? Probable we don't even have to write to a file in the unit test, but test this

//create app domain, set basepath?

           var layout = new FilePathLayout("logs\\app.log", true,FilePathKind.Unknown);
            var filename = layout.Render(LogEventInfo.CreateNullEvent());
            Assert.Equal(..., filename);

Dunno how the app domain code would look like - I haven't much experience with it ;)

[Tommyknocker1982]

Hi,

Having looked at that change in 4.3.8, I think that most users would expect it to use the base directory of the current app domain by default. So instead of reverting the behaviour, would it be possible to add a new token ${processdir} which resolves to the directory of the parent process? This would let us have the old behaviour by specifying "${processdir}\logs\app.log" in our config, and is consistent with existing tokens like ${processinfo} etc...

[snakefoot]

So something like this:

string appFilePath = System.Diagnostics.Process.GetCurrentProcess().MainModule.FileName;
string appBaseDir = System.IO.Path.GetDirectoryName(appFilePath);

Maybe it could just be an option on the BaseDirLayoutRenderer, whether it should use AppDomain-BaseDir or CurrentProcess-BaseDir.

[Tommyknocker1982]

Yes, that would work. Could that please be added to NLog 4.4? Thanks very much, Graham.

[304NotModified]

Having looked at that change in 4.3.8, I think that most users would expect it to use the base directory of the current app domain by default.

yes a/b should be equals to ${basedir}/a/b IMO.

But I really like to know, is this a bug? Is path.getfullname using the "processdir"? In which case is this not a problem?

Maybe it could just be an option on the BaseDirLayoutRenderer, whether it should use AppDomain-BaseDir or CurrentProcess-BaseDir.

Good idea!

[Tommyknocker1982]

Hi, no I think that if anything a bug was present up to 4.3.7 and fixed in 4.3.8. I've managed to get the old behaviour back by writing a custom layout renderer, so we don't require any changes to NLog now. Thanks to everybody who helped investigate the issue, you've been brilliant! This issue can be marked as closed now. Cheers, Graham.

[304NotModified]

@Tommyknocker1982 I still like to add this :)

Do you have time to send a PR with this proposal? (including some tests)?

option on the BaseDirLayoutRenderer, whether it should use AppDomain-BaseDir or CurrentProcess-BaseDir.

[304NotModified]

how could we test this in an unit test?

[snakefoot]

how could we test this in an unit test?

Guess you could create a normal AppDomain (instead of a Medium-Trust-One) with a custom basedir, and see the file is written in the test-runner-bin-folder (Like where DoConcurrentTest is currently writing).

[304NotModified]

thanks @snakefoot !

I will give it a try