Introduced serilog in Vocaluxe

Vocaluxe/Base/CGraphics.cs

@@ -20,6 +20,8 @@ using System.Collections.Generic;
 using System.Diagnostics;
 using System.Drawing;
 using System.Windows.Forms;
+using Serilog.Events;
+using SerilogTimings;
 using Vocaluxe.Base.Fonts;
 using Vocaluxe.Base.ThemeSystem;
 using Vocaluxe.Screens;
@@ -61,36 +63,35 @@ namespace Vocaluxe.Base
         public static void Init()
         {
             // Add Screens, must be the same order as in EScreens!
-            CLog.StartBenchmark("Build Screen List");
+            CLog.LogInformation("Build Screen List");
+            using (Operation.At(LogEventLevel.Information).Time("Build Screen List"))
+            {
+                _Screens.Add(new CScreenTest());
+                _Screens.Add(new CScreenLoad());
+                _Screens.Add(new CScreenMain());
+                _Screens.Add(new CScreenSong());
+                _Screens.Add(new CScreenOptions());
+                _Screens.Add(new CScreenSing());
+                _Screens.Add(new CScreenProfiles());
+                _Screens.Add(new CScreenScore());
+                _Screens.Add(new CScreenHighscore());
+                _Screens.Add(new CScreenOptionsGame());
+                _Screens.Add(new CScreenOptionsSound());
+                _Screens.Add(new CScreenOptionsRecord());
+                _Screens.Add(new CScreenOptionsVideo());
+                _Screens.Add(new CScreenOptionsVideoAdjustments());
+                _Screens.Add(new CScreenOptionsLyrics());
+                _Screens.Add(new CScreenOptionsTheme());
+                _Screens.Add(new CScreenNames());
+                _Screens.Add(new CScreenCredits());
+                _Screens.Add(new CScreenParty());
 
-            _Screens.Add(new CScreenTest());
-            _Screens.Add(new CScreenLoad());
-            _Screens.Add(new CScreenMain());
-            _Screens.Add(new CScreenSong());
-            _Screens.Add(new CScreenOptions());
-            _Screens.Add(new CScreenSing());
-            _Screens.Add(new CScreenProfiles());
-            _Screens.Add(new CScreenScore());
-            _Screens.Add(new CScreenHighscore());
-            _Screens.Add(new CScreenOptionsGame());
-            _Screens.Add(new CScreenOptionsSound());
-            _Screens.Add(new CScreenOptionsRecord());
-            _Screens.Add(new CScreenOptionsVideo());
-            _Screens.Add(new CScreenOptionsVideoAdjustments());
-            _Screens.Add(new CScreenOptionsLyrics());
-            _Screens.Add(new CScreenOptionsTheme());
-            _Screens.Add(new CScreenNames());
-            _Screens.Add(new CScreenCredits());
-            _Screens.Add(new CScreenParty());
-
-            Debug.Assert(_Screens.Count == (int)EScreen.CountEntry, "Screen list and screens enum do not match");
-
-            _PopupScreens.Add(new CPopupScreenPlayerControl());
-            _PopupScreens.Add(new CPopupScreenVolumeControl());
-            _PopupScreens.Add(new CPopupScreenServerQR());
-
-            CLog.StopBenchmark("Build Screen List");
+                Debug.Assert(_Screens.Count == (int)EScreen.CountEntry, "Screen list and screens enum do not match");
 
+                _PopupScreens.Add(new CPopupScreenPlayerControl());
+                _PopupScreens.Add(new CPopupScreenVolumeControl());
+                _PopupScreens.Add(new CPopupScreenServerQR());
+            }
             CurrentScreen = _Screens[(int)EScreen.Load];
             NextScreen = null;
             _CurrentPopupScreen = EPopupScreens.NoPopup;
@@ -99,9 +100,11 @@ namespace Vocaluxe.Base
             GlobalAlpha = 1f;
             ZOffset = 0f;
 
-            CLog.StartBenchmark("Load Theme");
-            LoadTheme();
-            CLog.StopBenchmark("Load Theme");
+            CLog.LogInformation("Load Theme");
+            using (Operation.At(LogEventLevel.Information).Time("Load Theme"))
+            {
+                LoadTheme();
+            }
         }
 
         public static void Close()
@@ -118,10 +121,12 @@ namespace Vocaluxe.Base
 
             for (int i = 0; i < _Screens.Count; i++)
             {
-                CLog.StartBenchmark("Load Theme " + Enum.GetNames(typeof(EScreen))[i]);
-                _Screens[i].Init();
-                _Screens[i].LoadTheme(CThemes.GetThemeScreensPath(_Screens[i].PartyModeID));
-                CLog.StopBenchmark("Load Theme " + Enum.GetNames(typeof(EScreen))[i]);
+                CLog.LogInformation("Load Theme " + Enum.GetNames(typeof(EScreen))[i]);
+                using (Operation.At(LogEventLevel.Information).Time("Load Theme " + Enum.GetNames(typeof(EScreen))[i]))
+                {
+                    _Screens[i].Init();
+                    _Screens[i].LoadTheme(CThemes.GetThemeScreensPath(_Screens[i].PartyModeID));
+                }
             }
 
             foreach (IMenu popup in _PopupScreens)

Vocaluxe/Base/CLog.cs

@@ -16,210 +16,262 @@
 #endregion
 
 using System;
+using System.Collections.Generic;
 using System.Diagnostics;
 using System.IO;
+using System.Runtime.CompilerServices;
 using System.Text;
+using System.Text.RegularExpressions;
 using System.Windows.Forms;
+using Serilog;
+using Serilog.Configuration;
+using Serilog.Core;
+using Serilog.Context;
+using Serilog.Events;
+using Serilog.Formatting.Compact;
 
 namespace Vocaluxe.Base
 {
-    class CLogFile : IDisposable
-    {
-        private readonly string _LogFileName;
-        private readonly string _LogName;
-        private StreamWriter _LogFile;
-        private readonly Object _FileMutex = new Object();
-
-        public CLogFile(string fileName, string logName)
-        {
-            _LogName = logName;
-            _LogFileName = fileName;
-        }
-
-        private void _Open()
-        {
-            lock (_FileMutex)
-            {
-                if (_LogFile != null)
-                    return;
-                _LogFile = new StreamWriter(Path.Combine(CSettings.DataFolder, _LogFileName), false, Encoding.UTF8);
-
-                _LogFile.WriteLine(_LogName + " " + CSettings.GetFullVersionText() + " " + DateTime.Now);
-                _LogFile.WriteLine("----------------------------------------");
-                _LogFile.WriteLine();
-            }
-        }
-
-        public void Close()
-        {
-            lock (_FileMutex)
-            {
-                if (_LogFile == null)
-                    return;
-                try
-                {
-                    _LogFile.Flush();
-                    _LogFile.Close();
-                }
-                catch (Exception) {}
-            }
-        }
-
-        public virtual void Add(string text)
-        {
-            if (_LogFile == null)
-                _Open();
-
-            // ReSharper disable PossibleNullReferenceException
-            _LogFile.WriteLine(text);
-            // ReSharper restore PossibleNullReferenceException
-            _LogFile.Flush();
-        }
-
-        public void Dispose()
-        {
-            Close();
-            GC.SuppressFinalize(this);
-        }
-    }
-
-    class CErrorLogFile : CLogFile
-    {
-        private int _NumErrors;
-        private readonly Object _WriteMutex = new Object();
-
-        public CErrorLogFile(string fileName, string logName) : base(fileName, logName) {}
-
-        public override void Add(string errorText)
-        {
-            lock (_WriteMutex)
-            {
-                _NumErrors++;
-                base.Add(_NumErrors + ") " + errorText);
-            }
-        }
-    }
-
     static class CLog
     {
-        private const int _MaxBenchmarks = 10;
-        private static int _BenchmarksRunning;
         private static bool _Initialized;
 
-        private static CLogFile _ErrorLog;
-        private static CLogFile _PerformanceLog;
-        private static CLogFile _BenchmarkLog;
-        private static CLogFile _DebugLog;
-        private static CLogFile _SongInfoLog;
+        private static readonly StringBuilder _MainLogStringBuilder = new StringBuilder();
+        private static readonly StringWriter _MainLogStringWriter = new StringWriter(_MainLogStringBuilder);
 
-        private static Stopwatch[] _BenchmarkTimer;
-        private static readonly double _NanosecPerTick = (1000.0 * 1000.0 * 1000.0) / Stopwatch.Frequency;
+        private static Logger _MainLog;
+        private static Logger _SongInfoLog;
+        private static string _LogFolder;
 
-        public static void Init()
+        private const string _MainLogTemplate = "[{TimeStampFromStart}] [{Level}] {Message}{NewLine}{Properties}{NewLine}{Exception}";
+        private const string _SongInfoLogTemplate = "{Message}{NewLine}Additional info:{Properties}{NewLine}{Exception}";
+
+        public static void Init(string logFolder)
         {
-            _ErrorLog = new CErrorLogFile(CSettings.FileNameErrorLog, "Error-Log");
-            _PerformanceLog = new CLogFile(CSettings.FileNamePerformanceLog, "Performance-Log");
-            _BenchmarkLog = new CLogFile(CSettings.FileNameBenchmarkLog, "Benchmark-Log");
-            _DebugLog = new CLogFile(CSettings.FileNameDebugLog, "Debug-Log");
-            _SongInfoLog = new CLogFile(CSettings.FileNameSongInfoLog, "Song-Information-Log");
+            _LogFolder = logFolder;
 
-            _BenchmarkTimer = new Stopwatch[_MaxBenchmarks];
-            for (int i = 0; i < _BenchmarkTimer.Length; i++)
-                _BenchmarkTimer[i] = new Stopwatch();
-            _BenchmarksRunning = 0;
+            _RollLogs(Path.Combine(_LogFolder, CSettings.FileNameMainLog), 2);
+            _RollLogs(Path.Combine(_LogFolder, CSettings.FileNameSongInfoLog), 2);
+
+            _MainLog = new LoggerConfiguration()
+                .Enrich.WithThreadId()
+                .Enrich.FromLogContext()
+                .Enrich.WithTimeStampFromStart()
+                .WriteTo.TextWriter(_MainLogStringWriter, outputTemplate: _MainLogTemplate)
+                // Json can be activated by adding "new CompactJsonFormatter()" as first argument
+                .WriteTo.File(Path.Combine(_LogFolder, CSettings.FileNameMainLog), flushToDiskInterval: TimeSpan.FromSeconds(30), outputTemplate: _MainLogTemplate)
+#if DEBUG
+                .WriteTo.Console(outputTemplate: _MainLogTemplate)
+#endif
+                .CreateLogger();
+
+            Log.Logger = _MainLog;
+
+            _SongInfoLog = new LoggerConfiguration()
+                .WriteTo.File(Path.Combine(_LogFolder, CSettings.FileNameSongInfoLog), flushToDiskInterval: TimeSpan.FromSeconds(60), outputTemplate: _SongInfoLogTemplate)
+#if DEBUG
+                .WriteTo.Console(outputTemplate: "[SongInfo] " + _SongInfoLogTemplate)
+#endif
+                .CreateLogger();
+           
             _Initialized = true;
         }
+        
 
         public static void Close()
         {
             if (_Initialized)
             {
-                _ErrorLog.Dispose();
-                _ErrorLog = null;
-                _PerformanceLog.Dispose();
-                _PerformanceLog = null;
-                _BenchmarkLog.Dispose();
-                _BenchmarkLog = null;
-                _DebugLog.Dispose();
-                _DebugLog = null;
+                
+                _MainLog.Dispose();
+                _MainLog = null;
                 _SongInfoLog.Dispose();
                 _SongInfoLog = null;
                 _Initialized = false;
             }
         }
 
-        #region LogError
-        public static void LogError(string errorText, bool show = false, bool exit = false, Exception e = null)
+        public static string MainLogEntries
         {
-            if (show)
-                MessageBox.Show(errorText, CSettings.ProgramName, MessageBoxButtons.OK, MessageBoxIcon.Error);
-            if (e != null)
-                errorText += ": " + e;
-            _ErrorLog.Add(errorText);
-            if (exit)
-                Environment.Exit(Environment.ExitCode);
-        }
-        #endregion LogError
-
-        public static void LogDebug(string text)
-        {
-            _DebugLog.Add(String.Format("{0:HH:mm:ss.ffff}", DateTime.Now) + ":" + text);
-#if DEBUG
-            Console.WriteLine(text);
-#endif
-        }
-
-        public static void LogSongInfo(string text)
-        {
-            _SongInfoLog.Add(text);
-        }
-
-        public static void LogPerformance(string text)
-        {
-            _PerformanceLog.Add(text);
-            _PerformanceLog.Add("-------------------------------");
-        }
-
-        #region LogBenchmark
-        public static void StartBenchmark(string text)
-        {
-            if (_BenchmarksRunning < _MaxBenchmarks)
-            {
-                string space = String.Empty;
-                for (int i = 0; i < _BenchmarksRunning; i++)
-                    space += "  ";
-                _BenchmarkLog.Add(space + "Start " + text);
-
-                _BenchmarkTimer[_BenchmarksRunning].Restart();
+            get {
+                _MainLogStringWriter.Flush();
+                return _MainLogStringBuilder.ToString();
             }
-            else
-                LogError("Tried to start to many benchmarks at once"); //Log and ignore
-            _BenchmarksRunning++; //Inc even if not started to correct right Stop() call
         }
 
-        public static void StopBenchmark(string text)
+        public static void LogError(Exception exception, string errorText, bool show = false, bool exit = false, [CallerMemberName] string callerMethodeName = "",
+            [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
         {
-            if (_BenchmarksRunning > 0 && _BenchmarksRunning <= _MaxBenchmarks)
+            using (LogContext.PushProperty("CallingContext", new { callerMethodeName = callerMethodeName, callerFilePath = callerFilePath, callerLineNumer = callerLineNumer }))
             {
-                _BenchmarksRunning--;
-                _BenchmarkTimer[_BenchmarksRunning].Stop();
-
-                string space = String.Empty;
-                for (int i = 0; i < _BenchmarksRunning; i++)
-                    space += "  ";
-
-                float ms;
-                if (Stopwatch.IsHighResolution && _NanosecPerTick > 0)
-                    ms = (float)((_NanosecPerTick * _BenchmarkTimer[_BenchmarksRunning].ElapsedTicks) / (1000.0 * 1000.0));
+                if (exit)
+                {
+                    _MainLog.Fatal(exception, errorText, propertyValues);
+                }
                 else
-                    ms = _BenchmarkTimer[_BenchmarksRunning].ElapsedMilliseconds;
+                {
+                    _MainLog.Error(exception, errorText, propertyValues);
+                }
+            }
 
-                _BenchmarkLog.Add(space + "Stop " + text + ", Elapsed Time: " + ms.ToString("0.000") + "ms");
-                _BenchmarkLog.Add(String.Empty);
+            if (show)
+            {
+                //Todo: Logsend assistent
+                MessageBox.Show(errorText, CSettings.ProgramName, MessageBoxButtons.OK, MessageBoxIcon.Error);
+            }
+
+
+            if (exit)
+            {
+                // Flush the logging piplines before exiting
+                _MainLog.Dispose();
+                _SongInfoLog.Dispose();
+                // Close the Programm
+                Environment.Exit(Environment.ExitCode);
             }
-            else
-                _BenchmarksRunning--;
         }
-        #endregion LogBenchmark
+
+        public static void LogError(string errorText, bool show = false, bool exit = false, [CallerMemberName] string callerMethodeName = "",
+            [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
+        {
+            // ReSharper disable ExplicitCallerInfoArgument
+            LogError(null, errorText, show, exit, callerMethodeName, callerFilePath, callerLineNumer, propertyValues);
+        }
+
+        public static void LogWarning(string text, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
+        {
+            using (LogContext.PushProperty("CallingContext", new { callerMethodeName = callerMethodeName, callerFilePath = callerFilePath, callerLineNumer = callerLineNumer }))
+            {
+                _MainLog.Warning(text, propertyValues);
+            }
+        }
+
+        public static void LogInformation(string text, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
+        {
+            using (LogContext.PushProperty("CallingContext", new { callerMethodeName = callerMethodeName, callerFilePath = callerFilePath, callerLineNumer = callerLineNumer }))
+            {
+                _MainLog.Information(text, propertyValues);
+            }
+        }
+
+        public static void LogDebug(string text, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
+        {
+            using (LogContext.PushProperty("CallingContext", new { callerMethodeName = callerMethodeName, callerFilePath = callerFilePath, callerLineNumer = callerLineNumer }))
+            {
+                _MainLog.Debug(text, propertyValues);
+            }
+        }
+
+        public static void LogSongError(Exception exception, string text, params object[] propertyValues)
+        {
+            _SongInfoLog.Error(exception, text, propertyValues);
+        }
+        public static void LogSongError(string text, params object[] propertyValues)
+        {
+            _SongInfoLog.Error(text, propertyValues);
+        }
+
+        public static void LogSongWaring(string text, params object[] propertyValues)
+        {
+            _SongInfoLog.Warning(text, propertyValues);
+        }
+
+        #region Log rolling
+
+        private static void _RollLogs(string mainLogFile, int numLogsToKeep)
+        {
+            _DeleteOldLogs(mainLogFile, numLogsToKeep);
+
+            string currentSourceFile = _GenerateRollLogFileName(mainLogFile, numLogsToKeep);
+            
+
+            for (var i = numLogsToKeep; i > 1; i--)
+            {
+                string currentTargetFile = currentSourceFile;
+                currentSourceFile = _GenerateRollLogFileName(mainLogFile, i - 1);
+
+                if (File.Exists(currentSourceFile))
+                {
+                    try
+                    {
+                        File.Move(currentSourceFile, currentTargetFile);
+                    }
+                    catch (Exception)
+                    {
+                        // Cant log anything here as the log isn't initialized yet
+                    }
+                }
+            }
+
+            if (File.Exists(mainLogFile))
+            {
+                try { 
+                    if(numLogsToKeep > 0) 
+                        File.Move(mainLogFile, currentSourceFile);
+                    else
+                        File.Delete(mainLogFile);
+                    }
+                catch (Exception)
+                {
+                    // Cant log anything here as the log isn't initialized yet
+                }
+            }
+        }
+
+        private static void _DeleteOldLogs(string mainLogFile, int numLogsToKeep)
+        {
+            Regex r = new Regex($"{Path.GetDirectoryName(mainLogFile)}\\\\{Path.GetFileNameWithoutExtension(mainLogFile)}_([0-9]+){Path.GetExtension(mainLogFile)}", RegexOptions.IgnoreCase);
+            IEnumerable<string> logFiles = Directory.EnumerateFiles($"{Path.GetDirectoryName(mainLogFile)}", $"{Path.GetFileNameWithoutExtension(mainLogFile)}*{Path.GetExtension(mainLogFile)}");
+            foreach (string file in logFiles)
+            {
+                Match m = r.Match(file);
+                if (m.Success)
+                {
+                    int logNum = -1;
+                    Int32.TryParse(m.Groups[1].Value, out logNum);
+
+                    if (logNum < 0 || logNum > numLogsToKeep - 1)
+                    {
+                        try
+                        {
+                            File.Delete(file);
+                        }
+                        catch (Exception)
+                        {
+                            // Cant log anything here as the log isn't initialized yet
+                        }
+
+                    }
+                }
+            }
+        }
+
+        private static string _GenerateRollLogFileName(string mainLogFile, int number)
+        {
+            return $"{Path.GetDirectoryName(mainLogFile)}\\{Path.GetFileNameWithoutExtension(mainLogFile)}_{number}{Path.GetExtension(mainLogFile)}";
+        }
+
+        #endregion
+
+        #region CTimeStampFromStartEnricher
+
+        // ReSharper disable once InconsistentNaming
+        private static LoggerConfiguration WithTimeStampFromStart(this LoggerEnrichmentConfiguration enrich)
+        {
+            return enrich.With(new CTimeStampFromStartEnricher());
+        }
+
+        private class CTimeStampFromStartEnricher : ILogEventEnricher
+        {
+            private readonly DateTimeOffset _Start  = DateTimeOffset.Now;
+
+            public void Enrich(LogEvent logEvent, ILogEventPropertyFactory lepf)
+            {
+                logEvent.AddPropertyIfAbsent(
+                    lepf.CreateProperty("TimeStampFromStart", logEvent.Timestamp - _Start));
+            }
+        }
+
+        #endregion
     }
 }

Vocaluxe/Base/CMain.cs

@@ -19,6 +19,7 @@ using System;
 using System.Collections.Generic;
 using System.Collections.ObjectModel;
 using System.Drawing;
+using System.Runtime.CompilerServices;
 using Vocaluxe.Base.Fonts;
 using Vocaluxe.Base.ThemeSystem;
 using VocaluxeLib;
@@ -507,21 +508,38 @@ namespace Vocaluxe.Base
         }
     }
 
+    // ReSharper disable ExplicitCallerInfoArgument
     class CBlog : ILog
     {
-        public void LogError(string errorText, bool showMsg = false, bool exit = false)
+        public void LogError(Exception exeption, string errorText, bool showMsg = false, bool exit = false, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
         {
-            CLog.LogError(errorText, showMsg, exit);
+            CLog.LogError(exeption, errorText, showMsg, exit, callerMethodeName, callerFilePath, callerLineNumer, propertyValues);
         }
 
-        public void LogDebug(string text)
+        public void LogError(string errorText, bool showMsg = false, bool exit = false, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
         {
-            CLog.LogDebug(text);
+            CLog.LogError(null, errorText, showMsg, exit, callerMethodeName, callerFilePath, callerLineNumer, propertyValues);
         }
 
-        public void LogSongInfo(string text)
+        public void LogDebug(string text, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues)
         {
-            CLog.LogSongInfo(text);
+            
+            CLog.LogDebug(text, callerMethodeName, callerFilePath, callerLineNumer, propertyValues);
+        }
+
+        public void LogSongWarning(string text, params object[] propertyValues)
+        {
+            CLog.LogSongWaring(text, propertyValues);
+        }
+
+        public void LogSongError(Exception exception, string text, params object[] propertyValues)
+        {
+            CLog.LogSongError(exception, text, propertyValues);
+        }
+
+        public void LogSongError(string text, params object[] propertyValues)
+        {
+            CLog.LogSongError(text, propertyValues);
         }
     }
 

Vocaluxe/Base/CSettings.cs

@@ -111,11 +111,8 @@ namespace Vocaluxe.Base
         public const string FileNameOldHighscoreDB = "Ultrastar.db";
         public const string FileNameCoverDB = "CoverDB.sqlite";
         public const string FileNameCreditsRessourcesDB = "CreditsRessourcesDB.sqlite";
-
-        public const string FileNamePerformanceLog = "Performance.log";
-        public const string FileNameErrorLog = "Error.log";
-        public const string FileNameBenchmarkLog = "Benchmark.log";
-        public const string FileNameDebugLog = "Debug.log";
+        
+        public const string FileNameMainLog = "Vocaluxe.log";
         public const string FileNameSongInfoLog = "SongInformation.log";
 
         public const string FileNameRequiredSkinElements = "RequiredSkinElements.xml";
@@ -135,6 +132,7 @@ namespace Vocaluxe.Base
         public const string FolderNameLanguages = "Languages";
         public const string FolderNameScreenshots = "Screenshots";
         public const string FolderNameBackgroundMusic = "BackgroundMusic";
+        public const string FolderNameLogs = "Logs";
 
         public const string FolderNamePartyModes = "PartyModes";
         public const string FolderNamePartyModeCode = "Code";

Vocaluxe/Base/CSongs.cs

@@ -22,6 +22,8 @@ using System.Linq;
 using System.Threading;
 using System.IO;
 using System.Threading.Tasks;
+using Serilog.Events;
+using SerilogTimings;
 using VocaluxeLib;
 using VocaluxeLib.Songs;
 
@@ -333,54 +335,65 @@ namespace Vocaluxe.Base
 
         public static void LoadSongs()
         {
-            CLog.StartBenchmark("Load Songs");
-            SongsLoaded = false;
-            _Songs.Clear();
-
-            CLog.StartBenchmark("List Songs");
-            var files = new List<string>();
-            foreach (string p in CConfig.SongFolders)
+            CLog.LogInformation("Load Songs");
+            using (Operation.At(LogEventLevel.Information).Time("Load Songs"))
             {
-                if (Directory.Exists(p))
+                SongsLoaded = false;
+                _Songs.Clear();
+
+                var files = new List<string>();
+
+                CLog.LogInformation("List Songs");
+                using (Operation.At(LogEventLevel.Information).Time("List Songs"))
                 {
-                    string path = p;
-                    files.AddRange(CHelper.ListFiles(path, "*.txt", true, true));
-                    files.AddRange(CHelper.ListFiles(path, "*.txd", true, true));
+                    
+                    foreach (string p in CConfig.SongFolders)
+                    {
+                        if (Directory.Exists(p))
+                        {
+                            string path = p;
+                            files.AddRange(CHelper.ListFiles(path, "*.txt", true, true));
+                            files.AddRange(CHelper.ListFiles(path, "*.txd", true, true));
+                        }
+                    }
+                }
+
+                CLog.LogInformation("Read TXTs");
+                using (Operation.At(LogEventLevel.Information).Time("Read TXTs"))
+                {
+                    foreach (string file in files)
+                    {
+                        CSong song = CSong.LoadSong(file);
+                        if (song == null)
+                            continue;
+                        song.ID = _Songs.Count;
+                        if (song.LoadNotes())
+                            _Songs.Add(song);
+                    }
+                }
+
+                CLog.LogInformation("Sort Songs");
+                using (Operation.At(LogEventLevel.Information).Time("Sorted Songs"))
+                {
+                    Sorter.SongSorting = CConfig.Config.Game.SongSorting;
+                    Sorter.IgnoreArticles = CConfig.Config.Game.IgnoreArticles;
+                    Categorizer.Tabs = CConfig.Config.Game.Tabs;
+                    Categorizer.ObjectChanged += _HandleCategoriesChanged;
+                }
+
+                Category = -1;
+                SongsLoaded = true;
+
+                switch (CConfig.Config.Theme.CoverLoading)
+                {
+                    case ECoverLoading.TR_CONFIG_COVERLOADING_ATSTART:
+                        _LoadCovers();
+                        break;
+                    case ECoverLoading.TR_CONFIG_COVERLOADING_DYNAMIC:
+                        _LoadCoversAsync();
+                        break;
                 }
             }
-            CLog.StopBenchmark("List Songs");
-
-            CLog.StartBenchmark("Read TXTs");
-            foreach (string file in files)
-            {
-                CSong song = CSong.LoadSong(file);
-                if (song == null)
-                    continue;
-                song.ID = _Songs.Count;
-                if (song.LoadNotes())
-                    _Songs.Add(song);
-            }
-            CLog.StopBenchmark("Read TXTs");
-
-            CLog.StartBenchmark("Sort Songs");
-            Sorter.SongSorting = CConfig.Config.Game.SongSorting;
-            Sorter.IgnoreArticles = CConfig.Config.Game.IgnoreArticles;
-            Categorizer.Tabs = CConfig.Config.Game.Tabs;
-            Categorizer.ObjectChanged += _HandleCategoriesChanged;
-            CLog.StopBenchmark("Sort Songs");
-            Category = -1;
-            SongsLoaded = true;
-
-            switch (CConfig.Config.Theme.CoverLoading)
-            {
-                case ECoverLoading.TR_CONFIG_COVERLOADING_ATSTART:
-                    _LoadCovers();
-                    break;
-                case ECoverLoading.TR_CONFIG_COVERLOADING_DYNAMIC:
-                    _LoadCoversAsync();
-                    break;
-            }
-            CLog.StopBenchmark("Load Songs");
         }
 
         private static void _LoadCoversAsync()
@@ -396,25 +409,28 @@ namespace Vocaluxe.Base
 
         private static void _LoadCovers()
         {
-            CLog.StartBenchmark("Load Covers");
-            int songCount = _Songs.Count;
-            AutoResetEvent ev = new AutoResetEvent(songCount == 0);
-
-            NumSongsWithCoverLoaded = 0;
-            foreach (CSong song in _Songs)
+            CLog.LogInformation("Load Covers");
+            using (Operation.At(LogEventLevel.Information).Time("Loaded Covers"))
             {
-                CSong tmp = song;
-                Task.Factory.StartNew(() =>
+                int songCount = _Songs.Count;
+                AutoResetEvent ev = new AutoResetEvent(songCount == 0);
+
+                NumSongsWithCoverLoaded = 0;
+                foreach (CSong song in _Songs)
+                {
+                    CSong tmp = song;
+                    Task.Factory.StartNew(() =>
                     {
                         tmp.LoadSmallCover();
                         if (Interlocked.Increment(ref _NumSongsWithCoverLoaded) >= songCount)
                             ev.Set();
                     });
+                }
+
+                ev.WaitOne();
+                _CoverLoaded = true;
+                CDataBase.CommitCovers();
             }
-            ev.WaitOne();
-            _CoverLoaded = true;
-            CDataBase.CommitCovers();
-            CLog.StopBenchmark("Load Covers");
         }
     }
 }

Vocaluxe/Base/Fonts/CFonts.cs

@@ -21,6 +21,8 @@ using System.Diagnostics;
 using System.Drawing;
 using System.IO;
 using System.Linq;
+using Serilog.Events;
+using SerilogTimings;
 using VocaluxeLib;
 using VocaluxeLib.Menu;
 using VocaluxeLib.Xml;
@@ -217,7 +219,7 @@ namespace Vocaluxe.Base.Fonts
                 }
             }
             else
-                CLog.LogError("Empty fontName requested", false, false, new Exception());
+                CLog.LogError("Empty fontName requested");
 
             if (_FontFamilies.Count == 0)
                 CLog.LogError("No fonts found!", true, true);
@@ -265,7 +267,7 @@ namespace Vocaluxe.Base.Fonts
             }
             catch (Exception e)
             {
-                CLog.LogError("Error loading default Fonts", false, false, e);
+                CLog.LogError(e, "Error loading default Fonts");
                 return false;
             }
 
@@ -287,9 +289,13 @@ namespace Vocaluxe.Base.Fonts
                     return false;
                 }
             }
-            CLog.StartBenchmark("BuildGlyphs");
-            _BuildGlyphs();
-            CLog.StopBenchmark("BuildGlyphs");
+
+            CLog.LogInformation("Build Glyphs");
+            using (Operation.At(LogEventLevel.Information).Time("Build Glyphs"))
+            {
+                _BuildGlyphs();
+            }
+
             return true;
         }
 

Vocaluxe/Base/ThemeSystem/CSkin.cs

@@ -147,7 +147,7 @@ namespace Vocaluxe.Base.ThemeSystem
             }
             catch (Exception e)
             {
-                CLog.LogError("Can't load skin file \"" + Path.Combine(_Folder, _FileName) + "\". Invalid file!", false, false, e);
+                CLog.LogError(e, "Can't load skin file \"" + Path.Combine(_Folder, _FileName) + "\". Invalid file!");
                 return false;
             }
 

Vocaluxe/Base/ThemeSystem/CTheme.cs

@@ -80,7 +80,7 @@ namespace Vocaluxe.Base.ThemeSystem
             }
             catch (Exception e)
             {
-                CLog.LogError("Can't load theme \"" + _FileName + "\". Invalid file!", false, false, e);
+                CLog.LogError(e, "Can't load theme \"" + _FileName + "\". Invalid file!");
                 return false;
             }
 

Vocaluxe/Lib/Draw/CDirect3D.cs

@@ -94,7 +94,7 @@ namespace Vocaluxe.Lib.Draw
             }
             catch (Direct3DX9NotFoundException e)
             {
-                CLog.LogError("No DirectX runtimes were found, please download and install them from http://www.microsoft.com/download/en/details.aspx?id=8109", true, true, e);
+                CLog.LogError(e, "No DirectX runtimes were found, please download and install them from http://www.microsoft.com/download/en/details.aspx?id=8109");
             }
 
             _Form.KeyDown += _OnKeyDown;
@@ -177,7 +177,7 @@ namespace Vocaluxe.Lib.Draw
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during D3D device creation.", false, false, e);
+                CLog.LogError(e, "Error during D3D device creation.");
             }
             finally
             {

Vocaluxe/Lib/Sound/CPortAudioHandle.cs

@@ -86,7 +86,7 @@ namespace Vocaluxe.Lib.Sound
                     }
                     catch (Exception ex)
                     {
-                        CLog.LogError(errorText: $"Error disposing PortAudio: {ex.Message}", e: ex);
+                        CLog.LogError(ex, "Error disposing PortAudio");
                     }
                 }
                 _Disposed = true;
@@ -179,7 +179,7 @@ namespace Vocaluxe.Lib.Sound
                 }
                 catch (Exception ex)
                 {
-                    CLog.LogError(errorText:$"Error closing stream: {ex.Message}", e:ex);
+                    CLog.LogError(ex, "Error closing stream:");
                 }
                 _Streams.Remove(stream);
             }

Vocaluxe/Lib/Video/Acinerella/CDecoderThread.cs

@@ -437,7 +437,7 @@ namespace Vocaluxe.Lib.Video.Acinerella
             }
             catch (Exception e)
             {
-                CLog.LogError("Couldn't copy the frame to the managed environment.", false, false, e);
+                CLog.LogError(e, "Couldn't copy the frame to the managed environment.");
                 return false;
             }
             

Vocaluxe/Program.cs

@@ -24,6 +24,8 @@ using System.Runtime.CompilerServices;
 using System.Runtime.ExceptionServices;
 using System.Threading;
 using System.Windows.Forms;
+using Serilog.Events;
+using SerilogTimings;
 using Vocaluxe.Base;
 using Vocaluxe.Base.Fonts;
 using Vocaluxe.Base.Server;
@@ -96,170 +98,210 @@ namespace Vocaluxe
                 Directory.CreateDirectory(CSettings.DataFolder);
 
                 // Init Log
-                CLog.Init();
+                CLog.Init(CSettings.FolderNameLogs);
 
                 if (!CProgrammHelper.CheckRequirements())
                     return;
                 CProgrammHelper.Init();
 
-                CLog.StartBenchmark("Init Program");
-                CMain.Init();
-                Application.DoEvents();
+                CLog.LogInformation("Init Program");
+                using (Operation.At(LogEventLevel.Information).Time("Init Program"))
+                {
+                    CMain.Init();
+                    Application.DoEvents();
 
-                // Init Language
-                CLog.StartBenchmark("Init Language");
-                if (!CLanguage.Init())
-                    throw new CLoadingException("Language");
-                CLog.StopBenchmark("Init Language");
+                    // Init Language
+                    CLog.LogInformation("Init Language");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Language"))
+                    {
+                        if (!CLanguage.Init())
+                            throw new CLoadingException("Language");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // load config
-                CLog.StartBenchmark("Init Config");
-                CConfig.LoadCommandLineParams(args);
-                CConfig.UseCommandLineParamsBefore();
-                CConfig.Init();
-                CConfig.UseCommandLineParamsAfter();
-                CLog.StopBenchmark("Init Config");
+                    // load config
+                    CLog.LogInformation("Init Config");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Config"))
+                    {
+                        CConfig.LoadCommandLineParams(args);
+                        CConfig.UseCommandLineParamsBefore();
+                        CConfig.Init();
+                        CConfig.UseCommandLineParamsAfter();
+                    }
 
-                // Create folders
-                CSettings.CreateFolders();
+                    // Create folders
+                    CSettings.CreateFolders();
 
-                _SplashScreen = new CSplashScreen();
-                Application.DoEvents();
+                    _SplashScreen = new CSplashScreen();
+                    Application.DoEvents();
 
-                // Init Draw
-                CLog.StartBenchmark("Init Draw");
-                if (!CDraw.Init())
-                    throw new CLoadingException("drawing");
-                CLog.StopBenchmark("Init Draw");
+                    // Init Draw
+                    CLog.LogInformation("Init Draw");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Draw"))
+                    {
+                        if (!CDraw.Init())
+                            throw new CLoadingException("drawing");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Playback
-                CLog.StartBenchmark("Init Playback");
-                if (!CSound.Init())
-                    throw new CLoadingException("playback");
-                CLog.StopBenchmark("Init Playback");
+                    // Init Playback
+                    CLog.LogInformation("Init Playback");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Playback"))
+                    {
+                        if (!CSound.Init())
+                            throw new CLoadingException("playback");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Record
-                CLog.StartBenchmark("Init Record");
-                if (!CRecord.Init())
-                    throw new CLoadingException("record");
-                CLog.StopBenchmark("Init Record");
+                    // Init Record
+                    CLog.LogInformation("Init Record");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Record"))
+                    {
+                        if (!CRecord.Init())
+                            throw new CLoadingException("record");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init VideoDecoder
-                CLog.StartBenchmark("Init Videodecoder");
-                if (!CVideo.Init())
-                    throw new CLoadingException("video");
-                CLog.StopBenchmark("Init Videodecoder");
+                    // Init VideoDecoder
+                    CLog.LogInformation("Init Videodecoder");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Videodecoder"))
+                    {
+                        if (!CVideo.Init())
+                            throw new CLoadingException("video");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Database
-                CLog.StartBenchmark("Init Database");
-                if (!CDataBase.Init())
-                    throw new CLoadingException("database");
-                CLog.StopBenchmark("Init Database");
+                    // Init Database
+                    CLog.LogInformation("Init Database");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Database"))
+                    {
+                        if (!CDataBase.Init())
+                            throw new CLoadingException("database");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                //Init Webcam
-                CLog.StartBenchmark("Init Webcam");
-                if (!CWebcam.Init())
-                    throw new CLoadingException("webcam");
-                CLog.StopBenchmark("Init Webcam");
+                    //Init Webcam
+                    CLog.LogInformation("Init Webcam");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Webcam"))
+                    {
+                        if (!CWebcam.Init())
+                            throw new CLoadingException("webcam");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Background Music
-                CLog.StartBenchmark("Init Background Music");
-                CBackgroundMusic.Init();
-                CLog.StopBenchmark("Init Background Music");
+                    // Init Background Music
+                    CLog.LogInformation("Init Background Music");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Background Music"))
+                    {
+                        CBackgroundMusic.Init();
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Profiles
-                CLog.StartBenchmark("Init Profiles");
-                CProfiles.Init();
-                CLog.StopBenchmark("Init Profiles");
+                    // Init Profiles
+                    CLog.LogInformation("Init Profiles");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Profiles"))
+                    {
+                        CProfiles.Init();
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Fonts
-                CLog.StartBenchmark("Init Fonts");
-                if (!CFonts.Init())
-                    throw new CLoadingException("fonts");
-                CLog.StopBenchmark("Init Fonts");
+                    // Init Fonts
+                    CLog.LogInformation("Init Fonts");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Fonts"))
+                    {
+                        if (!CFonts.Init())
+                            throw new CLoadingException("fonts");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Theme System
-                CLog.StartBenchmark("Init Theme");
-                if (!CThemes.Init())
-                    throw new CLoadingException("theme");
-                CLog.StopBenchmark("Init Theme");
+                    // Theme System
+                    CLog.LogInformation("Init Theme");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Theme"))
+                    {
+                        if (!CThemes.Init())
+                            throw new CLoadingException("theme");
+                    }
 
-                CLog.StartBenchmark("Load Theme");
-                CThemes.Load();
-                CLog.StopBenchmark("Load Theme");
+                    CLog.LogInformation("Load Theme");
+                    using (Operation.At(LogEventLevel.Information).Time("Load Theme"))
+                    {
+                        CThemes.Load();
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Load Cover
-                CLog.StartBenchmark("Init Cover");
-                if (!CCover.Init())
-                    throw new CLoadingException("covertheme");
-                CLog.StopBenchmark("Init Cover");
+                    // Load Cover
+                    CLog.LogInformation("Init Cover");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Cover"))
+                    {
+                        if (!CCover.Init())
+                            throw new CLoadingException("covertheme");
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Screens
-                CLog.StartBenchmark("Init Screens");
-                CGraphics.Init();
-                CLog.StopBenchmark("Init Screens");
+                    // Init Screens
+                    CLog.LogInformation("Init Screens");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Screens"))
+                    {
+                        CGraphics.Init();
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Server
-                CLog.StartBenchmark("Init Server");
-                CVocaluxeServer.Init();
-                CLog.StopBenchmark("Init Server");
+                    // Init Server
+                    CLog.LogInformation("Init Server");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Server"))
+                    {
+                        CVocaluxeServer.Init();
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Input
-                CLog.StartBenchmark("Init Input");
-                CController.Init();
-                CController.Connect();
-                CLog.StopBenchmark("Init Input");
+                    // Init Input
+                    CLog.LogInformation("Init Input");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Input"))
+                    {
+                        CController.Init();
+                        CController.Connect();
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Game;
-                CLog.StartBenchmark("Init Game");
-                CGame.Init();
-                CProfiles.Update();
-                CConfig.UsePlayers();
-                CLog.StopBenchmark("Init Game");
+                    // Init Game;
+                    CLog.LogInformation("Init Game");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Game"))
+                    {
+                        CGame.Init();
+                        CProfiles.Update();
+                        CConfig.UsePlayers();
+                    }
 
-                Application.DoEvents();
+                    Application.DoEvents();
 
-                // Init Party Modes;
-                CLog.StartBenchmark("Init Party Modes");
-                if (!CParty.Init())
-                    throw new CLoadingException("Party Modes");
-                CLog.StopBenchmark("Init Party Modes");
+                    // Init Party Modes;
+                    CLog.LogInformation("Init Party Modes");
+                    using (Operation.At(LogEventLevel.Information).Time("Init Party Modes"))
+                    {
+                        if (!CParty.Init())
+                            throw new CLoadingException("Party Modes");
+                    }
 
-                Application.DoEvents();
-                //Only reasonable point to call GC.Collect() because initialization may cause lots of garbage
-                //Rely on GC doing its job afterwards and call Dispose methods where appropriate
-                GC.Collect();
-                CLog.StopBenchmark("Init Program");
+                    Application.DoEvents();
+                    //Only reasonable point to call GC.Collect() because initialization may cause lots of garbage
+                    //Rely on GC doing its job afterwards and call Dispose methods where appropriate
+                    GC.Collect();
+                }
             }
             catch (Exception e)
             {
@@ -288,7 +330,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CController)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CController)");
             }
 
             try
@@ -297,7 +339,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CVocaluxeServer)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CVocaluxeServer)");
             }
 
             try
@@ -306,7 +348,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CGraphics)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CGraphics)");
             }
 
             try
@@ -315,7 +357,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CThemes)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CThemes)");
             }
 
             try
@@ -324,7 +366,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CCover)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CCover)");
             }
 
             try
@@ -333,7 +375,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CFonts)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CFonts)");
             }
 
             try
@@ -342,7 +384,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CBackgroundMusic)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CBackgroundMusic)");
             }
 
             try
@@ -351,7 +393,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CWebcam)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CWebcam)");
             }
 
             try
@@ -360,7 +402,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CDataBase)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CDataBase)");
             }
 
             try
@@ -369,7 +411,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CVideo)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CVideo)");
             }
 
             try
@@ -378,7 +420,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CRecord)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CRecord)");
             }
 
             try
@@ -387,7 +429,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CSound)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CSound)");
             }
 
             try
@@ -396,7 +438,7 @@ namespace Vocaluxe
             }
             catch (Exception e)
             {
-                CLog.LogError("Error during shutdown! (CDraw)", false, false, e);
+                CLog.LogError(e, "Error during shutdown! (CDraw)");
             }
 
             GC.Collect(); // Do a GC run here before we close logs to have finalizers run

Vocaluxe/Properties/AssemblyInfo.cs

@@ -27,7 +27,7 @@ using System.Runtime.InteropServices;
 [assembly: AssemblyConfiguration("")]
 [assembly: AssemblyCompany("")]
 [assembly: AssemblyProduct("Vocaluxe")]
-[assembly: AssemblyCopyright("Copyright © 2017")]
+[assembly: AssemblyCopyright("Copyright © 2018")]
 [assembly: AssemblyTrademark("")]
 [assembly: AssemblyCulture("")]
 

Vocaluxe/Screens/CScreenLoad.cs

@@ -15,8 +15,11 @@
 // along with Vocaluxe. If not, see <http://www.gnu.org/licenses/>.
 #endregion
 
+using System;
 using System.Threading;
 using System.Windows.Forms;
+using Serilog.Events;
+using SerilogTimings;
 using Vocaluxe.Base;
 using VocaluxeLib;
 using VocaluxeLib.Menu;
@@ -42,6 +45,8 @@ namespace Vocaluxe.Screens
         private bool _IntroOutPlayed;
         private CVideoPlayer[] _Intros;
 
+        private IDisposable _TimerLoadSongsFull;
+
         public override void Init()
         {
             base.Init();
@@ -123,7 +128,9 @@ namespace Vocaluxe.Screens
                     videoPlayer.PreLoad();
             }
 
-            CLog.StartBenchmark("Load Songs Full");
+            CLog.LogInformation("Load Songs Full");
+            _TimerLoadSongsFull = Operation.At(LogEventLevel.Information).Time("Loaded Songs Full");
+            
             _SongLoaderThread = new Thread(CSongs.LoadSongs) {Name = "SongLoader", IsBackground = true};
             _SongLoaderThread.Start();
             CBackgroundMusic.OwnSongsAvailable = false;
@@ -176,12 +183,15 @@ namespace Vocaluxe.Screens
             foreach (CVideoPlayer videoPlayer in _Intros)
                 videoPlayer.Close();
 
-            CLog.StopBenchmark("Load Songs Full");
+            // Stop the song full load timer
+            _TimerLoadSongsFull.Dispose();
 
             //Init Playlists
-            CLog.StartBenchmark("Init Playlists");
-            CPlaylists.Init();
-            CLog.StopBenchmark("Init Playlists");
+            CLog.LogInformation("Init Playlists");
+            using (Operation.At(LogEventLevel.Information).Time("Init Playlists"))
+            {
+                CPlaylists.Init();
+            }
         }
 
         private void _CheckStartIntroVideos()

Vocaluxe/Vocaluxe.csproj

@@ -158,6 +158,35 @@
     <DebugSymbols>true</DebugSymbols>
   </PropertyGroup>
   <ItemGroup>
+    <Reference Include="Microsoft.CSharp" />
+    <Reference Include="Serilog, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10, processorArchitecture=MSIL">
+      <HintPath>..\packages\Serilog.2.5.0\lib\net46\Serilog.dll</HintPath>
+      <Private>True</Private>
+    </Reference>
+    <Reference Include="Serilog.Enrichers.Thread, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10, processorArchitecture=MSIL">
+      <HintPath>..\packages\Serilog.Enrichers.Thread.3.0.0\lib\net45\Serilog.Enrichers.Thread.dll</HintPath>
+      <Private>True</Private>
+    </Reference>
+    <Reference Include="Serilog.Formatting.Compact, Version=1.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10, processorArchitecture=MSIL">
+      <HintPath>..\packages\Serilog.Formatting.Compact.1.0.0\lib\net45\Serilog.Formatting.Compact.dll</HintPath>
+      <Private>True</Private>
+    </Reference>
+    <Reference Include="Serilog.Sinks.Console, Version=3.1.1.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10, processorArchitecture=MSIL">
+      <HintPath>..\packages\Serilog.Sinks.Console.3.1.1\lib\net45\Serilog.Sinks.Console.dll</HintPath>
+      <Private>True</Private>
+    </Reference>
+    <Reference Include="Serilog.Sinks.File, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10, processorArchitecture=MSIL">
+      <HintPath>..\packages\Serilog.Sinks.File.3.1.0\lib\net45\Serilog.Sinks.File.dll</HintPath>
+      <Private>True</Private>
+    </Reference>
+    <Reference Include="Serilog.Sinks.TextWriter, Version=2.0.0.0, Culture=neutral, PublicKeyToken=24c2f752a8e58a10, processorArchitecture=MSIL">
+      <HintPath>..\packages\Serilog.Sinks.TextWriter.2.1.0\lib\net45\Serilog.Sinks.TextWriter.dll</HintPath>
+      <Private>True</Private>
+    </Reference>
+    <Reference Include="SerilogTimings, Version=2.2.0.0, Culture=neutral, PublicKeyToken=ea6fc7d88906f03a, processorArchitecture=MSIL">
+      <HintPath>..\packages\SerilogTimings.2.2.0\lib\net45\SerilogTimings.dll</HintPath>
+      <Private>True</Private>
+    </Reference>
     <Reference Include="System" />
     <Reference Include="System.Data" />
     <Reference Include="System.Drawing" />

Vocaluxe/packages.config

@@ -1,5 +1,12 @@
 <?xml version="1.0" encoding="utf-8"?>
 <packages>
+  <package id="Serilog" version="2.5.0" targetFramework="net471" />
+  <package id="Serilog.Enrichers.Thread" version="3.0.0" targetFramework="net471" />
+  <package id="Serilog.Formatting.Compact" version="1.0.0" targetFramework="net471" />
+  <package id="Serilog.Sinks.Console" version="3.1.1" targetFramework="net471" />
+  <package id="Serilog.Sinks.File" version="3.1.0" targetFramework="net471" />
+  <package id="Serilog.Sinks.TextWriter" version="2.1.0" targetFramework="net471" />
+  <package id="SerilogTimings" version="2.2.0" targetFramework="net471" />
   <package id="vocaluxe.dependencies" version="1.0.11" targetFramework="net40" />
   <package id="vocaluxe.dependencies.acinerella" version="1.0.5" targetFramework="net40" />
   <package id="vocaluxe.dependencies.aforgevideo" version="1.0.1" targetFramework="net40" />

VocaluxeLib/IBasic.cs

@@ -19,6 +19,7 @@ using System;
 using System.Collections.Generic;
 using System.Collections.ObjectModel;
 using System.Drawing;
+using System.Runtime.CompilerServices;
 using VocaluxeLib.Draw;
 using VocaluxeLib.Game;
 using VocaluxeLib.Menu;
@@ -167,9 +168,12 @@ namespace VocaluxeLib
 
     public interface ILog
     {
-        void LogError(string errorText, bool showMsg = false, bool exit = false);
-        void LogDebug(string text);
-        void LogSongInfo(string text);
+        void LogError(Exception exeption, string errorText, bool showMsg = false, bool exit = false, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues);
+        void LogError(string errorText, bool showMsg = false, bool exit = false, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues);
+        void LogDebug(string text, [CallerMemberName] string callerMethodeName = "", [CallerFilePath] string callerFilePath = "", [CallerLineNumber] int callerLineNumer = -1, params object[] propertyValues);
+        void LogSongWarning(string text, params object[] propertyValues);
+        void LogSongError(Exception exception, string text, params object[] propertyValues);
+        void LogSongError(string text, params object[] propertyValues);
     }
 
     public interface IFonts

VocaluxeLib/Songs/CSongLoader.cs

@@ -69,30 +69,7 @@ namespace VocaluxeLib.Songs
                 _Song.FileName = Path.GetFileName(filePath);
                 return true;
             }
-
-            /// <summary>
-            ///     Logs a given message with file name and line#
-            /// </summary>
-            /// <param name="msg">Message</param>
-            /// <param name="error">True prepends "Error: "; False prepends "Warning: "</param>
-            /// <param name="withLineNr">Adds line#</param>
-            private void _LogMsg(string msg, bool error, bool withLineNr)
-            {
-                msg = (error ? "Error: " : "Warning: ") + msg;
-                if (withLineNr)
-                    msg += " in line #" + _LineNr;
-                CBase.Log.LogSongInfo(msg + " (" + Path.Combine(_Song.Folder, _Song.FileName) + ")");
-            }
-
-            private void _LogError(string msg, bool withLineNr = true)
-            {
-                _LogMsg(msg, true, withLineNr);
-            }
-
-            private void _LogWarning(string msg, bool withLineNr = true)
-            {
-                _LogMsg(msg, false, withLineNr);
-            }
+            
 
             public bool ReadHeader(bool useSetEncoding = false)
             {
@@ -144,7 +121,8 @@ namespace VocaluxeLib.Songs
                         if (value == "")
                         {
                             _Song.UnknownTags.Add(line);
-                            _LogWarning("Empty value skipped");
+                            CBase.Log.LogSongWarning("[{SongFileName}] Empty value skipped", _Song.FileName);
+                           
                             continue;
                         }
 
@@ -157,7 +135,7 @@ namespace VocaluxeLib.Songs
                                 {
                                     if (useSetEncoding)
                                     {
-                                        _LogWarning("Duplicate encoding ignored");
+                                        CBase.Log.LogSongWarning("[{SongFileName}] Duplicate encoding ignored", _Song.FileName);
                                         continue;
                                     }
                                     sr.Dispose();
@@ -203,7 +181,7 @@ namespace VocaluxeLib.Songs
                                 }
                                 else
                                 {
-                                    _LogError("Can't find audio file: " + Path.Combine(_Song.Folder, value));
+                                    CBase.Log.LogSongError("[{SongFileName}] Can't find audio file: {AudioFile}", _Song.FileName, Path.Combine(_Song.Folder, value));
                                     return false;
                                 }
                                 break;
@@ -214,19 +192,19 @@ namespace VocaluxeLib.Songs
                                     headerFlags |= EHeaderFlags.BPM;
                                 }
                                 else
-                                    _LogWarning("Invalid BPM value");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid BPM value: {Value}", _Song.FileName, value);
                                 break;
                             case "EDITION":
                                 if (value.Length > 1)
                                     _Song.Editions.Add(value);
                                 else
-                                    _LogWarning("Invalid edition");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid edition: {Value}", _Song.FileName, value);
                                 break;
                             case "GENRE":
                                 if (value.Length > 1)
                                     _Song.Genres.Add(value);
                                 else
-                                    _LogWarning("Invalid genre");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid genre: {Value}", _Song.FileName, value);
                                 break;
                             case "ALBUM":
                                 _Song.Album = value;
@@ -236,13 +214,13 @@ namespace VocaluxeLib.Songs
                                 if (value.Length == 4 && int.TryParse(value, out num) && num > 0)
                                     _Song.Year = value;
                                 else
-                                    _LogWarning("Invalid year");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid year: {Value}", _Song.FileName, value);
                                 break;
                             case "LANGUAGE":
                                 if (value.Length > 1)
                                     _Song.Languages.Add(_UnifyLanguage(value));
                                 else
-                                    _LogWarning("Invalid language");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid language: {Value}", _Song.FileName, value);
                                 break;
                             case "COMMENT":
                                 if (!String.IsNullOrEmpty(_Song._Comment))
@@ -253,49 +231,49 @@ namespace VocaluxeLib.Songs
                                 if (CHelper.TryParse(value, out _Song.Gap))
                                     _Song.Gap /= 1000f;
                                 else
-                                    _LogWarning("Invalid gap");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid gap: {Value}", _Song.FileName, value);
                                 break;
                             case "COVER":
                                 if (File.Exists(Path.Combine(_Song.Folder, value)))
                                     _Song.CoverFileName = value;
                                 else
-                                    _LogWarning("Can't find cover file: " + Path.Combine(_Song.Folder, value));
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Can't find cover file: {MissingFile}", _Song.FileName, Path.Combine(_Song.Folder, value));
                                 break;
                             case "BACKGROUND":
                                 if (File.Exists(Path.Combine(_Song.Folder, value)))
                                     _Song.BackgroundFileNames.Add(value);
                                 else
-                                    _LogWarning("Can't find background file: " + Path.Combine(_Song.Folder, value));
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Can't find background file: {MissingFile}", _Song.FileName, Path.Combine(_Song.Folder, value));
                                 break;
                             case "VIDEO":
                                 if (File.Exists(Path.Combine(_Song.Folder, value)))
                                     _Song.VideoFileName = value;
                                 else
-                                    _LogWarning("Can't find video file: " + Path.Combine(_Song.Folder, value));
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Can't find video file: {MissingFile}", _Song.FileName, Path.Combine(_Song.Folder, value));
                                 break;
                             case "VIDEOGAP":
                                 if (!CHelper.TryParse(value, out _Song.VideoGap))
-                                    _LogWarning("Invalid videogap");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid videogap: {Value}", _Song.FileName, value);
                                 break;
                             case "VIDEOASPECT":
                                 if (!CHelper.TryParse(value, out _Song.VideoAspect, true))
-                                    _LogWarning("Invalid videoaspect");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid videoaspect: {Value}", _Song.FileName, value);
                                 break;
                             case "START":
                                 if (!CHelper.TryParse(value, out _Song.Start))
-                                    _LogWarning("Invalid start");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid start: {Value}", _Song.FileName, value);
                                 break;
                             case "END":
                                 if (CHelper.TryParse(value, out _Song.Finish))
                                     _Song.Finish /= 1000f;
                                 else
-                                    _LogWarning("Invalid end");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid end: {Value}", _Song.FileName, value);
                                 break;
                             case "PREVIEWSTART":
                                 if (CHelper.TryParse(value, out _Song.Preview.StartTime) && _Song.Preview.StartTime >= 0f)
                                     _Song.Preview.Source = EDataSource.Tag;
                                 else
-                                    _LogWarning("Invalid previewstart");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid previewstart: {Value}", _Song.FileName, value);
                                 break;
                             case "PREVIEW":
                                 if (CHelper.TryParse(value, out _Song.Preview.StartTime) && _Song.Preview.StartTime >= 0f)
@@ -305,19 +283,19 @@ namespace VocaluxeLib.Songs
                                     _Song.Preview.Source = EDataSource.Tag;
                                 }
                                 else
-                                    _LogWarning("Invalid previewstart");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid previewstart: {Value}", _Song.FileName, value);
                                 break;
                             case "MEDLEYSTARTBEAT":
                                 if (int.TryParse(value, out _Song.Medley.StartBeat))
                                     headerFlags |= EHeaderFlags.MedleyStartBeat;
                                 else
-                                    _LogWarning("Invalid medleystartbeat");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid medleystartbeat: {Value}", _Song.FileName, value);
                                 break;
                             case "MEDLEYENDBEAT":
                                 if (int.TryParse(value, out _Song.Medley.EndBeat))
                                     headerFlags |= EHeaderFlags.MedleyEndBeat;
                                 else
-                                    _LogWarning("Invalid medleyendbeat");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Invalid medleyendbeat: {Value}", _Song.FileName, value);
                                 break;
                             case "ENDSHORT":
                                 if ((headerFlags & EHeaderFlags.BPM) != 0)
@@ -329,7 +307,7 @@ namespace VocaluxeLib.Songs
                                         _Song.ShortEnd.Source = EDataSource.Tag;
                                     }
                                     else
-                                        _LogWarning("Invalid shortendbeat");
+                                        CBase.Log.LogSongWarning("[{SongFileName}] Invalid shortendbeat: {Value}", _Song.FileName, value);
                                 }
                                 break;
                             case "CALCMEDLEY":
@@ -364,7 +342,7 @@ namespace VocaluxeLib.Songs
                                 else
                                 {
                                     _Song.UnknownTags.Add(line);
-                                    _LogWarning("Unknown tag: #" + identifier);
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Unknown tag: #{Identifier}", _Song.FileName, identifier);
                                 }
 
                                 break;
@@ -374,31 +352,32 @@ namespace VocaluxeLib.Songs
                     if (sr.EndOfStream)
                     {
                         //No other data then header
-                        _LogError("Lyrics/Notes missing", false);
+                        CBase.Log.LogSongError("[{SongFileName}] Lyrics/Notes missing", _Song.FileName);
+
                         return false;
                     }
 
                     if ((headerFlags & EHeaderFlags.Title) == 0)
                     {
-                        _LogError("Title tag missing", false);
+                        CBase.Log.LogSongError("[{SongFileName}] Title tag missing", _Song.FileName);
                         return false;
                     }
 
                     if ((headerFlags & EHeaderFlags.Artist) == 0)
                     {
-                        _LogError("Artist tag missing", false);
+                        CBase.Log.LogSongError("[{SongFileName}] Artist tag missing", _Song.FileName);
                         return false;
                     }
 
                     if ((headerFlags & EHeaderFlags.MP3) == 0)
                     {
-                        _LogError("MP3 tag missing", false);
+                        CBase.Log.LogSongError("[{SongFileName}] MP3 tag missing", _Song.FileName);
                         return false;
                     }
 
                     if ((headerFlags & EHeaderFlags.BPM) == 0)
                     {
-                        _LogError("BPM tag missing", false);
+                        CBase.Log.LogSongError("[{SongFileName}] BPM tag missing", _Song.FileName);
                         return false;
                     }
 
@@ -407,7 +386,7 @@ namespace VocaluxeLib.Songs
                     {
                         if (_Song.Medley.StartBeat > _Song.Medley.EndBeat)
                         {
-                            _LogError("MedleyStartBeat is bigger than MedleyEndBeat in file", false);
+                            CBase.Log.LogSongError("[{SongFileName}] MedleyStartBeat is bigger than MedleyEndBeat in file: {StartBeat} > {EndBeat}", _Song.FileName, _Song.Medley.StartBeat > _Song.Medley.EndBeat);
                             headerFlags = headerFlags - EHeaderFlags.MedleyStartBeat - EHeaderFlags.MedleyEndBeat;
                         }
                     }
@@ -433,7 +412,7 @@ namespace VocaluxeLib.Songs
                 {
                     if (sr != null)
                         sr.Dispose();
-                    _LogError("Error reading txt header" + e.Message, false);
+                    CBase.Log.LogSongError(e, "[{SongFileName}] Error reading txt header with Message: {ExceptionMessage}",  e.Message, _Song.FileName);
                     return false;
                 }
                 _Song.Encoding = sr.CurrentEncoding;
@@ -530,7 +509,7 @@ namespace VocaluxeLib.Songs
 
                 if (!File.Exists(filePath))
                 {
-                    _LogError("The file does not exist", false);
+                    CBase.Log.LogSongError("[{SongFileName}] The file songfile does not exist", _Song.FileName);
                     return false;
                 }
 
@@ -579,7 +558,7 @@ namespace VocaluxeLib.Songs
 
                                 if (!int.TryParse(line, out player))
                                 {
-                                    _LogError("Wrong or missing number after \"P\"");
+                                    CBase.Log.LogSongError("[{SongFileName}] Wrong or missing number after \"P\" (in line {LineNr})", _Song.FileName, _LineNr);
                                     return false;
                                 }
                                 currentBeat = 0;
@@ -593,25 +572,25 @@ namespace VocaluxeLib.Songs
                                 {
                                     if (noteData.Length == 3)
                                     {
-                                        _LogWarning("Ignored note without text");
+                                        CBase.Log.LogSongWarning("[{SongFileName}] Ignored note without text (in line {LineNr})", _Song.FileName, _LineNr);
                                         changesMade.NoTextNoteCt++;
                                         continue;
                                     }
-                                    _LogError("Invalid note found");
+                                    CBase.Log.LogSongError("[{SongFileName}] Invalid note found (in line {LineNr}): {noteData}", _Song.FileName, _LineNr, noteData);
                                     sr.Dispose();
                                     return false;
                                 }
                                 int tone;
                                 if (!int.TryParse(noteData[0], out beat) || !int.TryParse(noteData[1], out length) || !int.TryParse(noteData[2], out tone))
                                 {
-                                    _LogError("Invalid note found (non-numeric values)");
+                                    CBase.Log.LogSongError("[{SongFileName}] Invalid note found (non-numeric values) (in line {LineNr}): {noteData}", _Song.FileName, _LineNr, noteData);
                                     sr.Dispose();
                                     return false;
                                 }
                                 string text = noteData[3].TrimMultipleWs();
                                 if (text == "")
                                 {
-                                    _LogWarning("Ignored note without text");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Ignored note without text (in line {LineNr})", _Song.FileName, _LineNr);
                                     changesMade.NoTextNoteCt++;
                                     continue;
                                 }
@@ -622,12 +601,12 @@ namespace VocaluxeLib.Songs
                                     changesMade.ZeroLengthNoteCt++;
                                     if (_CurrentReadMode == ENoteReadMode.Normal && changesMade.ZeroLengthNoteCt > _MaxZeroNoteCt && changesMade.OverlapNoteCt <= _MaxOverlapNoteCt)
                                     {
-                                        _LogWarning("Found more than " + _MaxZeroNoteCt + " note with length < 1. Trying alternative read mode.");
+                                        CBase.Log.LogSongWarning("[{SongFileName}] Found more than {MaxZeroNoteCt} notes with length < 1. Trying alternative read mode.", _Song.FileName, _MaxZeroNoteCt);
                                         _CurrentReadMode = ENoteReadMode.ZeroBased;
                                         sr.Dispose();
                                         return ReadNotes(true);
                                     }
-                                    _LogWarning("Ignored note with length < 1");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Ignored note with length < 1 (in line {LineNr})", _Song.FileName, _LineNr);
                                 }
                                 else
                                 {
@@ -656,13 +635,13 @@ namespace VocaluxeLib.Songs
                                                 changesMade.OverlapNoteCt++;
                                                 if (changesMade.OverlapNoteCt > _MaxOverlapNoteCt && _CurrentReadMode == ENoteReadMode.ZeroBased)
                                                 {
-                                                    _LogWarning("Found more than " + _MaxOverlapNoteCt + " overlapping notes. Using standard mode.");
+                                                    CBase.Log.LogSongWarning("[{SongFileName}] Found more than {MaxOverlapNoteCt} overlapping notes. Using standard mode.", _Song.FileName, _MaxOverlapNoteCt);
                                                     _CurrentReadMode = ENoteReadMode.OneBased;
                                                     sr.Dispose();
                                                     return ReadNotes(true);
                                                 }
                                             }
-                                            _LogWarning("Ignored note for player " + (curPlayer + 1) + " because it overlaps with other note");
+                                            CBase.Log.LogSongWarning("[{SongFileName}] Ignored note for player {CurrentPlayerNumber} because it overlaps with other note (in line {LineNr})", _Song.FileName, (curPlayer + 1), _LineNr);
                                         }
                                     }
                                 }
@@ -671,13 +650,13 @@ namespace VocaluxeLib.Songs
                                 string[] lineBreakData = line.Split(splitChars);
                                 if (lineBreakData.Length < 1)
                                 {
-                                    _LogError("Invalid line break found (No beat)");
+                                    CBase.Log.LogSongError("[{SongFileName}] Invalid line break found (No beat) (in line {LineNr}): {LineBreakData}", _Song.FileName, _LineNr, lineBreakData);
                                     sr.Dispose();
                                     return false;
                                 }
                                 if (!int.TryParse(lineBreakData[0], out beat))
                                 {
-                                    _LogError("Invalid line break found (Non-numeric value)");
+                                    CBase.Log.LogSongError("[{SongFileName}] Invalid line break found (Non-numeric value) (in line {LineNr}): {LineBreakData}", _Song.FileName, _LineNr, lineBreakData);
                                     sr.Dispose();
                                     return false;
                                 }
@@ -687,7 +666,7 @@ namespace VocaluxeLib.Songs
                                     beat += currentBeat;
                                     if (lineBreakData.Length < 2 || !int.TryParse(lineBreakData[1], out length))
                                     {
-                                        _LogWarning("Missing line break length");
+                                        CBase.Log.LogSongWarning("[{SongFileName}] Missing line break length (in line {LineNr}):{LineBreakData}", _Song.FileName, _LineNr, lineBreakData);
                                         changesMade.NoLengthBreakCt++;
                                         currentBeat = beat;
                                     }
@@ -697,7 +676,8 @@ namespace VocaluxeLib.Songs
 
                                 if (lastNote != null && beat <= lastNote.EndBeat)
                                 {
-                                    _LogWarning("Line break is before previous note end. Adjusted.");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Line break is before previous note end. Adjusted. (in line {LineNr})", _Song.FileName, _LineNr);
+                                    
                                     changesMade.AjustedBreakCt++;
                                     if (_Song.Relative)
                                         currentBeat += lastNote.EndBeat - beat + 1;
@@ -706,7 +686,7 @@ namespace VocaluxeLib.Songs
 
                                 if (beat < 1)
                                 {
-                                    _LogWarning("Ignored line break because position is < 1");
+                                    CBase.Log.LogSongWarning("[{SongFileName}] Ignored line break because position is < 1 (in line {LineNr})", _Song.FileName, _LineNr);
                                     changesMade.InvalidPosBreakCt++;
                                 }
                                 else
@@ -714,12 +694,12 @@ namespace VocaluxeLib.Songs
                                     foreach (int curPlayer in player.GetSetBits())
                                     {
                                         if (!_NewSentence(curPlayer, beat))
-                                            _LogWarning("Ignored line break for player " + (curPlayer + 1) + " (Overlapping or duplicate)");
+                                            CBase.Log.LogSongWarning("[{SongFileName}] Ignored line break for player {CurPlayerNr} (Overlapping or duplicate) (in line {LineNr})", _Song.FileName, (curPlayer + 1) , _LineNr);
                                     }
                                 }
                                 break;
                             default:
-                                _LogError("Unexpected or missing character (" + tag + ")");
+                                CBase.Log.LogSongError("[{SongFileName}] Unexpected or missing character ({Tag})", _Song.FileName, tag);
                                 return false;
                         }
                     }
@@ -729,13 +709,13 @@ namespace VocaluxeLib.Songs
                         CVoice voice = _Song.Notes.GetVoice(i);
                         int emptyLines = voice.RemoveEmptyLines();
                         if (emptyLines > 0)
-                            _LogWarning("Removed " + emptyLines + " empty lines from P" + ". This often indicates a problem with the line breaks in the file", false);
+                            CBase.Log.LogSongWarning("[{SongFileName}] Removed {NumEmptyLines} empty lines from P .This often indicates a problem with the line breaks in the file", _Song.FileName, emptyLines);
                         voice.UpdateTimings();
                     }
                 }
                 catch (Exception e)
                 {
-                    _LogError("An unhandled exception occured (" + e.Message + ")");
+                    CBase.Log.LogSongError(e, "[{SongFileName}] An unhandled exception occured: {ExceptionMessage}", _Song.FileName, e.Message);
                     if (sr != null)
                         sr.Dispose();
                     return false;
@@ -752,7 +732,7 @@ namespace VocaluxeLib.Songs
                 }
                 catch (Exception e)
                 {
-                    _LogError("An unhandled exception occured (" + e.Message + ")", false);
+                    CBase.Log.LogSongError(e, "[{SongFileName}] An unhandled exception occured: {ExceptionMessage}", _Song.FileName, e.Message);
                     return false;
                 }
 

VocaluxeTests/PartyModeTests.cs

@@ -46,7 +46,7 @@ namespace VocaluxeTests
         public void TestRoundGeneration()
         {
             CBase.Game = new CBGame();
-            CLog.Init();
+            CLog.Init(CSettings.FolderNameLogs);
             CBase.Log = new CBlog();
             for (int i = 0; i < 10; i++)
             {