log4net RollingFileAppender stops working after deployment

Question

My aps.net core application is running fine and generating logs and rolling them each day, however as soon I deploy a new version of the app to IIS it stops logging and also stops rolling. It only starts again if I rename the current log file to something different. But then it works as expected again.

The deployment involves stopping the app by creating a app_offline.htm file in the apps root folder.

The app runs on dot.net core 2.2.8 and the log4net version is 2.0.10.

This is the condig for my RollingFileAppender

<appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
    <file value="<some absolute path>\Log.txt"/>
    <appendToFile value="true" />
    <staticLogFileName value="true" />
    <rollingStyle value="Date" />
    <datePattern value=" yyyy-MM-dd" />

    <threshold value="All" />
    <layout type="log4net.Layout.PatternLayout">
        <!--<conversionPattern value="%date [%thread] %-5level %logger  - %message%newline" />-->
        <conversionPattern value="%property{log4net:HostName} %date [%thread] %-5level %logger - %message%newline%exception" />
    </layout>
</appender>

Any idea what might cause this behavior?

Windows logs:

In the windows logs I can find this error (but not always):

IISMANAGER_CRASH

IIS Manager terminated unexpectedly.

Exception:System.Runtime.Remoting.RemotingException: Cannot call disconnect on a proxy.
   at System.Runtime.Remoting.RemotingServices.Disconnect(MarshalByRefObject obj, Boolean bResetURI)
   at System.Web.Hosting.ApplicationManager.HostingEnvironmentShutdownComplete(String appId, IApplicationHost appHost)
   at System.Web.Hosting.ApplicationManager.HostingEnvironmentShutdownComplete(String appId, IApplicationHost appHost)
   at System.Web.Hosting.HostingEnvironment.OnAppDomainUnload(Object unusedObject, EventArgs unusedEventArgs)

Process:InetMgr

I also noticed that a different application gets shutdown due to the deployment because it has the same physical root. Could this be the problem? Should I add a delay between shutting down the app (via creating app_offline.htm) and the deployment?

The part with the second app is also a difference to the development deployment (which does not have the problem).

Answer 1

The problem was the second app that has the same physical address. Since it uses the same root folder it also uses the same log4net-config. This means that two processes want to log to the same file. Here comes the LockingModel from FileAppender into focus.

As the docs state

The default locking model is the FileAppender.ExclusiveLock.

And the docs for FileAppender.ExclusiveLock states

Open the file once for writing and hold it open until CloseFile() is called. Maintains an exclusive lock on the file during this time.

which causes two processes too fight over an exclusive look over the same file (and I would expect that if one process has the file opend it will only close it if the process ended (i.e. if IIS recycles it)).

The solution is to use the FileAppender.InterProcessLock which provides cross-process file locking.

To use it we just add this xml code to the appenders configuration:

<lockingModel type="log4net.Appender.FileAppender+InterProcessLock" />