Add logging of send conversions (#214)

* Added logging to IRootToHostConverter * Log send conversion errors --------- Co-authored-by: Dimitrie Stefanescu <didimitrie@gmail.com> Co-authored-by: Oğuzhan Koral <45078678+oguzhankoral@users.noreply.github.com>
specklesystems · Sep 2, 2024 · 9d6c914 · 9d6c914
1 parent 077ac24
commit 9d6c914
Show file tree

Hide file tree

Showing 5 changed files with 117 additions and 51 deletions.
diff --git a/Connectors/ArcGIS/Speckle.Connectors.ArcGIS3/Operations/Send/ArcGISRootObjectBuilder.cs b/Connectors/ArcGIS/Speckle.Connectors.ArcGIS3/Operations/Send/ArcGISRootObjectBuilder.cs
@@ -3,10 +3,12 @@
 using ArcGIS.Desktop.Framework.Threading.Tasks;
 using ArcGIS.Desktop.Internal.Mapping;
 using ArcGIS.Desktop.Mapping;
+using Microsoft.Extensions.Logging;
 using Speckle.Connectors.ArcGIS.HostApp;
 using Speckle.Connectors.Utils.Builders;
 using Speckle.Connectors.Utils.Caching;
 using Speckle.Connectors.Utils.Conversion;
+using Speckle.Connectors.Utils.Extensions;
 using Speckle.Connectors.Utils.Operations;
 using Speckle.Converters.ArcGIS3;
 using Speckle.Converters.Common;
@@ -28,18 +30,21 @@ public class ArcGISRootObjectBuilder : IRootObjectBuilder<MapMember>
   private readonly ISendConversionCache _sendConversionCache;
   private readonly ArcGISColorManager _colorManager;
   private readonly IConversionContextStack<ArcGISDocument, Unit> _contextStack;
+  private readonly ILogger<ArcGISRootObjectBuilder> _logger;
 
   public ArcGISRootObjectBuilder(
     ISendConversionCache sendConversionCache,
     ArcGISColorManager colorManager,
     IConversionContextStack<ArcGISDocument, Unit> contextStack,
-    IRootToSpeckleConverter rootToSpeckleConverter
+    IRootToSpeckleConverter rootToSpeckleConverter,
+    ILogger<ArcGISRootObjectBuilder> logger
   )
   {
     _sendConversionCache = sendConversionCache;
     _colorManager = colorManager;
     _contextStack = contextStack;
     _rootToSpeckleConverter = rootToSpeckleConverter;
+    _logger = logger;
   }
 
   public async Task<RootObjectBuilderResult> Build(
@@ -69,9 +74,10 @@ public async Task<RootObjectBuilderResult> Build(
     {
       ct.ThrowIfCancellationRequested();
       var collectionHost = rootObjectCollection;
-      var applicationId = mapMember.URI;
-      Base converted;
+      string applicationId = mapMember.URI;
+      string sourceType = mapMember.GetType().Name;
 
+      Base converted;
       try
       {
         int groupCount = nestedGroups.Count; // bake here, because count will change in the loop
@@ -147,12 +153,12 @@ mapMember is not GroupLayer
           parentCollection.Item2.elements.Add(converted);
         }
 
-        results.Add(new(Status.SUCCESS, applicationId, mapMember.GetType().Name, converted));
+        results.Add(new(Status.SUCCESS, applicationId, sourceType, converted));
       }
       catch (Exception ex) when (!ex.IsFatal())
       {
-        results.Add(new(Status.ERROR, applicationId, mapMember.GetType().Name, null, ex));
-        // POC: add logging
+        _logger.LogSendConversionError(ex, sourceType);
+        results.Add(new(Status.ERROR, applicationId, sourceType, null, ex));
       }
 
       onOperationProgressed?.Invoke("Converting", (double)++count / objects.Count);

diff --git a/...tors/Autocad/Speckle.Connectors.AutocadShared/Operations/Send/AutocadRootObjectBuilder.cs b/...tors/Autocad/Speckle.Connectors.AutocadShared/Operations/Send/AutocadRootObjectBuilder.cs
@@ -1,9 +1,12 @@
 using System.Diagnostics;
+using System.Diagnostics.CodeAnalysis;
 using Autodesk.AutoCAD.DatabaseServices;
+using Microsoft.Extensions.Logging;
 using Speckle.Connectors.Autocad.HostApp;
 using Speckle.Connectors.Utils.Builders;
 using Speckle.Connectors.Utils.Caching;
 using Speckle.Connectors.Utils.Conversion;
+using Speckle.Connectors.Utils.Extensions;
 using Speckle.Connectors.Utils.Operations;
 using Speckle.Converters.Common;
 using Speckle.Objects.Other;
@@ -26,6 +29,7 @@ public class AutocadRootObjectBuilder : IRootObjectBuilder<AutocadRootObject>
   private readonly AutocadLayerManager _layerManager;
   private readonly AutocadGroupManager _groupManager;
   private readonly ISyncToThread _syncToThread;
+  private readonly ILogger<AutocadRootObjectBuilder> _logger;
 
   public AutocadRootObjectBuilder(
     IRootToSpeckleConverter converter,
@@ -35,7 +39,8 @@ public AutocadRootObjectBuilder(
     AutocadColorManager colorManager,
     AutocadLayerManager layerManager,
     AutocadGroupManager groupManager,
-    ISyncToThread syncToThread
+    ISyncToThread syncToThread,
+    ILogger<AutocadRootObjectBuilder> logger
   )
   {
     _converter = converter;
@@ -46,14 +51,19 @@ ISyncToThread syncToThread
     _layerManager = layerManager;
     _groupManager = groupManager;
     _syncToThread = syncToThread;
+    _logger = logger;
   }
 
-  // It is already simplified but has many different references since it is a builder. Do not know can we simplify it now.
-  // Later we might consider to refactor proxies from one proxy manager? but we do not know the shape of it all potential
-  // proxy classes yet. So I'm disabling this with pragma now!!!
-#pragma warning disable CA1506
+  [SuppressMessage(
+    "Maintainability",
+    "CA1506:Avoid excessive class coupling",
+    Justification = """
+      It is already simplified but has many different references since it is a builder. Do not know can we simplify it now.
+      Later we might consider to refactor proxies from one proxy manager? but we do not know the shape of it all potential
+      proxy classes yet. So I'm supressing this one now!!!
+      """
+  )]
   public Task<RootObjectBuilderResult> Build(
-#pragma warning restore CA1506
     IReadOnlyList<AutocadRootObject> objects,
     SendInfo sendInfo,
     Action<string, double?>? onOperationProgressed = null,
@@ -90,6 +100,7 @@ public Task<RootObjectBuilderResult> Build(
       foreach (var (entity, applicationId) in atomicObjects)
       {
         ct.ThrowIfCancellationRequested();
+        string sourceType = entity.GetType().ToString();
         try
         {
           Base converted;
@@ -117,12 +128,13 @@ public Task<RootObjectBuilderResult> Build(
           }
 
           layer.elements.Add(converted);
-          results.Add(new(Status.SUCCESS, applicationId, entity.GetType().ToString(), converted));
+          results.Add(new(Status.SUCCESS, applicationId, sourceType, converted));
         }
         catch (Exception ex) when (!ex.IsFatal())
         {
-          results.Add(new(Status.ERROR, applicationId, entity.GetType().ToString(), null, ex));
-          // POC: add logging
+          _logger.LogSendConversionError(ex, sourceType);
+
+          results.Add(new(Status.ERROR, applicationId, sourceType, null, ex));
         }
         onOperationProgressed?.Invoke("Converting", (double)++count / atomicObjects.Count);
       }

diff --git a/Connectors/Revit/Speckle.Connectors.RevitShared/Operations/Send/RevitRootObjectBuilder.cs b/Connectors/Revit/Speckle.Connectors.RevitShared/Operations/Send/RevitRootObjectBuilder.cs
@@ -1,10 +1,12 @@
 using System.Diagnostics;
 using Autodesk.Revit.DB;
+using Microsoft.Extensions.Logging;
 using Speckle.Connectors.DUI.Exceptions;
 using Speckle.Connectors.Revit.HostApp;
 using Speckle.Connectors.Utils.Builders;
 using Speckle.Connectors.Utils.Caching;
 using Speckle.Connectors.Utils.Conversion;
+using Speckle.Connectors.Utils.Extensions;
 using Speckle.Connectors.Utils.Operations;
 using Speckle.Converters.Common;
 using Speckle.Converters.RevitShared.Helpers;
@@ -24,14 +26,16 @@ public class RevitRootObjectBuilder : IRootObjectBuilder<ElementId>
   private readonly ISyncToThread _syncToThread;
   private readonly ElementUnpacker _elementUnpacker;
   private readonly SendCollectionManager _sendCollectionManager;
+  private readonly ILogger<RevitRootObjectBuilder> _logger;
 
   public RevitRootObjectBuilder(
     IRootToSpeckleConverter converter,
     IRevitConversionContextStack conversionContextStack,
     ISendConversionCache sendConversionCache,
     ISyncToThread syncToThread,
     ElementUnpacker elementUnpacker,
-    SendCollectionManager sendCollectionManager
+    SendCollectionManager sendCollectionManager,
+    ILogger<RevitRootObjectBuilder> logger
   )
   {
     _converter = converter;
@@ -40,6 +44,7 @@ SendCollectionManager sendCollectionManager
     _syncToThread = syncToThread;
     _elementUnpacker = elementUnpacker;
     _sendCollectionManager = sendCollectionManager;
+    _logger = logger;
 
     _rootObject = new Collection()
     {
@@ -89,7 +94,8 @@ public Task<RootObjectBuilderResult> Build(
       foreach (Element revitElement in atomicObjects)
       {
         ct.ThrowIfCancellationRequested();
-        var applicationId = revitElement.UniqueId; // NOTE: converter set applicationIds to unique ids; if we ever change this in the converter, behaviour here needs to match.
+        string applicationId = revitElement.UniqueId; // NOTE: converter set applicationIds to unique ids; if we ever change this in the converter, behaviour here needs to match.
+        string sourceType = revitElement.GetType().Name;
         try
         {
           Base converted;
@@ -106,11 +112,12 @@ public Task<RootObjectBuilderResult> Build(
 
           var collection = _sendCollectionManager.GetAndCreateObjectHostCollection(revitElement, _rootObject);
           collection.elements.Add(converted);
-          results.Add(new(Status.SUCCESS, applicationId, revitElement.GetType().Name, converted));
+          results.Add(new(Status.SUCCESS, applicationId, sourceType, converted));
         }
         catch (Exception ex) when (!ex.IsFatal())
         {
-          results.Add(new(Status.ERROR, applicationId, revitElement.GetType().Name, null, ex));
+          _logger.LogSendConversionError(ex, sourceType);
+          results.Add(new(Status.ERROR, applicationId, sourceType, null, ex));
         }
 
         onOperationProgressed?.Invoke("Converting", (double)++countProgress / atomicObjects.Count);

diff --git a/Connectors/Rhino/Speckle.Connectors.RhinoShared/Operations/Send/RhinoRootObjectBuilder.cs b/Connectors/Rhino/Speckle.Connectors.RhinoShared/Operations/Send/RhinoRootObjectBuilder.cs
@@ -1,17 +1,20 @@
+using Microsoft.Extensions.Logging;
 using Rhino;
 using Rhino.DocObjects;
 using Speckle.Connectors.DUI.Models.Card.SendFilter;
 using Speckle.Connectors.Rhino.HostApp;
 using Speckle.Connectors.Utils.Builders;
 using Speckle.Connectors.Utils.Caching;
 using Speckle.Connectors.Utils.Conversion;
+using Speckle.Connectors.Utils.Extensions;
 using Speckle.Connectors.Utils.Instances;
 using Speckle.Connectors.Utils.Operations;
 using Speckle.Converters.Common;
 using Speckle.Sdk;
 using Speckle.Sdk.Logging;
 using Speckle.Sdk.Models;
 using Speckle.Sdk.Models.Collections;
+using Speckle.Sdk.Models.Instances;
 using Layer = Rhino.DocObjects.Layer;
 
 namespace Speckle.Connectors.Rhino.Operations.Send;
@@ -30,6 +33,7 @@ public class RhinoRootObjectBuilder : IRootObjectBuilder<RhinoObject>
   private readonly RhinoMaterialManager _materialManager;
   private readonly RhinoColorManager _colorManager;
   private readonly ISyncToThread _syncToThread;
+  private readonly ILogger<RhinoRootObjectBuilder> _logger;
 
   public RhinoRootObjectBuilder(
     ISendConversionCache sendConversionCache,
@@ -40,7 +44,8 @@ public RhinoRootObjectBuilder(
     IRootToSpeckleConverter rootToSpeckleConverter,
     RhinoMaterialManager materialManager,
     RhinoColorManager colorManager,
-    ISyncToThread syncToThread
+    ISyncToThread syncToThread,
+    ILogger<RhinoRootObjectBuilder> logger
   )
   {
     _sendConversionCache = sendConversionCache;
@@ -52,6 +57,7 @@ ISyncToThread syncToThread
     _materialManager = materialManager;
     _colorManager = colorManager;
     _syncToThread = syncToThread;
+    _logger = logger;
   }
 
   public Task<RootObjectBuilderResult> Build(
@@ -94,37 +100,8 @@ public Task<RootObjectBuilderResult> Build(
           Layer layer = _contextStack.Current.Document.Layers[rhinoObject.Attributes.LayerIndex];
           versionLayers.Add(layer);
           Collection collectionHost = _layerManager.GetHostObjectCollection(layer, rootObjectCollection);
-          string applicationId = rhinoObject.Id.ToString();
-
-          try
-          {
-            // get from cache or convert:
-            // What we actually do here is check if the object has been previously converted AND has not changed.
-            // If that's the case, we insert in the host collection just its object reference which has been saved from the prior conversion.
-            Base converted;
-            if (rhinoObject is InstanceObject)
-            {
-              converted = instanceProxies[applicationId];
-            }
-            else if (_sendConversionCache.TryGetValue(sendInfo.ProjectId, applicationId, out ObjectReference value))
-            {
-              converted = value;
-            }
-            else
-            {
-              converted = _rootToSpeckleConverter.Convert(rhinoObject);
-              converted.applicationId = applicationId;
-            }
-
-            // add to host
-            collectionHost.elements.Add(converted);
-
-            results.Add(new(Status.SUCCESS, applicationId, rhinoObject.ObjectType.ToString(), converted));
-          }
-          catch (Exception ex) when (!ex.IsFatal())
-          {
-            results.Add(new(Status.ERROR, applicationId, rhinoObject.ObjectType.ToString(), null, ex));
-          }
+
+          results.Add(ConvertRhinoObject(rhinoObject, collectionHost, instanceProxies, sendInfo));
 
           ++count;
           onOperationProgressed?.Invoke("Converting", (double)count / atomicObjects.Count);
@@ -149,4 +126,45 @@ public Task<RootObjectBuilderResult> Build(
       // 5. profit
       return new RootObjectBuilderResult(rootObjectCollection, results);
     });
+
+  private SendConversionResult ConvertRhinoObject(
+    RhinoObject rhinoObject,
+    Collection collectionHost,
+    IReadOnlyDictionary<string, InstanceProxy> instanceProxies,
+    SendInfo sendInfo
+  )
+  {
+    string applicationId = rhinoObject.Id.ToString();
+    string sourceType = rhinoObject.ObjectType.ToString();
+    try
+    {
+      // get from cache or convert:
+      // What we actually do here is check if the object has been previously converted AND has not changed.
+      // If that's the case, we insert in the host collection just its object reference which has been saved from the prior conversion.
+      Base converted;
+      if (rhinoObject is InstanceObject)
+      {
+        converted = instanceProxies[applicationId];
+      }
+      else if (_sendConversionCache.TryGetValue(sendInfo.ProjectId, applicationId, out ObjectReference value))
+      {
+        converted = value;
+      }
+      else
+      {
+        converted = _rootToSpeckleConverter.Convert(rhinoObject);
+        converted.applicationId = applicationId;
+      }
+
+      // add to host
+      collectionHost.elements.Add(converted);
+
+      return new(Status.SUCCESS, applicationId, sourceType, converted);
+    }
+    catch (Exception ex) when (!ex.IsFatal())
+    {
+      _logger.LogSendConversionError(ex, sourceType);
+      return new(Status.ERROR, applicationId, sourceType, null, ex);
+    }
+  }
 }
diff --git a/Sdk/Speckle.Connectors.Utils/Extensions/RootObjectBuilderExtensions.cs b/Sdk/Speckle.Connectors.Utils/Extensions/RootObjectBuilderExtensions.cs
@@ -0,0 +1,23 @@
+using Microsoft.Extensions.Logging;
+using Speckle.Connectors.Utils.Builders;
+using Speckle.Sdk;
+
+namespace Speckle.Connectors.Utils.Extensions;
+
+public static class RootObjectBuilderExtensions
+{
+  public static void LogSendConversionError<T>(
+    this ILogger<IRootObjectBuilder<T>> logger,
+    Exception ex,
+    string objectType
+  )
+  {
+    LogLevel logLevel = ex switch
+    {
+      SpeckleException => LogLevel.Information, //If it's too noisy, we could demote to LogLevel.Debug
+      _ => LogLevel.Error
+    };
+
+    logger.Log(logLevel, ex, "Conversion of object {objectType} was not successful", objectType);
+  }
+}