Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Why does log4net randomly stops to log with SignalR?

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...

like image 636
gobes Avatar asked Jan 28 '26 23:01

gobes


1 Answers

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.

like image 84
gobes Avatar answered Jan 31 '26 13:01

gobes



Donate For Us

If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!