I have two SignalR servers working with a redis backplane and using log4net. When I start the app, everything is fine, the log file is written correctly on both servers. But sometimes, the log file isn't written anymore and the internal debug log says :
log4net: Opening file for writing [C:\myLogPath\] append [True]
...everytime a new line have to be log (more than 100 times by seconds - it's the expected logging rate) without any error message, neither before nor after. The problem happens on both servers AT THE SAME TIME - the last line logged is exactly the same; that's why I wrote the SignalR servers were using a backplane. Here is my log4net.config :
<log4net>
<appender name="LogFileAppender" type="log4net.Appender.RollingFileAppender" >
<param name="File" value="C:\myLogPath\SignalR\log.txt" />
<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
<appendToFile value="true" />
<rollingStyle value="Date" />
<maxSizeRollBackups value="-1" />
<maximumFileSize value="100MB" />
<datePattern value="ddMMyyyy" />
<staticLogFileName value="true" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date - %-5level - %message%newline" />
</layout>
</appender>
<root>
<level value="ALL" />
<appender-ref ref="LogFileAppender" />
</root>
</log4net>
I am sure the files are not being rolled up, as the maxSizeRollBackups is set to -1 (equivalent to infinite) and the log.txt file weights ~16MB , far away from the maximumFileSize. I tried with and without MinimalLock, without any effect.
Here is the Startup class, where I start log4net :
public class Startup
{
public void Configuration(IAppBuilder app)
{
Common.Logger.Start(ConfigurationManager.AppSettings["pathLog4net"]);
Common.Logger.Info("Démarrage SignalR");
//Connect to backplane, make some DI, singletons initialisations...
Common.Logger.Info("Mapping");
app.Map("/signalr", map =>
{
map.UseCors(CorsOptions.AllowAll);
var hubConfiguration = new HubConfiguration
{
EnableJSONP = true,
EnableDetailedErrors = HttpContext.Current.IsDebuggingEnabled
};
map.RunSignalR(hubConfiguration);
});
}
}
... and the Common.Logger class, which encapsulate log4net :
public static class Logger
{
private static log4net.ILog Log { get; set; }
static Logger()
{
Log = log4net.LogManager.GetLogger(typeof(Logger));
}
public static void Start(string path)
{
log4net.Config.XmlConfigurator.Configure(new FileInfo(path));
}
public static void Error(object msg)
{
Log.Error(msg);
}
public static void Info(object msg)
{
Log.Info(msg);
}
}
The Logger.Info method is called in every hub methods, so I wondered if it could be a concurrency problem, but the log4net doc states it is tread safe - although I don't know at which level it is; and the problem occurs on the second SignalR exactly AT THE SAME TIME. Every time I restart the apps, the log is working during an undefined amout of time, then it stops again.
I tried changing the log4net config, disabling the internal log, but nothing works. I don't know what to do anymore... why is the log stopping ? why log4net can't append to the file, even if the internal log says Opening file [...] append [True] ? if anyone have some idea I'll be grateful forever :)
EDIT: Obviously the rights are correctly set - I was so f*cked up I shamefully tried Full control to Everyone...
Sooooo... actually it was a simple problem. My websites are working with a business layer, and they had their own log4net instance, using the same config file... so it was simply a lock error.
I changed the signalr logging encapsulation to use the log4net of the business layer, and now everything is fine.
Good to know: when there is a lock error, log4net seems to log it only on the first attempt to write the said file.
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With