Merge pull request #532 from taooceros/ExceptionLogPartialOpt

Exception log partial opt
This commit is contained in:
Jeremy Wu 2021-06-30 06:29:46 +10:00 committed by GitHub
commit 55e7ce0d90
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
9 changed files with 165 additions and 159 deletions

View file

@ -157,7 +157,7 @@ namespace Flow.Launcher.Core.Plugin
}
}
public static async Task<List<Result>> QueryForPlugin(PluginPair pair, Query query, CancellationToken token)
public static async Task<List<Result>> QueryForPluginAsync(PluginPair pair, Query query, CancellationToken token)
{
var results = new List<Result>();
try
@ -171,7 +171,7 @@ namespace Flow.Launcher.Core.Plugin
token.ThrowIfCancellationRequested();
if (results == null)
return results;
return null;
UpdatePluginMetadata(results, metadata, query);
metadata.QueryCount += 1;
@ -184,10 +184,6 @@ namespace Flow.Launcher.Core.Plugin
// null will be fine since the results will only be added into queue if the token hasn't been cancelled
return null;
}
catch (Exception e)
{
Log.Exception($"|PluginManager.QueryForPlugin|Exception for plugin <{pair.Metadata.Name}> when query <{query}>", e);
}
return results;
}

View file

@ -49,8 +49,11 @@
</ItemGroup>
<ItemGroup>
<PackageReference Include="NLog.Schema" Version="4.7.0-rc1" />
<PackageReference Include="NLog.Web.AspNetCore" Version="4.9.0" />
<PackageReference Include="Ben.Demystifier" Version="0.4.1" />
<PackageReference Include="Microsoft.VisualStudio.Threading" Version="16.10.56" />
<PackageReference Include="NLog" Version="4.7.10" />
<PackageReference Include="NLog.Schema" Version="4.7.10" />
<PackageReference Include="NLog.Web.AspNetCore" Version="4.12.0" />
<PackageReference Include="System.Drawing.Common" Version="4.7.0" />
<PackageReference Include="ToolGood.Words.Pinyin" Version="3.0.1.4" />
</ItemGroup>

View file

@ -5,6 +5,11 @@ using NLog;
using NLog.Config;
using NLog.Targets;
using Flow.Launcher.Infrastructure.UserSettings;
using JetBrains.Annotations;
using NLog.Fluent;
using NLog.Targets.Wrappers;
using System.Runtime.ExceptionServices;
using System.Text;
namespace Flow.Launcher.Infrastructure.Logger
{
@ -23,15 +28,37 @@ namespace Flow.Launcher.Infrastructure.Logger
}
var configuration = new LoggingConfiguration();
var target = new FileTarget();
configuration.AddTarget("file", target);
target.FileName = CurrentLogDirectory.Replace(@"\", "/") + "/${shortdate}.txt";
const string layout =
@"${date:format=HH\:mm\:ss.ffffK} - " +
@"${level:uppercase=true:padding=-5} - ${logger} - ${message:l}" +
@"${onexception:${newline}" +
@"EXCEPTION OCCURS\: ${exception:format=tostring}${newline}}";
var fileTarget = new FileTarget
{
FileName = CurrentLogDirectory.Replace(@"\", "/") + "/${shortdate}.txt",
Layout = layout
};
var fileTargetASyncWrapper = new AsyncTargetWrapper(fileTarget);
var debugTarget = new OutputDebugStringTarget
{
Layout = layout
};
configuration.AddTarget("file", fileTargetASyncWrapper);
configuration.AddTarget("debug", debugTarget);
#if DEBUG
var rule = new LoggingRule("*", LogLevel.Debug, target);
var fileRule = new LoggingRule("*", LogLevel.Debug, fileTargetASyncWrapper);
var debugRule = new LoggingRule("*", LogLevel.Debug, debugTarget);
configuration.LoggingRules.Add(debugRule);
#else
var rule = new LoggingRule("*", LogLevel.Info, target);
var fileRule = new LoggingRule("*", LogLevel.Info, fileTargetASyncWrapper);
#endif
configuration.LoggingRules.Add(rule);
configuration.LoggingRules.Add(fileRule);
LogManager.Configuration = configuration;
}
@ -39,7 +66,6 @@ namespace Flow.Launcher.Infrastructure.Logger
{
var logger = LogManager.GetLogger("FaultyLogger");
message = $"Wrong logger message format <{message}>";
System.Diagnostics.Debug.WriteLine($"FATAL|{message}");
logger.Fatal(message);
}
@ -51,12 +77,11 @@ namespace Flow.Launcher.Infrastructure.Logger
}
[MethodImpl(MethodImplOptions.Synchronized)]
public static void Exception(string className, string message, System.Exception exception, [CallerMemberName] string methodName = "")
{
exception = exception.Demystify();
#if DEBUG
throw exception;
ExceptionDispatchInfo.Capture(exception).Throw();
#else
var classNameWithMethod = CheckClassAndMessageAndReturnFullClassWithMethod(className, message, methodName);
@ -90,23 +115,9 @@ namespace Flow.Launcher.Infrastructure.Logger
{
var logger = LogManager.GetLogger(classAndMethod);
System.Diagnostics.Debug.WriteLine($"ERROR|{message}");
var messageBuilder = new StringBuilder();
logger.Error("-------------------------- Begin exception --------------------------");
logger.Error(message);
do
{
logger.Error($"Exception full name:\n <{e.GetType().FullName}>");
logger.Error($"Exception message:\n <{e.Message}>");
logger.Error($"Exception stack trace:\n <{e.StackTrace}>");
logger.Error($"Exception source:\n <{e.Source}>");
logger.Error($"Exception target site:\n <{e.TargetSite}>");
logger.Error($"Exception HResult:\n <{e.HResult}>");
e = e.InnerException;
} while (e != null);
logger.Error("-------------------------- End exception --------------------------");
logger.Error(e, message);
}
private static void LogInternal(string message, LogLevel level)
@ -117,8 +128,6 @@ namespace Flow.Launcher.Infrastructure.Logger
var prefix = parts[1];
var unprefixed = parts[2];
var logger = LogManager.GetLogger(prefix);
System.Diagnostics.Debug.WriteLine($"{level.Name}|{message}");
logger.Log(level, unprefixed);
}
else
@ -128,11 +137,12 @@ namespace Flow.Launcher.Infrastructure.Logger
}
/// <param name="message">example: "|prefix|unprefixed" </param>
[MethodImpl(MethodImplOptions.Synchronized)]
/// <param name="e">Exception</param>
public static void Exception(string message, System.Exception e)
{
e = e.Demystify();
#if DEBUG
throw e;
ExceptionDispatchInfo.Capture(e).Throw();
#else
if (FormatValid(message))
{
@ -165,7 +175,6 @@ namespace Flow.Launcher.Infrastructure.Logger
var logger = LogManager.GetLogger(classNameWithMethod);
System.Diagnostics.Debug.WriteLine($"{level.Name}|{message}");
logger.Log(level, message);
}

View file

@ -3,6 +3,8 @@ using System.Windows.Threading;
using NLog;
using Flow.Launcher.Infrastructure;
using Flow.Launcher.Infrastructure.Exception;
using NLog.Fluent;
using Log = Flow.Launcher.Infrastructure.Logger.Log;
namespace Flow.Launcher.Helper
{
@ -45,4 +47,4 @@ namespace Flow.Launcher.Helper
return info;
}
}
}
}

View file

@ -19,8 +19,10 @@ using Flow.Launcher.Plugin;
using Flow.Launcher.Plugin.SharedCommands;
using Flow.Launcher.Storage;
using Flow.Launcher.Infrastructure.Logger;
using Microsoft.VisualStudio.Threading;
using System.Threading.Channels;
using ISavable = Flow.Launcher.Plugin.ISavable;
using System.Windows.Threading;
namespace Flow.Launcher.ViewModel
{
@ -110,7 +112,9 @@ namespace Flow.Launcher.ViewModel
}
Log.Error("MainViewModel", "Unexpected ResultViewUpdate ends");
};
}
;
void continueAction(Task t)
{
@ -118,7 +122,7 @@ namespace Flow.Launcher.ViewModel
throw t.Exception;
#else
Log.Error($"Error happen in task dealing with viewupdate for results. {t.Exception}");
_resultsViewUpdateTask =
_resultsViewUpdateTask =
Task.Run(updateAction).ContinueWith(continueAction, TaskContinuationOptions.OnlyOnFaulted);
#endif
}
@ -137,7 +141,8 @@ namespace Flow.Launcher.ViewModel
if (!_resultsUpdateChannelWriter.TryWrite(new ResultsForUpdate(e.Results, pair.Metadata, e.Query, _updateToken)))
{
Log.Error("MainViewModel", "Unable to add item to Result Update Queue");
};
}
;
}
};
}
@ -237,21 +242,24 @@ namespace Flow.Launcher.ViewModel
ReloadPluginDataCommand = new RelayCommand(_ =>
{
var msg = new Msg { Owner = Application.Current.MainWindow };
var msg = new Msg
{
Owner = Application.Current.MainWindow
};
MainWindowVisibility = Visibility.Collapsed;
PluginManager
.ReloadData()
.ContinueWith(_ =>
Application.Current.Dispatcher.Invoke(() =>
{
msg.Show(
InternationalizationManager.Instance.GetTranslation("success"),
InternationalizationManager.Instance.GetTranslation("completedSuccessfully"),
"");
}))
.ConfigureAwait(false);
.ReloadData()
.ContinueWith(_ =>
Application.Current.Dispatcher.Invoke(() =>
{
msg.Show(
InternationalizationManager.Instance.GetTranslation("success"),
InternationalizationManager.Instance.GetTranslation("completedSuccessfully"),
"");
}))
.ConfigureAwait(false);
});
}
@ -422,7 +430,10 @@ namespace Flow.Launcher.ViewModel
Title = string.Format(title, h.Query),
SubTitle = string.Format(time, h.ExecutedDateTime),
IcoPath = "Images\\history.png",
OriginQuery = new Query { RawQuery = h.Query },
OriginQuery = new Query
{
RawQuery = h.Query
},
Action = _ =>
{
SelectedResults = Results;
@ -448,7 +459,9 @@ namespace Flow.Launcher.ViewModel
}
}
private void QueryResults()
private readonly IReadOnlyList<Result> _emptyResult = new List<Result>();
private async void QueryResults()
{
_updateSource?.Cancel();
@ -469,6 +482,12 @@ namespace Flow.Launcher.ViewModel
ProgressBarVisibility = Visibility.Hidden;
_isQueryRunning = true;
// Switch to ThreadPool thread
await TaskScheduler.Default;
if (currentCancellationToken.IsCancellationRequested)
return;
var query = QueryBuilder.Build(QueryText.Trim(), PluginManager.NonGlobalPlugins);
// handle the exclusiveness of plugin using action keyword
@ -478,74 +497,73 @@ namespace Flow.Launcher.ViewModel
var plugins = PluginManager.ValidPluginsForQuery(query);
Task.Run(async () =>
if (query.ActionKeyword == Plugin.Query.GlobalPluginWildcardSign)
{
// Wait 45 millisecond for query change in global query
// if query changes, return so that it won't be calculated
await Task.Delay(45, currentCancellationToken);
if (currentCancellationToken.IsCancellationRequested)
return;
}
_ = Task.Delay(200, currentCancellationToken).ContinueWith(_ =>
{
// start the progress bar if query takes more than 200 ms and this is the current running query and it didn't finish yet
if (!currentCancellationToken.IsCancellationRequested && _isQueryRunning)
{
if (query.ActionKeyword == Plugin.Query.GlobalPluginWildcardSign)
{
// Wait 45 millisecond for query change in global query
// if query changes, return so that it won't be calculated
await Task.Delay(45, currentCancellationToken);
if (currentCancellationToken.IsCancellationRequested)
return;
}
ProgressBarVisibility = Visibility.Visible;
}
}, currentCancellationToken, TaskContinuationOptions.NotOnCanceled, TaskScheduler.Default);
_ = Task.Delay(200, currentCancellationToken).ContinueWith(_ =>
{
// start the progress bar if query takes more than 200 ms and this is the current running query and it didn't finish yet
if (!currentCancellationToken.IsCancellationRequested && _isQueryRunning)
{
ProgressBarVisibility = Visibility.Visible;
}
}, currentCancellationToken);
// plugins is ICollection, meaning LINQ will get the Count and preallocate Array
// plugins is ICollection, meaning LINQ will get the Count and preallocate Array
var tasks = plugins.Select(plugin => plugin.Metadata.Disabled switch
{
false => QueryTask(plugin),
true => Task.CompletedTask
}).ToArray();
Task[] tasks = plugins.Select(plugin => plugin.Metadata.Disabled switch
{
false => QueryTask(plugin),
true => Task.CompletedTask
}).ToArray();
try
{
// Check the code, WhenAll will translate all type of IEnumerable or Collection to Array, so make an array at first
await Task.WhenAll(tasks);
}
catch (OperationCanceledException)
{
// nothing to do here
}
try
{
// Check the code, WhenAll will translate all type of IEnumerable or Collection to Array, so make an array at first
await Task.WhenAll(tasks);
}
catch (OperationCanceledException)
{
// nothing to do here
}
if (currentCancellationToken.IsCancellationRequested)
return;
if (currentCancellationToken.IsCancellationRequested)
return;
// this should happen once after all queries are done so progress bar should continue
// until the end of all querying
_isQueryRunning = false;
if (!currentCancellationToken.IsCancellationRequested)
{
// update to hidden if this is still the current query
ProgressBarVisibility = Visibility.Hidden;
}
// this should happen once after all queries are done so progress bar should continue
// until the end of all querying
_isQueryRunning = false;
if (!currentCancellationToken.IsCancellationRequested)
{
// update to hidden if this is still the current query
ProgressBarVisibility = Visibility.Hidden;
}
// Local function
async Task QueryTask(PluginPair plugin)
{
// Since it is wrapped within a Task.Run, the synchronous context is null
// Task.Yield will force it to run in ThreadPool
await Task.Yield();
// Local function
async Task QueryTask(PluginPair plugin)
{
// Since it is wrapped within a ThreadPool Thread, the synchronous context is null
// Task.Yield will force it to run in ThreadPool
await Task.Yield();
var results = await PluginManager.QueryForPlugin(plugin, query, currentCancellationToken);
if (currentCancellationToken.IsCancellationRequested || results == null) return;
IReadOnlyList<Result> results = await PluginManager.QueryForPluginAsync(plugin, query, currentCancellationToken);
currentCancellationToken.ThrowIfCancellationRequested();
if (!_resultsUpdateChannelWriter.TryWrite(new ResultsForUpdate(results, plugin.Metadata, query, currentCancellationToken)))
{
Log.Error("MainViewModel", "Unable to add item to Result Update Queue");
};
}
}, currentCancellationToken)
.ContinueWith(t => Log.Exception("|MainViewModel|Plugins Query Exceptions", t.Exception),
TaskContinuationOptions.OnlyOnFaulted);
results ??= _emptyResult;
if (!_resultsUpdateChannelWriter.TryWrite(new ResultsForUpdate(results, plugin.Metadata, query, currentCancellationToken)))
{
Log.Error("MainViewModel", "Unable to add item to Result Update Queue");
}
}
}

View file

@ -8,7 +8,7 @@ namespace Flow.Launcher.ViewModel
{
public struct ResultsForUpdate
{
public List<Result> Results { get; }
public IReadOnlyList<Result> Results { get; }
public PluginMetadata Metadata { get; }
public string ID { get; }
@ -16,7 +16,7 @@ namespace Flow.Launcher.ViewModel
public Query Query { get; }
public CancellationToken Token { get; }
public ResultsForUpdate(List<Result> results, PluginMetadata metadata, Query query, CancellationToken token)
public ResultsForUpdate(IReadOnlyList<Result> results, PluginMetadata metadata, Query query, CancellationToken token)
{
Results = results;
Metadata = metadata;

View file

@ -21,7 +21,8 @@ namespace Flow.Launcher.Plugin.Explorer.Search.DirectoryInfo
RecurseSubdirectories = true
}, query, search, criteria, token);
return DirectorySearch(new EnumerationOptions(), query, search, criteria, token); // null will be passed as default
return DirectorySearch(new EnumerationOptions(), query, search, criteria,
token); // null will be passed as default
}
public static string ConstructSearchCriteria(string search)
@ -57,7 +58,8 @@ namespace Flow.Launcher.Plugin.Explorer.Search.DirectoryInfo
{
var directoryInfo = new System.IO.DirectoryInfo(path);
foreach (var fileSystemInfo in directoryInfo.EnumerateFileSystemInfos(searchCriteria, enumerationOption))
foreach (var fileSystemInfo in directoryInfo.EnumerateFileSystemInfos(searchCriteria, enumerationOption)
)
{
if (fileSystemInfo is System.IO.DirectoryInfo)
{
@ -74,17 +76,10 @@ namespace Flow.Launcher.Plugin.Explorer.Search.DirectoryInfo
}
catch (Exception e)
{
if (!(e is ArgumentException))
throw e;
Log.Exception("Flow.Plugin.Explorer.", nameof(DirectoryInfoSearch), e);
results.Add(new Result {Title = e.Message, Score = 501});
return results;
#if DEBUG // Please investigate and handle error from DirectoryInfo search
#else
Log.Exception($"|Flow.Launcher.Plugin.Explorer.DirectoryInfoSearch|Error from performing DirectoryInfoSearch", e);
#endif
}
// Initial ordering, this order can be updated later by UpdateResultView.MainViewModel based on history of user selection.

View file

@ -17,20 +17,20 @@ namespace Flow.Launcher.Plugin.Explorer.Search.WindowsIndex
// Reserved keywords in oleDB
private const string reservedStringPattern = @"^[`\@\#\^,\&\/\\\$\%_]+$";
internal async static Task<List<Result>> ExecuteWindowsIndexSearchAsync(string indexQueryString, string connectionString, Query query, CancellationToken token)
internal static async Task<List<Result>> ExecuteWindowsIndexSearchAsync(string indexQueryString, string connectionString, Query query, CancellationToken token)
{
var results = new List<Result>();
var fileResults = new List<Result>();
try
{
using var conn = new OleDbConnection(connectionString);
await using var conn = new OleDbConnection(connectionString);
await conn.OpenAsync(token);
token.ThrowIfCancellationRequested();
using var command = new OleDbCommand(indexQueryString, conn);
await using var command = new OleDbCommand(indexQueryString, conn);
// Results return as an OleDbDataReader.
using var dataReaderResults = await command.ExecuteReaderAsync(token) as OleDbDataReader;
await using var dataReaderResults = await command.ExecuteReaderAsync(token) as OleDbDataReader;
token.ThrowIfCancellationRequested();
if (dataReaderResults.HasRows)
@ -42,18 +42,18 @@ namespace Flow.Launcher.Plugin.Explorer.Search.WindowsIndex
{
// # is URI syntax for the fragment component, need to be encoded so LocalPath returns complete path
var encodedFragmentPath = dataReaderResults
.GetString(1)
.Replace("#", "%23", StringComparison.OrdinalIgnoreCase);
.GetString(1)
.Replace("#", "%23", StringComparison.OrdinalIgnoreCase);
var path = new Uri(encodedFragmentPath).LocalPath;
if (dataReaderResults.GetString(2) == "Directory")
{
results.Add(ResultManager.CreateFolderResult(
dataReaderResults.GetString(0),
path,
path,
query, 0, true, true));
dataReaderResults.GetString(0),
path,
path,
query, 0, true, true));
}
else
{
@ -63,6 +63,11 @@ namespace Flow.Launcher.Plugin.Explorer.Search.WindowsIndex
}
}
}
catch (OperationCanceledException)
{
// return empty result when cancelled
return results;
}
catch (InvalidOperationException e)
{
// Internal error from ExecuteReader(): Connection closed.

View file

@ -20,27 +20,6 @@ namespace Flow.Launcher.Plugin.Program.Logger
{
public const string DirectoryName = "Logs";
static ProgramLogger()
{
var path = Path.Combine(DataLocation.DataDirectory(), DirectoryName, Constant.Version);
if (!Directory.Exists(path))
{
Directory.CreateDirectory(path);
}
var configuration = new LoggingConfiguration();
var target = new FileTarget();
configuration.AddTarget("file", target);
target.FileName = path.Replace(@"\", "/") + "/${shortdate}.txt";
#if DEBUG
var rule = new LoggingRule("*", LogLevel.Debug, target);
#else
var rule = new LoggingRule("*", LogLevel.Error, target);
#endif
configuration.LoggingRules.Add(rule);
LogManager.Configuration = configuration;
}
/// <summary>
/// Logs an exception
/// </summary>
@ -48,8 +27,6 @@ namespace Flow.Launcher.Plugin.Program.Logger
internal static void LogException(string classname, string callingMethodName, string loadingProgramPath,
string interpretationMessage, Exception e)
{
Debug.WriteLine($"ERROR{classname}|{callingMethodName}|{loadingProgramPath}|{interpretationMessage}");
var logger = LogManager.GetLogger("");
var innerExceptionNumber = 1;
@ -103,6 +80,7 @@ namespace Flow.Launcher.Plugin.Program.Logger
{
var logger = LogManager.GetLogger("");
logger.Error(e, $"fail to log exception in program logger, parts length is too small: {parts.Length}, message: {message}");
return;
}
var classname = parts[0];