Better logger

1. Throw exception for fatal/error log when debugging
2. Write to debug output for warn/debug/info log when debugging
3. part of #355

Plugins/Wox.Plugin.Program/FileChangeWatcher.cs

@@ -2,7 +2,7 @@
 using System.Diagnostics;
 using System.IO;
 using System.Threading;
-
+using Wox.Infrastructure.Logger;
 namespace Wox.Plugin.Program
 {
     internal class FileChangeWatcher
@@ -15,7 +15,7 @@ namespace Wox.Plugin.Program
             if (watchedPath.Contains(path)) return;
             if (!Directory.Exists(path))
             {
-                Debug.WriteLine(string.Format("FileChangeWatcher: {0} doesn't exist", path));
+                Log.Warn($"FileChangeWatcher: {path} doesn't exist");
                 return;
             }
 

Plugins/Wox.Plugin.Program/ProgramSources/AppPathsProgramSource.cs

@@ -57,7 +57,7 @@ namespace Wox.Plugin.Program.ProgramSources
                     }
                     catch (Exception e)
                     {
-                        Log.Error(e.StackTrace);
+                        Log.Error(e);
                     }
                 }
             }

Plugins/Wox.Plugin.Program/ProgramSources/FileSystemProgramSource.cs

@@ -2,6 +2,7 @@
 using System.Collections.Generic;
 using System.IO;
 using System.Linq;
+using Wox.Core.Exception;
 using Wox.Infrastructure.Logger;
 
 namespace Wox.Plugin.Program.ProgramSources
@@ -70,7 +71,8 @@ namespace Wox.Plugin.Program.ProgramSources
             }
             catch (Exception e)
             {
-                Log.Warn(string.Format("GetAppFromDirectory failed: {0} - {1}", path, e.Message));
+                var woxPluginException = new WoxPluginException("Program", $"GetAppFromDirectory failed: {path}", e);
+                Log.Error(woxPluginException);
             }
         }
 

Plugins/Wox.Plugin.Program/Programs.cs

@@ -8,6 +8,7 @@ using System.Windows;
 using IWshRuntimeLibrary;
 using Wox.Infrastructure;
 using Wox.Plugin.Program.ProgramSources;
+using Wox.Infrastructure.Logger;
 using Stopwatch = Wox.Infrastructure.Stopwatch;
 
 namespace Wox.Plugin.Program
@@ -17,7 +18,7 @@ namespace Wox.Plugin.Program
         private static object lockObject = new object();
         private static List<Program> programs = new List<Program>();
         private static List<IProgramSource> sources = new List<IProgramSource>();
-        private static Dictionary<string, Type> SourceTypes = new Dictionary<string, Type>() { 
+        private static Dictionary<string, Type> SourceTypes = new Dictionary<string, Type>() {
             {"FileSystemProgramSource", typeof(FileSystemProgramSource)},
             {"CommonStartMenuProgramSource", typeof(CommonStartMenuProgramSource)},
             {"UserStartMenuProgramSource", typeof(UserStartMenuProgramSource)},
@@ -27,7 +28,7 @@ namespace Wox.Plugin.Program
 
         public List<Result> Query(Query query)
         {
-            
+
             var fuzzyMather = FuzzyMatcher.Create(query.Search);
             List<Program> returnList = programs.Where(o => MatchProgram(o, fuzzyMather)).ToList();
             returnList.ForEach(ScoreFilter);
@@ -75,7 +76,7 @@ namespace Wox.Plugin.Program
             {
                 programs = ProgramCacheStorage.Instance.Programs;
             });
-            Debug.WriteLine($"Preload {programs.Count} programs from cache");
+            Log.Info($"Preload {programs.Count} programs from cache");
             Stopwatch.Debug("Program Index", IndexPrograms);
         }
 
@@ -98,7 +99,7 @@ namespace Wox.Plugin.Program
                 }
 
                 sources.Clear();
-                foreach(var source in programSources.Where(o => o.Enabled))
+                foreach (var source in programSources.Where(o => o.Enabled))
                 {
                     Type sourceClass;
                     if (SourceTypes.TryGetValue(source.Type, out sourceClass))

Wox.Core/Plugin/CSharpPluginLoader.cs

@@ -2,6 +2,7 @@
 using System.Collections.Generic;
 using System.Linq;
 using System.Reflection;
+using Wox.Core.Exception;
 using Wox.Infrastructure.Logger;
 using Wox.Plugin;
 
@@ -19,10 +20,10 @@ namespace Wox.Core.Plugin
                 try
                 {
                     Assembly asm = Assembly.Load(AssemblyName.GetAssemblyName(metadata.ExecuteFilePath));
-                    List<Type> types = asm.GetTypes().Where(o => o.IsClass && !o.IsAbstract &&  o.GetInterfaces().Contains(typeof(IPlugin))).ToList();
+                    List<Type> types = asm.GetTypes().Where(o => o.IsClass && !o.IsAbstract && o.GetInterfaces().Contains(typeof(IPlugin))).ToList();
                     if (types.Count == 0)
                     {
-                        Log.Warn(string.Format("Couldn't load plugin {0}: didn't find the class that implement IPlugin", metadata.Name));
+                        Log.Warn($"Couldn't load plugin {metadata.Name}: didn't find the class that implement IPlugin");
                         continue;
                     }
 
@@ -39,12 +40,7 @@ namespace Wox.Core.Plugin
                 }
                 catch (System.Exception e)
                 {
-                    Log.Error(string.Format("Couldn't load plugin {0}: {1}", metadata.Name, e.Message));
+                    Log.Error(new WoxPluginException(metadata.Name, $"Couldn't load plugin", e));
-#if (DEBUG)
-                    {
-                        throw;
-                    }
-#endif
                 }
             }
 

Wox.Core/Plugin/JsonRPCPlugin.cs

@@ -74,7 +74,7 @@ namespace Wox.Core.Plugin
                 }
                 catch (System.Exception e)
                 {
-                    Log.Error(e.Message);
+                    Log.Error(e);
                 }
             }
             return null;

Wox.Core/Plugin/PluginConfig.cs

@@ -47,7 +47,7 @@ namespace Wox.Core.Plugin
                     }
                     catch (System.Exception e)
                     {
-                        Log.Error(ExceptionFormatter.FormatExcpetion(e));
+                        Log.Fatal(e);
                     }
                 }
                 PluginMetadata metadata = GetPluginMetadata(directory);
@@ -63,7 +63,7 @@ namespace Wox.Core.Plugin
             string configPath = Path.Combine(pluginDirectory, pluginConfigName);
             if (!File.Exists(configPath))
             {
-                Log.Warn(string.Format("parse plugin {0} failed: didn't find config file.", configPath));
+                Log.Warn($"parse plugin {configPath} failed: didn't find config file.");
                 return null;
             }
 
@@ -77,40 +77,25 @@ namespace Wox.Core.Plugin
                 // for plugin still use old ActionKeyword
                 metadata.ActionKeyword = metadata.ActionKeywords?[0];
             }
-            catch (System.Exception)
+            catch (System.Exception e)
             {
-                string error = string.Format("Parse plugin config {0} failed: json format is not valid", configPath);
+                string msg = $"Parse plugin config {configPath} failed: json format is not valid";
-                Log.Warn(error);
+                Log.Error(new WoxException(msg));
-#if (DEBUG)
-                {
-                    throw new WoxException(error);
-                }
-#endif
                 return null;
             }
 
 
             if (!AllowedLanguage.IsAllowed(metadata.Language))
             {
-                string error = string.Format("Parse plugin config {0} failed: invalid language {1}", configPath, metadata.Language);
+                string msg = $"Parse plugin config {configPath} failed: invalid language {metadata.Language}";
-                Log.Warn(error);
+                Log.Error(new WoxException(msg));
-#if (DEBUG)
-                {
-                    throw new WoxException(error);
-                }
-#endif
                 return null;
             }
 
             if (!File.Exists(metadata.ExecuteFilePath))
             {
-                string error = string.Format("Parse plugin config {0} failed: ExecuteFile {1} didn't exist", configPath, metadata.ExecuteFilePath);
+                string msg = $"Parse plugin config {configPath} failed: ExecuteFile {metadata.ExecuteFilePath} didn't exist";
-                Log.Warn(error);
+                Log.Error(new WoxException(msg));
-#if (DEBUG)
-                {
-                    throw new WoxException(error);
-                }
-#endif
                 return null;
             }
 

Wox.Core/Plugin/PluginManager.cs

@@ -58,7 +58,7 @@ namespace Wox.Core.Plugin
                     }
                     catch (System.Exception e)
                     {
-                        Log.Error(e.Message);
+                        Log.Error(e);
                     }
                 }
             }
@@ -69,7 +69,7 @@ namespace Wox.Core.Plugin
         /// </summary>
         public static void Init(IPublicAPI api)
         {
-            if (api == null) throw new WoxCritialException("api is null");
+            if (api == null) throw new WoxFatalException("api is null");
 
             SetupPluginDirectories();
             API = api;
@@ -164,7 +164,7 @@ namespace Wox.Core.Plugin
                 if (customizedPluginConfig != null && customizedPluginConfig.Disabled) continue;
                 if (IsInstantQueryPlugin(plugin))
                 {
-                    Stopwatch.Debug($"Instant Query for {plugin.Metadata.Name}", () =>
+                    Stopwatch.Normal($"Instant QueryForPlugin for {plugin.Metadata.Name}", () =>
                     {
                         QueryForPlugin(plugin, query);
                     });
@@ -173,7 +173,10 @@ namespace Wox.Core.Plugin
                 {
                     ThreadPool.QueueUserWorkItem(state =>
                     {
-                        QueryForPlugin(plugin, query);
+                        Stopwatch.Normal($"Normal QueryForPlugin for {plugin.Metadata.Name}", () =>
+                        {
+                            QueryForPlugin(plugin, query);
+                        });
                     });
                 }
             }
@@ -184,7 +187,7 @@ namespace Wox.Core.Plugin
             try
             {
                 List<Result> results = new List<Result>();
-                var milliseconds = Stopwatch.Normal($"Query for {pair.Metadata.Name}", () =>
+                var milliseconds = Stopwatch.Normal($"Plugin.Query cost for {pair.Metadata.Name}", () =>
                     {
                         results = pair.Plugin.Query(query) ?? results;
                         results.ForEach(o => { o.PluginID = pair.Metadata.ID; });
@@ -195,7 +198,7 @@ namespace Wox.Core.Plugin
             }
             catch (System.Exception e)
             {
-                throw new WoxPluginException(pair.Metadata.Name, e);
+                throw new WoxPluginException(pair.Metadata.Name, $"QueryForPlugin failed", e);
             }
         }
 
@@ -239,12 +242,7 @@ namespace Wox.Core.Plugin
                 }
                 catch (System.Exception e)
                 {
-                    Log.Error($"Couldn't load plugin context menus {pluginPair.Metadata.Name}: {e.Message}");
+                    Log.Error(new WoxPluginException(pluginPair.Metadata.Name, $"Couldn't load plugin context menus", e));
-#if (DEBUG)
-                    {
-                        throw;
-                    }
-#endif
                 }
             }
 

Wox.Core/Theme/Theme.cs

@@ -35,7 +35,7 @@ namespace Wox.Core.Theme
                     }
                     catch (System.Exception e)
                     {
-                        Log.Error(e.Message);
+                        Log.Error(e);
                     }
                 }
             }

Wox.Core/Wox.Core.csproj

@@ -57,13 +57,6 @@
   </ItemGroup>
   <ItemGroup>
     <Compile Include="APIServer.cs" />
-    <Compile Include="Exception\ExceptionFormatter.cs" />
-    <Compile Include="Exception\WoxCritialException.cs" />
-    <Compile Include="Exception\WoxException.cs" />
-    <Compile Include="Exception\WoxHttpException.cs" />
-    <Compile Include="Exception\WoxI18nException.cs" />
-    <Compile Include="Exception\WoxJsonRPCException.cs" />
-    <Compile Include="Exception\WoxPluginException.cs" />
     <Compile Include="Updater\Release.cs" />
     <Compile Include="Updater\UpdaterManager.cs" />
     <Compile Include="Updater\WoxUpdateSource.cs" />

Wox.Core/i18n/Internationalization.cs

@@ -32,7 +32,7 @@ namespace Wox.Core.i18n
                 }
                 catch (System.Exception e)
                 {
-                    Log.Error(e.Message);
+                    Log.Error(e);
                 }
             }
         }
@@ -122,12 +122,8 @@ namespace Wox.Core.i18n
             }
             catch (System.Exception e)
             {
-                Log.Warn("Update Plugin metadata translation failed:" + e.Message);
+                var woxPluginException = new WoxPluginException(pluginPair.Metadata.Name, "Update Plugin metadata translation failed:", e);
-#if (DEBUG)
+                Log.Error(woxPluginException);
-                {
-                    throw;
-                }
-#endif
             }
         }
 

Wox.Infrastructure/Exception/WoxException.cs

@@ -14,7 +14,6 @@
         public WoxException(string msg, System.Exception innerException)
             : base(msg, innerException)
         {
-
         }
     }
 }

Wox.Infrastructure/Exception/WoxFatalException.cs

@@ -3,9 +3,9 @@
     /// <summary>
     /// Represent exceptions that wox can't handle and MUST close running Wox.
     /// </summary>
-    public class WoxCritialException : WoxException
+    public class WoxFatalException : WoxException
     {
-        public WoxCritialException(string msg) : base(msg)
+        public WoxFatalException(string msg) : base(msg)
         {
         }
     }

Wox.Infrastructure/Exception/WoxPluginException.cs

@@ -4,8 +4,8 @@
     {
         public string PluginName { get; set; }
 
-        public WoxPluginException(string pluginName,System.Exception e)
+        public WoxPluginException(string pluginName, string msg, System.Exception e)
-            : base(e.Message,e)
+            : base($"{msg}: {pluginName}", e)
         {
             PluginName = pluginName;
         }

Wox.Infrastructure/Logger/Log.cs

@@ -1,5 +1,6 @@
 using System;
 using NLog;
+using Wox.Core.Exception;
 
 namespace Wox.Infrastructure.Logger
 {
@@ -7,34 +8,40 @@ namespace Wox.Infrastructure.Logger
     {
         private static NLog.Logger logger = LogManager.GetCurrentClassLogger();
 
-        public static void Error(string msg)
-        {
-            logger.Error(msg);
-        }
-
         public static void Error(Exception e)
         {
+#if DEBUG
+            throw e;
+#else
             logger.Error(e.Message + "\r\n" + e.StackTrace);
+#endif
         }
 
         public static void Debug(string msg)
         {
+            System.Diagnostics.Debug.WriteLine($"DEBUG: {msg}");
             logger.Debug(msg);
         }
 
         public static void Info(string msg)
         {
+            System.Diagnostics.Debug.WriteLine($"INFO: {msg}");
             logger.Info(msg);
         }
 
         public static void Warn(string msg)
         {
+            System.Diagnostics.Debug.WriteLine($"WARN: {msg}");
             logger.Warn(msg);
         }
 
-        public static void Fatal(string msg)
+        public static void Fatal(Exception e)
         {
-            logger.Fatal(msg);
+#if DEBUG
+            throw e;
+#else
+            logger.Fatal(ExceptionFormatter.FormatExcpetion(e));
+#endif
         }
     }
 }

Wox.Infrastructure/Stopwatch.cs

@@ -18,14 +18,6 @@ namespace Wox.Infrastructure
 #endif
         }
 
-        [Conditional("DEBUG")]
-        private static void WriteTimeInfo(string name, long milliseconds)
-        {
-            string info = $"{name} : {milliseconds}ms";
-            System.Diagnostics.Debug.WriteLine(info);
-            Log.Info(info);
-        }
-
         /// <summary>
         /// This stopwatch will also appear only in Debug mode
         /// </summary>
@@ -36,7 +28,8 @@ namespace Wox.Infrastructure
             action();
             stopWatch.Stop();
             var milliseconds = stopWatch.ElapsedMilliseconds;
-            WriteTimeInfo(name, milliseconds);
+            string info = $"{name} : {milliseconds}ms";
+            Log.Debug(info);
             return milliseconds;
         }
 

Wox.Infrastructure/Wox.Infrastructure.csproj

@@ -46,9 +46,17 @@
     </Reference>
     <Reference Include="System" />
     <Reference Include="System.Core" />
+    <Reference Include="System.Xml" />
     <Reference Include="WindowsBase" />
   </ItemGroup>
   <ItemGroup>
+    <Compile Include="Exception\ExceptionFormatter.cs" />
+    <Compile Include="Exception\WoxException.cs" />
+    <Compile Include="Exception\WoxFatalException.cs" />
+    <Compile Include="Exception\WoxHttpException.cs" />
+    <Compile Include="Exception\WoxI18nException.cs" />
+    <Compile Include="Exception\WoxJsonRPCException.cs" />
+    <Compile Include="Exception\WoxPluginException.cs" />
     <Compile Include="Hotkey\InterceptKeys.cs" />
     <Compile Include="Hotkey\KeyEvent.cs" />
     <Compile Include="Logger\Log.cs" />

Wox.Test/Plugins/PluginInitTest.cs

@@ -11,7 +11,7 @@ namespace Wox.Test.Plugins
         [Test]
         public void PublicAPIIsNullTest()
         {
-            Assert.Throws(typeof(WoxCritialException), () => PluginManager.Init(null));
+            Assert.Throws(typeof(WoxFatalException), () => PluginManager.Init(null));
         }
     }
 }

Wox.sln

@@ -62,6 +62,9 @@ EndProject
 Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "Wox.Plugin.Everything", "Plugins\Wox.Plugin.Everything\Wox.Plugin.Everything.csproj", "{230AE83F-E92E-4E69-8355-426B305DA9C0}"
 EndProject
 Global
+	GlobalSection(Performance) = preSolution
+		HasPerformanceSessions = true
+	EndGlobalSection
 	GlobalSection(SolutionConfigurationPlatforms) = preSolution
 		Debug|Any CPU = Debug|Any CPU
 		Release|Any CPU = Release|Any CPU

Wox/Helper/ErrorReporting.cs

@@ -9,7 +9,7 @@ namespace Wox.Helper
     {
         public static void Report(Exception e)
         {
-            Log.Error(ExceptionFormatter.FormatExcpetion(e));
+            Log.Fatal(e);
             new CrashReporter.CrashReporter(e).Show();
         }
 

Wox/Helper/ListBoxItems.cs

@@ -9,6 +9,7 @@ using Wox.Plugin;
 namespace Wox.Helper
 {
     class ListBoxItems : ObservableCollection<Result>
+    // todo implement custom moveItem,removeItem,insertItem
     {
         public void RemoveAll(Predicate<Result> predicate)
         {
@@ -21,7 +22,10 @@ namespace Wox.Helper
 
                 OnPropertyChanged(new PropertyChangedEventArgs("Count"));
                 OnPropertyChanged(new PropertyChangedEventArgs("Item[]"));
-                // fuck ms http://blogs.msdn.com/b/nathannesbit/archive/2009/04/20/addrange-and-observablecollection.aspx
+                // fuck ms 
+                // http://blogs.msdn.com/b/nathannesbit/archive/2009/04/20/addrange-and-observablecollection.aspx
+                // http://geekswithblogs.net/NewThingsILearned/archive/2008/01/16/listcollectionviewcollectionview-doesnt-support-notifycollectionchanged-with-multiple-items.aspx
+                // PS: don't use Reset for other data updates, it will cause UI flickering
                 OnCollectionChanged(new NotifyCollectionChangedEventArgs(NotifyCollectionChangedAction.Reset));
             }
         }

Wox/MainWindow.xaml.cs

@@ -32,6 +32,7 @@ using IDataObject = System.Windows.IDataObject;
 using KeyEventArgs = System.Windows.Input.KeyEventArgs;
 using MenuItem = System.Windows.Forms.MenuItem;
 using MessageBox = System.Windows.MessageBox;
+using Stopwatch = Wox.Infrastructure.Stopwatch;
 using ToolTip = System.Windows.Controls.ToolTip;
 
 namespace Wox
@@ -852,10 +853,14 @@ namespace Wox
 
         private void UpdateResultViewInternal(List<Result> list)
         {
-            Dispatcher.Invoke(new Action(() =>
+            if (list != null && list.Count > 0)
             {
-                pnlResult.AddResults(list);
+                Dispatcher.Invoke(new Action(() =>
-            }));
+                {
+                    Stopwatch.Normal($"UI update cost for {list[0].PluginDirectory.Split('\\').Last()}",
+                        () =>{pnlResult.AddResults(list);});
+                }));
+            }
         }
 
         private Result GetTopMostContextMenu(Result result)