From a597b3a2ff2cf6582ae22765987271b5f316aada Mon Sep 17 00:00:00 2001 From: Connor Ivy Date: Thu, 13 Jul 2023 14:48:41 -0500 Subject: [PATCH 1/4] better error reporting --- .../ConnectorRevit/Revit/ErrorEater.cs | 77 ++++++++++++++----- .../UI/ConnectorBindingsRevit.Receive.cs | 26 ++++++- Core/Core/Logging/SpeckleLog.cs | 17 +++- .../DesktopUI2/ViewModels/StreamViewModel.cs | 11 +++ 4 files changed, 105 insertions(+), 26 deletions(-) diff --git a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs index 7cd8c1b4f7..6670edded9 100644 --- a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs +++ b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs @@ -1,12 +1,16 @@ -using System; +using System; using System.Collections.Generic; using System.Diagnostics; using System.Linq; using System.Text; using Autodesk.Revit.DB; +using Autodesk.Revit.DB.Visual; +using DesktopUI2.Models; +using DesktopUI2.ViewModels; using Speckle.ConnectorRevit.Entry; using Speckle.ConnectorRevit.UI; using Speckle.Core.Kits; +using Speckle.Core.Logging; using Speckle.Core.Models; namespace ConnectorRevit.Revit @@ -14,7 +18,10 @@ namespace ConnectorRevit.Revit public class ErrorEater : IFailuresPreprocessor { private ISpeckleConverter _converter; + private List _exceptions = new(); + public Dictionary CommitErrorsDict = new(); + public AggregateException? AggregateException { get; private set; } public ErrorEater(ISpeckleConverter converter) { _converter = converter; @@ -22,11 +29,10 @@ public ErrorEater(ISpeckleConverter converter) public FailureProcessingResult PreprocessFailures(FailuresAccessor failuresAccessor) { - IList failList = new List(); - var criticalFails = 0; + var resolvedFailures = 0; var failedElements = new List(); // Inside event handler, get all warnings - failList = failuresAccessor.GetFailureMessages(); + var failList = failuresAccessor.GetFailureMessages(); foreach (FailureMessageAccessor failure in failList) { // check FailureDefinitionIds against ones that you want to dismiss, @@ -35,34 +41,63 @@ public FailureProcessingResult PreprocessFailures(FailuresAccessor failuresAcces //if (failID == BuiltInFailures.RoomFailures.RoomNotEnclosed) //{ var t = failure.GetDescriptionText(); - _converter.Report.LogConversionError(new Exception(t)); var s = failure.GetSeverity(); - if (s == FailureSeverity.Warning) continue; + if (s == FailureSeverity.Warning) + { + // just delete the warnings for now + failuresAccessor.DeleteWarning(failure); + resolvedFailures++; + continue; + } + try { failuresAccessor.ResolveFailure(failure); + resolvedFailures++; } - catch (Exception e) + catch { - // currently, the whole commit is rolled back. this should be investigated further at a later date - // to properly proceed with commit - failedElements.AddRange(failure.GetFailingElementIds()); - //_converter.ConversionErrors.Clear(); - _converter.Report.LogConversionError(new Exception( - "Objects failed to bake due to a fatal error!\n" + - "This is likely due to scaling issues - please ensure you've set the correct units on your objects or remove any invalid objects.\n\n" + - "Revit error: " + t)); - // logging the error - var exception = - new Speckle.Core.Logging.SpeckleException("Revit commit failed: " + t, e, - level: Sentry.SentryLevel.Warning); - return FailureProcessingResult.ProceedWithCommit; + var idsToDelete = failure.GetFailingElementIds().ToList(); + + if (failuresAccessor.IsElementsDeletionPermitted(idsToDelete)) + { + failuresAccessor.DeleteElements(idsToDelete); + resolvedFailures++; + } + else + { + if (CommitErrorsDict.ContainsKey(t)) CommitErrorsDict[t]++; + else CommitErrorsDict.Add(t, 1); + // currently, the whole commit is rolled back. this should be investigated further at a later date + // to properly proceed with commit + failedElements.AddRange(failure.GetFailingElementIds()); + + // logging the error + var speckleEx = new SpeckleException($"Fatal Error: {t}"); + _exceptions.Add(speckleEx); + SpeckleLog.Logger.Fatal(speckleEx, "Fatal Error: {failureMessage}", t); + } } } failuresAccessor.DeleteAllWarnings(); - return FailureProcessingResult.Continue; + if (resolvedFailures > 0) return FailureProcessingResult.ProceedWithCommit; + else return FailureProcessingResult.Continue; + } + + public Exception? GetException() + { + if (CommitErrorsDict.Count > 1 && _exceptions.Count > 1) + { + return new AggregateException(_exceptions); + } + else if (CommitErrorsDict.Count == 1 && _exceptions.Count > 0) + { + return _exceptions[0]; + } + + return null; } } } diff --git a/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs b/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs index 25b682d9b6..44af0d9d8a 100644 --- a/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs +++ b/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs @@ -97,7 +97,8 @@ await elementTypeMapper.Map(state.Settings.FirstOrDefault(x => x.Slug == "receiv g.Start(); var failOpts = t.GetFailureHandlingOptions(); - failOpts.SetFailuresPreprocessor(new ErrorEater(converter)); + var errorEater = new ErrorEater(converter); + failOpts.SetFailuresPreprocessor(errorEater); failOpts.SetClearAfterRollback(true); t.SetFailureHandlingOptions(failOpts); t.Start(); @@ -113,6 +114,18 @@ await elementTypeMapper.Map(state.Settings.FirstOrDefault(x => x.Slug == "receiv previousObjects.AddConvertedElements(convertedObjects); t.Commit(); + + if (t.GetStatus() == TransactionStatus.RolledBack) + { + var numTotalErrors = errorEater.CommitErrorsDict.Sum(kvp => kvp.Value); + var numUniqueErrors = errorEater.CommitErrorsDict.Keys.Count; + + var exception = errorEater.GetException(); + if (exception == null) SpeckleLog.Logger.Warning("Revit commit failed with {numUniqueErrors} unique errors and {numTotalErrors} total errors, but the ErrorEater did not capture any exceptions", numUniqueErrors, numTotalErrors); + else SpeckleLog.Logger.Fatal("The Revit API could not resolve {numUniqueErrors} unique errors and {numTotalErrors} total errors when trying to commit the Speckle model. The whole transaction is being rolled back.", numUniqueErrors, numTotalErrors); + return (false, exception ?? new SpeckleException($"The Revit API could not resolve {numUniqueErrors} unique errors and {numTotalErrors} total errors when trying to commit the Speckle model. The whole transaction is being rolled back.")); + } + g.Assimilate(); return (true, null); } @@ -132,9 +145,14 @@ await elementTypeMapper.Map(state.Settings.FirstOrDefault(x => x.Slug == "receiv if (!success) { - //Don't wrap cancellation token (if it's ours!) - if (exception is OperationCanceledException && progress.CancellationToken.IsCancellationRequested) throw exception; - throw new SpeckleException(exception.Message, exception); + switch (exception) + { + case OperationCanceledException when progress.CancellationToken.IsCancellationRequested: + case AggregateException: + throw exception; + default: + throw new SpeckleException(exception.Message, exception); + } } CurrentOperationCancellation = null; diff --git a/Core/Core/Logging/SpeckleLog.cs b/Core/Core/Logging/SpeckleLog.cs index 2e8d601bdb..fb4514aaaa 100644 --- a/Core/Core/Logging/SpeckleLog.cs +++ b/Core/Core/Logging/SpeckleLog.cs @@ -106,6 +106,8 @@ public static ILogger Logger private static bool _initialized = false; + private static string _logFolderPath; + /// /// Initialize logger configuration for a global Serilog.Log logger. /// @@ -162,8 +164,9 @@ SpeckleLogConfiguration logConfiguration // if not, disable file sink, even if its enabled in the config // show a warning about that... var canLogToFile = true; + _logFolderPath = SpecklePathProvider.LogFolderPath(hostApplicationName, hostApplicationVersion); var logFilePath = Path.Combine( - SpecklePathProvider.LogFolderPath(hostApplicationName, hostApplicationVersion), + _logFolderPath, "SpeckleCoreLog.txt" ); var serilogLogConfiguration = new LoggerConfiguration().MinimumLevel @@ -227,6 +230,18 @@ SpeckleLogConfiguration logConfiguration return logger; } + public static void OpenCurrentLogFolder() + { + try + { + Process.Start(_logFolderPath); + } + catch + { + Logger.Error("Unable to open log file folder at the following path, {path}", _logFolderPath); + } + } + private static void _addUserIdToGlobalContextFromDefaultAccount() { var machineName = Environment.MachineName; diff --git a/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs b/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs index 734cc03b35..dcb9c217de 100644 --- a/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs +++ b/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs @@ -1512,6 +1512,17 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call Type = NotificationType.Error }; break; + case AggregateException _: + logLevel = LogEventLevel.Error; + notificationViewModel = new PopUpNotificationViewModel + { + Title = $"😖 {commandPrettyName} Failed!", + Message = "Click to open the log file for a detailed list of error messages", + OnClick = SpeckleLog.OpenCurrentLogFolder, + Type = NotificationType.Error, + Expiration = TimeSpan.FromSeconds(10) + }; + break; case SpeckleException _: logLevel = LogEventLevel.Error; notificationViewModel = new PopUpNotificationViewModel From 0827d787995124c68be82e318f277fa5ca1a1216 Mon Sep 17 00:00:00 2001 From: Connor Ivy Date: Thu, 13 Jul 2023 14:50:51 -0500 Subject: [PATCH 2/4] remove unused code --- ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs | 11 ----------- 1 file changed, 11 deletions(-) diff --git a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs index 6670edded9..5ee72d60b1 100644 --- a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs +++ b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs @@ -1,17 +1,9 @@ using System; using System.Collections.Generic; -using System.Diagnostics; using System.Linq; -using System.Text; using Autodesk.Revit.DB; -using Autodesk.Revit.DB.Visual; -using DesktopUI2.Models; -using DesktopUI2.ViewModels; -using Speckle.ConnectorRevit.Entry; -using Speckle.ConnectorRevit.UI; using Speckle.Core.Kits; using Speckle.Core.Logging; -using Speckle.Core.Models; namespace ConnectorRevit.Revit { @@ -19,9 +11,7 @@ public class ErrorEater : IFailuresPreprocessor { private ISpeckleConverter _converter; private List _exceptions = new(); - public Dictionary CommitErrorsDict = new(); - public AggregateException? AggregateException { get; private set; } public ErrorEater(ISpeckleConverter converter) { _converter = converter; @@ -81,7 +71,6 @@ public FailureProcessingResult PreprocessFailures(FailuresAccessor failuresAcces } } - failuresAccessor.DeleteAllWarnings(); if (resolvedFailures > 0) return FailureProcessingResult.ProceedWithCommit; else return FailureProcessingResult.Continue; } From 7806ce9c429beaab55635bcc6ed85001b85a307b Mon Sep 17 00:00:00 2001 From: Jedd Morgan <45512892+JR-Morgan@users.noreply.github.com> Date: Fri, 14 Jul 2023 15:45:27 +0100 Subject: [PATCH 3/4] Included exception in logs + ensured stack trace from error eater --- .../UI/ConnectorBindingsRevit.Receive.cs | 10 +++++++--- Core/Core/Logging/SpeckleLog.cs | 4 ++-- .../DesktopUI2/ViewModels/StreamViewModel.cs | 16 ++++++++++------ 3 files changed, 19 insertions(+), 11 deletions(-) diff --git a/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs b/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs index 44af0d9d8a..018c7962a4 100644 --- a/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs +++ b/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs @@ -121,8 +121,11 @@ await elementTypeMapper.Map(state.Settings.FirstOrDefault(x => x.Slug == "receiv var numUniqueErrors = errorEater.CommitErrorsDict.Keys.Count; var exception = errorEater.GetException(); - if (exception == null) SpeckleLog.Logger.Warning("Revit commit failed with {numUniqueErrors} unique errors and {numTotalErrors} total errors, but the ErrorEater did not capture any exceptions", numUniqueErrors, numTotalErrors); - else SpeckleLog.Logger.Fatal("The Revit API could not resolve {numUniqueErrors} unique errors and {numTotalErrors} total errors when trying to commit the Speckle model. The whole transaction is being rolled back.", numUniqueErrors, numTotalErrors); + if (exception == null) + SpeckleLog.Logger.Warning("Revit commit failed with {numUniqueErrors} unique errors and {numTotalErrors} total errors, but the ErrorEater did not capture any exceptions", numUniqueErrors, numTotalErrors); + else + SpeckleLog.Logger.Fatal(exception, "The Revit API could not resolve {numUniqueErrors} unique errors and {numTotalErrors} total errors when trying to commit the Speckle model. The whole transaction is being rolled back.", numUniqueErrors, numTotalErrors); + return (false, exception ?? new SpeckleException($"The Revit API could not resolve {numUniqueErrors} unique errors and {numTotalErrors} total errors when trying to commit the Speckle model. The whole transaction is being rolled back.")); } @@ -148,8 +151,9 @@ await elementTypeMapper.Map(state.Settings.FirstOrDefault(x => x.Slug == "receiv switch (exception) { case OperationCanceledException when progress.CancellationToken.IsCancellationRequested: - case AggregateException: throw exception; + case AggregateException: + throw new SpeckleException(null, exception); default: throw new SpeckleException(exception.Message, exception); } diff --git a/Core/Core/Logging/SpeckleLog.cs b/Core/Core/Logging/SpeckleLog.cs index fb4514aaaa..dda27c5044 100644 --- a/Core/Core/Logging/SpeckleLog.cs +++ b/Core/Core/Logging/SpeckleLog.cs @@ -236,9 +236,9 @@ public static void OpenCurrentLogFolder() { Process.Start(_logFolderPath); } - catch + catch (Exception ex) { - Logger.Error("Unable to open log file folder at the following path, {path}", _logFolderPath); + Logger.Error(ex, "Unable to open log file folder at the following path, {path}", _logFolderPath); } } diff --git a/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs b/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs index dcb9c217de..5b1b30713f 100644 --- a/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs +++ b/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs @@ -1469,7 +1469,11 @@ private void HandleCommandException(Exception ex, [CallerMemberName] string comm HandleCommandException(ex, Progress.CancellationToken.IsCancellationRequested, commandName); } - public static void HandleCommandException(Exception ex, bool isUserCancel, [CallerMemberName] string commandName = "UnknownCommand") + public static void HandleCommandException( + Exception ex, + bool isUserCancel, + [CallerMemberName] string commandName = "UnknownCommand" + ) { string commandPrettyName = commandName.EndsWith("Command") ? commandName.Substring(0, commandName.Length - "Command".Length) @@ -1479,7 +1483,7 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call INotification notificationViewModel; switch (ex) { - case OperationCanceledException _: + case OperationCanceledException: // NOTE: We expect an OperationCanceledException to occur when our CancellationToken is cancelled. // If our token wasn't cancelled, then this is highly unexpected, and treated with HIGH SEVERITY! // Likely, another deeper token was cancelled, and the exception wasn't handled correctly somewhere deeper. @@ -1492,7 +1496,7 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call Type = isUserCancel ? NotificationType.Success : NotificationType.Error }; break; - case InvalidOperationException _: + case InvalidOperationException: // NOTE: Hopefully, this means that the Receive/Send/Preview/etc. command could not START because of invalid state logLevel = LogEventLevel.Warning; notificationViewModel = new PopUpNotificationViewModel @@ -1502,7 +1506,7 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call Type = NotificationType.Warning }; break; - case SpeckleGraphQLException _: + case SpeckleGraphQLException: // NOTE: GraphQL requests for StreamData are expected to fail for a variety of reasons logLevel = LogEventLevel.Warning; notificationViewModel = new PopUpNotificationViewModel @@ -1512,7 +1516,7 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call Type = NotificationType.Error }; break; - case AggregateException _: + case SpeckleException when ex.Message is null: logLevel = LogEventLevel.Error; notificationViewModel = new PopUpNotificationViewModel { @@ -1523,7 +1527,7 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call Expiration = TimeSpan.FromSeconds(10) }; break; - case SpeckleException _: + case SpeckleException: logLevel = LogEventLevel.Error; notificationViewModel = new PopUpNotificationViewModel { From 142071c393a7b8de2a484e040b4252cc5e7656a7 Mon Sep 17 00:00:00 2001 From: Jedd Morgan <45512892+JR-Morgan@users.noreply.github.com> Date: Fri, 14 Jul 2023 16:13:54 +0100 Subject: [PATCH 4/4] Added non user facing speckle exception --- .../ConnectorRevit/Revit/ErrorEater.cs | 26 +++++++++---------- .../UI/ConnectorBindingsRevit.Receive.cs | 3 +-- Core/Core/Logging/SpeckleException.cs | 1 + .../Logging/SpeckleNonUserFacingException.cs | 16 ++++++++++++ .../DesktopUI2/ViewModels/StreamViewModel.cs | 2 +- 5 files changed, 32 insertions(+), 16 deletions(-) create mode 100644 Core/Core/Logging/SpeckleNonUserFacingException.cs diff --git a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs index 5ee72d60b1..679be91ea6 100644 --- a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs +++ b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs @@ -12,6 +12,7 @@ public class ErrorEater : IFailuresPreprocessor private ISpeckleConverter _converter; private List _exceptions = new(); public Dictionary CommitErrorsDict = new(); + public ErrorEater(ISpeckleConverter converter) { _converter = converter; @@ -25,7 +26,7 @@ public FailureProcessingResult PreprocessFailures(FailuresAccessor failuresAcces var failList = failuresAccessor.GetFailureMessages(); foreach (FailureMessageAccessor failure in failList) { - // check FailureDefinitionIds against ones that you want to dismiss, + // check FailureDefinitionIds against ones that you want to dismiss, //FailureDefinitionId failID = failure.GetFailureDefinitionId(); // prevent Revit from showing Unenclosed room warnings //if (failID == BuiltInFailures.RoomFailures.RoomNotEnclosed) @@ -57,8 +58,10 @@ public FailureProcessingResult PreprocessFailures(FailuresAccessor failuresAcces } else { - if (CommitErrorsDict.ContainsKey(t)) CommitErrorsDict[t]++; - else CommitErrorsDict.Add(t, 1); + if (CommitErrorsDict.ContainsKey(t)) + CommitErrorsDict[t]++; + else + CommitErrorsDict.Add(t, 1); // currently, the whole commit is rolled back. this should be investigated further at a later date // to properly proceed with commit failedElements.AddRange(failure.GetFailingElementIds()); @@ -71,21 +74,18 @@ public FailureProcessingResult PreprocessFailures(FailuresAccessor failuresAcces } } - if (resolvedFailures > 0) return FailureProcessingResult.ProceedWithCommit; - else return FailureProcessingResult.Continue; + if (resolvedFailures > 0) + return FailureProcessingResult.ProceedWithCommit; + else + return FailureProcessingResult.Continue; } - public Exception? GetException() + public SpeckleNonUserFacingException? GetException() { - if (CommitErrorsDict.Count > 1 && _exceptions.Count > 1) - { - return new AggregateException(_exceptions); - } - else if (CommitErrorsDict.Count == 1 && _exceptions.Count > 0) + if (CommitErrorsDict.Count > 0 && _exceptions.Count > 0) { - return _exceptions[0]; + return new SpeckleNonUserFacingException("Error eater was unable to resolve exceptions", new AggregateException(_exceptions)); } - return null; } } diff --git a/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs b/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs index 018c7962a4..2136295ad2 100644 --- a/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs +++ b/ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs @@ -151,9 +151,8 @@ await elementTypeMapper.Map(state.Settings.FirstOrDefault(x => x.Slug == "receiv switch (exception) { case OperationCanceledException when progress.CancellationToken.IsCancellationRequested: + case SpeckleNonUserFacingException: throw exception; - case AggregateException: - throw new SpeckleException(null, exception); default: throw new SpeckleException(exception.Message, exception); } diff --git a/Core/Core/Logging/SpeckleException.cs b/Core/Core/Logging/SpeckleException.cs index b049f69883..daf9ac8a6b 100644 --- a/Core/Core/Logging/SpeckleException.cs +++ b/Core/Core/Logging/SpeckleException.cs @@ -34,3 +34,4 @@ public SpeckleException(string message, bool log, SentryLevel level = SentryLeve public List> GraphQLErrors { get; set; } #endregion } + diff --git a/Core/Core/Logging/SpeckleNonUserFacingException.cs b/Core/Core/Logging/SpeckleNonUserFacingException.cs new file mode 100644 index 0000000000..de853439d8 --- /dev/null +++ b/Core/Core/Logging/SpeckleNonUserFacingException.cs @@ -0,0 +1,16 @@ +#nullable enable +using System; + +namespace Speckle.Core.Logging; + +/// +/// These are exceptions who's message is not user friendly +/// +public class SpeckleNonUserFacingException : SpeckleException +{ + public SpeckleNonUserFacingException() { } + + public SpeckleNonUserFacingException(string? message) : base(message) { } + + public SpeckleNonUserFacingException(string? message, Exception? innerException) : base(message, innerException) { } +} diff --git a/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs b/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs index 5b1b30713f..db5471c707 100644 --- a/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs +++ b/DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs @@ -1516,7 +1516,7 @@ public static void HandleCommandException( Type = NotificationType.Error }; break; - case SpeckleException when ex.Message is null: + case SpeckleNonUserFacingException: logLevel = LogEventLevel.Error; notificationViewModel = new PopUpNotificationViewModel {