Open log file with Read/Write access

[MaxXor]

I am trying to implement encrypted storing of log files. However this is currently not possible with the FileLifecycleHooks class as the underlyingStream parameter was opened with FileAccess.Write. I'm trying to get it to work with AES in CBC mode with padding, which requires re-reading of the last block because of the padding if an existing log file is opened.

Would it be possible to open the log files with read/write access in this library?

Below is a minimal example which describes the situation:

using Serilog;
using Serilog.Sinks.File;
using System;
using System.IO;
using System.Security.Cryptography;
using System.Text;

namespace TestCryptoHooks
{
    public class Program
    {
        // Adapted from: https://stackoverflow.com/a/30864169

        public static string ReadStringFromFile(string fileName, byte[] key, byte[] iv)
        {
            string plainText;

            using (Rijndael algo = Rijndael.Create())
            {
                algo.Key = key;
                algo.IV = iv;
                algo.Mode = CipherMode.CBC;
                algo.Padding = PaddingMode.PKCS7;

                // Create the streams used for decryption.
                using (FileStream file = new FileStream(fileName, FileMode.Open, FileAccess.Read))
                // Create a decrytor to perform the stream transform.
                using (ICryptoTransform decryptor = algo.CreateDecryptor())
                using (CryptoStream cs = new CryptoStream(file, decryptor, CryptoStreamMode.Read))
                using (StreamReader sr = new StreamReader(cs))
                {
                    // Read all data from the stream.
                    plainText = sr.ReadToEnd();
                }
            }

            return plainText;
        }

        public class CryptoHooks : FileLifecycleHooks
        {
            private byte[] _key;
            private byte[] _iv;

            public CryptoHooks(byte[] key, byte[] iv)
            {
                _key = key;
                _iv = iv;
            }

            public override Stream OnFileOpened(Stream underlyingStream, Encoding _)
            {
                var algo = Rijndael.Create(); 
                algo.Key = _key;
                algo.IV = _iv;
                algo.Mode = CipherMode.CBC;
                algo.Padding = PaddingMode.PKCS7;

                byte[] previous = null;
                int previousLength = 0;

                long length = underlyingStream.Length;

                if (length != 0)
                {
                    // The IV length is equal to the block length
                    byte[] block = new byte[_iv.Length];

                    if (length >= _iv.Length * 2)
                    {
                        // At least 2 blocks, take the penultimate block
                        // as the IV
                        underlyingStream.Position = length - _iv.Length * 2;
                        underlyingStream.Read(block, 0, block.Length);
                        algo.IV = block;
                    }
                    else
                    {
                        // A single block present, use the IV given
                        underlyingStream.Position = length - _iv.Length;
                        algo.IV = _iv;
                    }

                    // Read the last block
                    underlyingStream.Read(block, 0, block.Length);

                    // And reposition at the beginning of the last block
                    underlyingStream.Position = length - _iv.Length;

                    // We use a MemoryStream because the CryptoStream
                    // will close the Stream at the end
                    using (var ms = new MemoryStream(block))
                    // Create a decrytor to perform the stream transform.
                    using (ICryptoTransform decryptor = algo.CreateDecryptor())
                    using (CryptoStream cs = new CryptoStream(ms, decryptor, CryptoStreamMode.Read))
                    {
                        // Read all data from the stream. The decrypted last
                        // block can be long up to block length characters
                        // (so up to iv.Length) (this with AES + CBC)
                        previous = new byte[_iv.Length];
                        previousLength = cs.Read(previous, 0, previous.Length);
                    }
                }
                else
                {
                    // Use the IV given
                    algo.IV = _iv;
                }

                var outStream = new CryptoStream(underlyingStream, algo.CreateEncryptor(), CryptoStreamMode.Write);

                // Rewrite the last block, if present. We even skip
                // the case of block present but empty
                if (previousLength != 0)
                {
                    outStream.Write(previous, 0, previousLength);
                }

                return outStream;
            }
        }

        static void Main(string[] args)
        {
            var key = Encoding.UTF8.GetBytes("Simple key");
            var iv = Encoding.UTF8.GetBytes("Simple IV");

            Array.Resize(ref key, 128 / 8);
            Array.Resize(ref iv, 128 / 8);

            Log.Logger = new LoggerConfiguration()
                .WriteTo.Async(a => a.File("file.log", rollingInterval: RollingInterval.Day, retainedFileCountLimit: 31, hooks: new CryptoHooks(key, iv)))
                .CreateLogger();

            Log.Information("This will be written to disk on the worker thread");
            Log.CloseAndFlush();
            string plainText = ReadStringFromFile("file20200602.log", key, iv);
            Console.WriteLine(plainText);
            Console.ReadLine();
        }
    }
}

[cocowalla]

Thanks for the report!

I doubt there are any implications to just opening the FileStream in ReadWrite mode instead of Write, and this would likely be useful for other hooks too.

I'll take a closer look at this one tomorrow and report back 👍

[MaxXor]

No further remarks are mentioned in the .NET docs and the FileShare.Read flag is also still working as expected in my testings. I didn't notice any different behavior. I hope this can be integrated and soon released in an update.

[cocowalla]

After looking some more, I see that all FileStreams are opened in append mode, which makes sense for log files, but only works in conjunction with Write access, not Read/ReadWrite.

For another reason, I actually did some testing recently with different file modes on Windows, and while Append mode should be giving a hint to the OS, it didn't actually result in any better performance. I think on Windows at least, Append mode is more about access permissions and semantics; I believe writes before the current EOF are prevented, and it will seek to the end of the file automatically.

So, this one isn't so clear cut as I thought 😄

@nblumhardt what are your thoughts here? Reading from the underlying stream would be useful, even if only in some niche scenarios. But I wonder if there is perhaps some other route, such as a new hook:

string OnFileOpening();

The idea here would be to provide the caller the name of the file before Serilog opens it, so the caller has a chance to do anything they want with it beforehand (read it, delete it, write a header, whatever).

[nblumhardt]

Tricky! I'd be wary of changing the open flags, at least without spending some time re-validating the atomic append functionality and concurrent-burn-testing it (https://nblumhardt.com/2016/08/atomic-shared-log-file-writes/ ). My instinct says changing flags here will cause downstream effects and should probably be a last resort :-)

By

string OnFileOpening();

did you mean:

Stream OnFileOpening(string path);

@cocowalla ?

I think it would be easy in that kind of scheme to write hooks that break other expectations of the sink, later in the process. Not sure how that would come out, I need to give it more thought - no straightforward options, unfortunately.

If you're on a tight timeline, @MaxXor, creating a minimal encrypted file sink based on this package will be the quickest and easiest path.

[cocowalla]

@nblumhardt
I actually meant something in between:

void OnFileOpening(string path);

It wouldn't return anything, just give the caller the opportunity to work with the file at that path (if it exists).

Something like you suggested below would indeed be much more powerful, and make it rather easy to break things 😄 It would also have some crossover with the existing OnFileOpened callback.

Stream OnFileOpening(string path);

Not sure I entirely understand how append mode helps multiple processes to write to the same file though (the very idea of this sounds highly dubious tho!) - are you saying that if multiple processes open with mode, each write automatically locks the file, seeks to the end of the stream, writes, then unlocks the file? I had imagined it just seeked to the end when the stream was first opened 🤷

But aye, I can certainly see that this isn't as simple as it initially looked 😖

@EamonHetherton you've also been involved with hooks, do you have any thoughts on this?

[EamonHetherton]

My use cases to date have all been 1 proccess = 1 log file and I don't have a depth of experience with the nuances of FileMode/FileAccess so not sure I can contribute much. That said, I'd be concerned that if we simply pass the filename back through a hook before we open it to write to, and that the hook consumer was to open the file for read, that the temporal proximity of their open for read and serilog's open for append/write might cause problems?

An option at the file sink level to specify file access mode might work; retaining the existing behaviour by default but I guess the surface area of that change is much larger, not just in code but complexity and documentation etc. Feel free to ignore all of the above if I misinterpreted something, its early and i've got a head cold so brain's running at significantly reduced capacity :)

[MaxXor]

Any update on this?

[nblumhardt]

Nothing happening in the short-term on this; forking and modifying for your needs will be the quickest way forward for now, sorry.