Skip to content

Commit

Permalink
Fix(Revit): Better reporting of critical errors in Revit (#2771)
Browse files Browse the repository at this point in the history 
* 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 <[email protected]>
Co-authored-by: Jedd Morgan <[email protected]>
  • Loading branch information
@connorivy @JR-Morgan
3 people authored Jul 14, 2023
1 parent d165793 commit 956afcb
Show file tree
Hide file tree
Showing 6 changed files with 130 additions and 38 deletions.
80 changes: 52 additions & 28 deletions ConnectorRevit/ConnectorRevit/Revit/ErrorEater.cs
View file
Original file line number Diff line number Diff line change
@@ -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<Exception> _exceptions = new();
public Dictionary<string, int> CommitErrorsDict = new();

public ErrorEater(ISpeckleConverter converter)
{
Expand All @@ -22,47 +20,73 @@ public ErrorEater(ISpeckleConverter converter)

public FailureProcessingResult PreprocessFailures(FailuresAccessor failuresAccessor)
{
IList<FailureMessageAccessor> failList = new List<FailureMessageAccessor>();
var criticalFails = 0;
var resolvedFailures = 0;
var failedElements = new List<ElementId>();
// 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;
}
}
}
29 changes: 25 additions & 4 deletions ConnectorRevit/ConnectorRevit/UI/ConnectorBindingsRevit.Receive.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand All @@ -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);
}
Expand All @@ -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;
Expand Down
1 change: 1 addition & 0 deletions Core/Core/Logging/SpeckleException.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,3 +34,4 @@ public SpeckleException(string message, bool log, SentryLevel level = SentryLeve
public List<KeyValuePair<string, object>> GraphQLErrors { get; set; }
#endregion
}

17 changes: 16 additions & 1 deletion Core/Core/Logging/SpeckleLog.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -106,6 +106,8 @@ public static ILogger Logger

private static bool _initialized = false;

private static string _logFolderPath;

/// <summary>
/// Initialize logger configuration for a global Serilog.Log logger.
/// </summary>
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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;
Expand Down
16 changes: 16 additions & 0 deletions Core/Core/Logging/SpeckleNonUserFacingException.cs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,16 @@
#nullable enable
using System;

namespace Speckle.Core.Logging;

/// <summary>
/// These are exceptions who's message is not user friendly
/// </summary>
public class SpeckleNonUserFacingException : SpeckleException
{
public SpeckleNonUserFacingException() { }

public SpeckleNonUserFacingException(string? message) : base(message) { }

public SpeckleNonUserFacingException(string? message, Exception? innerException) : base(message, innerException) { }
}
25 changes: 20 additions & 5 deletions DesktopUI2/DesktopUI2/ViewModels/StreamViewModel.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Expand All @@ -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.
Expand All @@ -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
Expand All @@ -1502,7 +1506,7 @@ public static void HandleCommandException(Exception ex, bool isUserCancel, [Call
Type = NotificationType.Warning
};
break;
case SpeckleGraphQLException<StreamData> _:
case SpeckleGraphQLException<StreamData>:
// NOTE: GraphQL requests for StreamData are expected to fail for a variety of reasons
logLevel = LogEventLevel.Warning;
notificationViewModel = new PopUpNotificationViewModel
Expand All @@ -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
{
Expand Down

0 comments on commit 956afcb

Please sign in to comment.