Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

log4net not logging in worker threads with MinimalLock model

I have a rater "interesting" problem, where log4net doesn't write the log messages if they come from inside a worker thread in ASP.NET MVC. This seems to only be an issue when I've added <lockingModel type="log4net.Appender.FileAppender+MinimalLock" /> to my log4net configuration and when the website is running on my server (IIS 8.0). On my own computer log4net logs the messages just fine - even with the MinimalLock configuration and if I remove this 'MinimalLock' it will log messages in worker threads on the server as well.

Here is an example:

public class MvcApplication : System.Web.HttpApplication
{
    private static readonly log4net.ILog log = log4net.LogManager.GetLogger(
        System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);


    protected void Application_Start()
    {

        // This is logged just fine - with or without MinimalLock, 
        // both local and on server
        log.Info("Logging ouside worker!");

        // This is only logged without MinimalLock configured 
        // if the site is hosted on my server runnning IIS 8.0.
        var thread = new Thread(() => log.Info("Logging inside worker!"));
        thread.Start();
    }

}

and here is my log4net configuration:

<log4net>
  <root>
    <level value="ALL" />
    <appender-ref ref="LogFileAppender" />
  </root>
  <appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender">
    <file value="App_Data\log.log" />
    <appendToFile value="true" />
    <rollingStyle value="Size" />
    <maxSizeRollBackups value="10" />
    <maximumFileSize value="10MB" />
    <staticLogFileName value="true" />
    <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date [%thread] %level %logger - %message%newline" />
    </layout>
  </appender>
</log4net>

Without the MinimalLock lockingModel configured, I'm unable to read the log file on the server, so removing it isn't really an option. I'm also unable to avoid logging inside of worker threads, as I need to log potential errors inside of the workers spawned by Quartz.net.

I suspect it is an issue of permissions on the server, but I have very limited access to the server, as I'm not the administrator (I basically only have FTP access - they won't even grant me external access to the MSSQL DB).

Here's the question

If my suspicion is correct, what changes should I request from my server administrator in order to fix the problem? Which permissions should be granted to which user, in order for MinimalLock to work properly in my hosted environment?

If it is not an issue with permissions, what could it be instead?

Any help is much appreciated. Thanks in advance.

Update:

After enabling the debug log for log4net, I found the following errors when I run the example code above (full path omitted):

log4net:ERROR [RollingFileAppender] Unable to acquire lock on file App_Data\log.log. Access to the path 'App_Data\log.log' is denied.
log4net:ERROR [RollingFileAppender] Unable to acquire lock on file App_Data\log.log. Access to the path 'App_Data\log.log' is denied.
log4net:ERROR [RollingFileAppender] Unable to acquire lock on file App_Data\log.log. Access to the path 'App_Data\log.log' is denied.
log4net: ConfigureAndWatchHandler: Changed [web.config]
log4net: ConfigureAndWatchHandler: Changed [web.config]
log4net: Hierarchy: Shutdown called on Hierarchy [log4net-default-repository]
log4net:ERROR [RollingFileAppender] Unable to acquire lock on file App_Data\log.log. Access to the path 'App_Data\log.log' is denied.
log4net:ERROR [RollingFileAppender] Could not close writer [log4net.Util.CountingQuietTextWriter]
log4net.Appender.FileAppender+LockingStream+LockStateException: The file is not currently locked
   at log4net.Appender.FileAppender.LockingStream.AssertLocked()
   at log4net.Appender.FileAppender.LockingStream.Flush()
   at System.IO.StreamWriter.Flush(Boolean flushStream, Boolean flushEncoder)
   at System.IO.StreamWriter.Dispose(Boolean disposing)
   at System.IO.StreamWriter.Close()
   at log4net.Util.QuietTextWriter.Close()
   at log4net.Appender.TextWriterAppender.CloseWriter()

These only occur on the server.

like image 947
Nikolaj Dam Larsen Avatar asked Dec 15 '14 21:12

Nikolaj Dam Larsen


1 Answers

I managed to solve the issue.

In my hosting environment, the worker threads are associated with a different Windows identity than their parent. The identity used by the worker threads only had read permission on my App_Data/Logs folder. As my access to the server is limited, I created a .cshtml file to programmatically add write and modify permissions to the identity of the worker threads.

like image 148
Nikolaj Dam Larsen Avatar answered Oct 22 '22 13:10

Nikolaj Dam Larsen