Search code examples
c#.netloggingstreamwriter

StreamWriter keeps writing to the same file after instantiating it again for another file


I'm trying to implement a simple file-logger object, with the possibility to truncate the file when its size reaches a threshold.

I am using a StreamWriter, which gets written to at each call of the method Log(). In order to decide when to truncate, I am checking the StreamWriter.BaseStream.Length property before each write and, if it is bigger than the threshold, I close the StreamWriter, create a new file and open the StreamWriter on that file. For example, if I set the threshold to 10Mb files, it will create a new file each 10Mb of written data.

Under normal load (let's say 3-4 seconds between calls to Log()), everything works as it should. However, the product which is going to use this logger will work with lots of data and required logging every 1 second, even less.

The problem is that the logger seems to completely ignore the creation of the new file(and opening the new stream), failing to truncate it and keeps writing to the existing stream.

I also tried to manually compute the stream's length, hoping it would be a problem with the stream, but it does not work.

I have found out that going step by step with the debugger makes it work correctly, but it does not solve my problem. Logging each second seems to make the program skip the UpdateFile() method entirely.

public class Logger
{
    private static Logger _logger;
    private const string LogsDirectory = "Logs";

    private StreamWriter _streamWriter;
    private string _path;
    private readonly bool _truncate;
    private readonly int _maxSizeMb;
    private long _currentSize;

    //===========================================================//
    public static void Set(string filename, bool truncate = false, int maxSizeMb = 10)
    {
        if (_logger == null)
        {
            if (filename.Contains('_'))
            {
                throw new Exception("Filename cannot contain the _ character!");
            }

            if (filename.Contains('.'))
            {
                throw new Exception("The filename must not include the extension");
            }
            _logger = new Logger(filename, truncate, maxSizeMb);
        }
    }

    //===========================================================//
    public static void Log(string message, LogType logType = LogType.Info)
    {
        _logger?.InternalLog(message, logType);
    }

    //===========================================================//
    public static void LogException(Exception ex)
    {
        _logger?.InternalLogException(ex);
    }

    //===========================================================//
    private Logger(string filename, bool truncate = false, int maxSizeMb = 10)
    {
        _path = Path.Combine(AppDomain.CurrentDomain.BaseDirectory, LogsDirectory, $"{filename}_{DateTimeToPrefix(DateTime.Now)}.log");
        if (CheckForExistingLogs())
        {
            _path = GetLatestLogFilename();
        }
        _truncate = truncate;
        _maxSizeMb = maxSizeMb;
        _streamWriter = new StreamWriter(File.Open(_path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite));
        _currentSize = _streamWriter.BaseStream.Length;
    }

    //===========================================================//
    private bool CheckForExistingLogs()
    {
        var directory = Path.GetDirectoryName(_path);
        var filename = Path.GetFileNameWithoutExtension(_path);
        if (filename.Contains('_'))
        {
            filename = filename.Split('_').First();
        }
        return new DirectoryInfo(directory).GetFiles().Any(x => x.Name.ToLower().Contains(filename.ToLower()));
    }

    //===========================================================//
    private string GetLatestLogFilename()
    {
        var directory = Path.GetDirectoryName(_path);
        var filename = Path.GetFileNameWithoutExtension(_path);
        if (filename.Contains('_'))
        {
            filename = filename.Split('_').First();
        }
        var files = new DirectoryInfo(directory).GetFiles().Where(x => x.Name.ToLower().Contains(filename.ToLower()));
        files = files.OrderBy(x => PrefixToDateTime(x.Name.Split('_').Last()));
        return files.Last().FullName;
    }

    //===========================================================//
    private void UpdateFile()
    {
        _streamWriter.Flush();
        _streamWriter.Close();
        _streamWriter.Dispose();
        _streamWriter = StreamWriter.Null;
        _path = GenerateNewFilename();
        _streamWriter = new StreamWriter(File.Open(_path, FileMode.Append, FileAccess.Write, FileShare.ReadWrite));
        _currentSize = _streamWriter.BaseStream.Length;
    }

    //===========================================================//
    private string GenerateNewFilename()
    {
        var directory = Path.GetDirectoryName(_path);
        var oldFilename = Path.GetFileNameWithoutExtension(_path);
        if (oldFilename.Contains('_'))
        {
            oldFilename = oldFilename.Split('_').First();
        }

        var newFilename = $"{oldFilename}_{DateTimeToPrefix(DateTime.Now)}.log";
        return Path.Combine(directory, newFilename);
    }

    //===========================================================//
    private static string DateTimeToPrefix(DateTime dateTime)
    {
        return dateTime.ToString("yyyyMMddHHmm");
    }

    //===========================================================//
    private static DateTime PrefixToDateTime(string prefix)
    {
        var year = Convert.ToInt32(string.Join("", prefix.Take(4)));
        var month = Convert.ToInt32(string.Join("", prefix.Skip(4).Take(2)));
        var day = Convert.ToInt32(string.Join("", prefix.Skip(6).Take(2)));
        var hour = Convert.ToInt32(string.Join("", prefix.Skip(8).Take(2)));
        var minute = Convert.ToInt32(string.Join("", prefix.Skip(10).Take(2)));

        return new DateTime(year, month, day, hour, minute, 0);
    }

    //===========================================================//
    private int ConvertSizeToMb()
    {
        return Convert.ToInt32(Math.Truncate(_currentSize / 1024f / 1024f));
    }

    //===========================================================//
    public void InternalLog(string message, LogType logType = LogType.Info)
    {
        if (_truncate && ConvertSizeToMb() >= _maxSizeMb)
        {
            UpdateFile();
        }

        var sendMessage = string.Empty;
        switch (logType)
        {
            case LogType.Error:
            {
                sendMessage += "( E ) ";
                break;
            }
            case LogType.Warning:
            {
                sendMessage += "( W ) ";
                break;
            }
            case LogType.Info:
            {
                sendMessage += "( I ) ";
                break;
            }
        }
        sendMessage += $"{DateTime.Now:dd.MM.yyyy HH:mm:ss}: {message}";
        _streamWriter.WriteLine(sendMessage);
        _streamWriter.Flush();
        _currentSize += Encoding.ASCII.GetByteCount(sendMessage);
        Console.WriteLine(_currentSize);
    }

    //===========================================================//
    public void InternalLogException(Exception ex)
    {
        if (_truncate && ConvertSizeToMb() >= _maxSizeMb)
        {
            UpdateFile();
        }

        var sendMessage = $"( E ) {DateTime.Now:dd.MM.yyyy HH:mm:ss}: {ex.Message}{Environment.NewLine}{ex.StackTrace}";
        _streamWriter.WriteLine(sendMessage);
        _streamWriter.Flush();
        _currentSize += Encoding.ASCII.GetByteCount(sendMessage);
    }
}

Usage example:

private static void Main(string[] args)
{
    Logger.Set("Log", true, 10);
    while (true)
    {
        Logger.Log("anything");
    }
}

Have you ever encountered such a problem before? How can it be solved? Thanks :)


Solution

  • I don't know how much data your application writes to the log each minute. But if the amount is more than 10MB then the method DateTimeToPrefix will return the same name for a second call inside a minute interval. (Well at least for me this is what happens with the code included in the Main method).

    I changed the ToString() to include also the seconds and this gives correct amount of data written in the expected files.

    private static string DateTimeToPrefix(DateTime dateTime)
    {
        return dateTime.ToString("yyyyMMddHHmmss");
    }