serilog / serilog-sinks-file

Write Serilog events to files in text and JSON formats, optionally rolling on time or size
Apache License 2.0
333 stars 117 forks source link

Shared log files throws UnauthorizedAccessException on Mutex creation #291

Closed bocca closed 11 months ago

bocca commented 1 year ago

In some cases, the second process trying to open a shared file (shared: true) throws exception on mutex creation, and no log events are registered. This is registered in SelfLog:

2023-07-13T14:56:59.4806193Z Caught exception while emitting to sink Serilog.Sinks.File.RollingFileSink: System.UnauthorizedAccessException: Access to the path 'C::logs:log-20230713.txt.serilog' is denied.
   at System.Threading.Mutex.CreateMutexCore(Boolean initiallyOwned, String name, Boolean& createdNew)
   at System.Threading.Mutex..ctor(Boolean initiallyOwned, String name)
   at Serilog.Sinks.File.SharedFileSink..ctor(String path, ITextFormatter textFormatter, Nullable`1 fileSizeLimitBytes, Encoding encoding)
   at Serilog.Sinks.File.RollingFileSink.OpenFile(DateTime now, Nullable`1 minSequence)
   at Serilog.Sinks.File.RollingFileSink.AlignCurrentFileTo(DateTime now, Boolean nextSequence)
   at Serilog.Sinks.File.RollingFileSink.Emit(LogEvent logEvent)
   at Serilog.Core.Sinks.SafeAggregateSink.Emit(LogEvent logEvent)

The documentation for System.Threading.Mutex says

UnauthorizedAccessException: The named mutex exists and has access control security, but the user does not have FullControl."

My enviroment is: ASP.NET Core 6 app hosted in IIS in-process in Windows Server 2012 R2 (I know, it's old). I deploy using Blue/Green deployment applied to the apppool level, that is, for a small period of time, I have two appools simultaneously trying to log to the same file.

In .NET Framework, there is a Mutex constructor that accepts an MutexSecurity with an ACL to specify the FullControl permission required. In .NET Core there is no such construtor, but instead the method MutexAcl.Create in System.Threading.AccessControl nuget package can be used. This way of creating the mutex, posted in NLog issue #5244, resolves the problem:

        private static Mutex ForceCreateSharableMutex(string name)
        {
            if (System.Runtime.InteropServices.RuntimeInformation.IsOSPlatform(OSPlatform.Windows))
            {
                // Creates a mutex sharable by more than one process 
                var mutexSecurity = new MutexSecurity();
                var everyoneSid = new SecurityIdentifier(WellKnownSidType.WorldSid, null);
                mutexSecurity.AddAccessRule(new MutexAccessRule(everyoneSid, MutexRights.FullControl, AccessControlType.Allow));

#if NET48
                // The constructor will either create new mutex or open
                // an existing one, in a thread-safe manner
                return new Mutex(false, name, out _, mutexSecurity);
#else
                return MutexAcl.Create(false, name, out _, mutexSecurity);
#endif
            }

            return new Mutex(false, name, out _);
        }

I have tested it, replacing the mutex creation in SharedFileSink.OSMutex.cs, and it worked for me.

In case of .NET Core, using MutexAcl.Create adds a dependency to System.Threading.AccessControl package. If that is not desirable, I suggest to include a way to pass to Serilog a factory method to create mutexes, and talk about the problem and solution in the documentation of Shared log files.

nblumhardt commented 1 year ago

ATOMIC_APPEND has been possible in .NET (Core) for a few versions now, I think we'd be better off enabling that feature and taking the necessary NUPKG dependency on the versions that support it.

(Changing access rights to the mutex would probably need a breaking change, since it would allow a low-privilege user to disrupt logging by a higher-privileged user by taking and never releasing the mutex.)

bocca commented 1 year ago

I have tested ATOMIC_APPEND and added some comments and code in #221.

nblumhardt commented 1 year ago

Thanks!

bartelink commented 11 months ago

Closing on the basis that #221 can track the issue/need If this is incorrect and there is something separately actionable here, I'm not opposed to having an issue; I just don't see what it is...