From 956afcbaa6c36c7d6d7dd28bd8fb37f916a93181 Mon Sep 17 00:00:00 2001 From: connorivy <43247197+connorivy@users.noreply.github.com> Date: Fri, 14 Jul 2023 10:14:17 -0500 Subject: [PATCH] Fix(Revit): Better reporting of critical errors in Revit (#2771) * better error reporting * remove unused code * Included exception in logs + ensured stack trace from error eater * Added non user facing speckle exception --------- Co-authored-by: Connor Ivy Co-authored-by: Jedd Morgan <45512892+JR-Morgan@users.noreply.github.com> --- .../ConnectorRevit/Revit/ErrorEater.cs | 80 ++++++++++++------- .../UI/ConnectorBindingsRevit.Receive.cs | 29 ++++++- Core/Core/Logging/SpeckleException.cs | 1 + Core/Core/Logging/SpeckleLog.cs | 17 +++- .../Logging/SpeckleNonUserFacingException.cs | 16 ++++ .../DesktopUI2/ViewModels/StreamViewModel.cs | 25 ++++-- 6 files changed, 130 insertions(+), 38 deletions(-) create mode 100644 Core/Core/Logging/SpeckleNonUserFacingException.cs diff --git a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs index 7cd8c1b4f7..679be91ea6 100644 --- a/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs +++ b/ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs @@ -1,19 +1,17 @@ -using System; +using System; using System.Collections.Generic; -using System.Diagnostics; using System.Linq; -using System.Text; using Autodesk.Revit.DB; -using Speckle.ConnectorRevit.Entry; -using Speckle.ConnectorRevit.UI; using Speckle.Core.Kits; -using Speckle.Core.Models; +using Speckle.Core.Logging; namespace ConnectorRevit.Revit { public class ErrorEater : IFailuresPreprocessor { private ISpeckleConverter _converter; + private List _exceptions = new(); + public Dictionary CommitErrorsDict = new(); public ErrorEater(ISpeckleConverter converter) { @@ -22,47 +20,73 @@ 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, + // 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) //{ 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 SpeckleNonUserFacingException? GetException() + { + if (CommitErrorsDict.Count > 0 && _exceptions.Count > 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 25b682d9b6..2136295ad2 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,21 @@ 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(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.")); + } + g.Assimilate(); return (true, null); } @@ -132,9 +148,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 SpeckleNonUserFacingException: + throw exception; + default: + throw new SpeckleException(exception.Message, exception); + } } CurrentOperationCancellation = null; 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/SpeckleLog.cs b/Core/Core/Logging/SpeckleLog.cs index 2e8d601bdb..dda27c5044 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 (Exception ex) + { + Logger.Error(ex, "Unable to open log file folder at the following path, {path}", _logFolderPath); + } + } + private static void _addUserIdToGlobalContextFromDefaultAccount() { var machineName = Environment.MachineName; 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 734cc03b35..db5471c707 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,18 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call Type = NotificationType.Error }; break; - case SpeckleException _: + case SpeckleNonUserFacingException: + 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 {