IfcClash now has logging and fix bug where exclude clash filters on large files was very slow

src/blenderbim/blenderbim/bim/module/clash/prop.py

@@ -41,7 +41,7 @@ class BIMClashProperties(PropertyGroup):
     blender_clash_set_a: CollectionProperty(name="Blender Clash Set A", type=StrProperty)
     blender_clash_set_b: CollectionProperty(name="Blender Clash Set B", type=StrProperty)
     clash_sets: CollectionProperty(name="Clash Sets", type=ClashSet)
-    should_create_clash_snapshots: BoolProperty(name="Create Snapshots", default=True)
+    should_create_clash_snapshots: BoolProperty(name="Create Snapshots", default=False)
     clash_results_path: StringProperty(name="Clash Results Path")
     smart_grouped_clashes_path: StringProperty(name="Smart Grouped Clashes Path")
     active_clash_set_index: IntProperty(name="Active Clash Set Index")

src/ifcclash/ifcclash/collider.py

@@ -1,4 +1,3 @@
-
 # IfcClash - IFC-based clash detection.
 # Copyright (C) 2020, 2021 Dion Moult <dion@thinkmoult.com>
 #
@@ -23,14 +22,20 @@ import ifcopenshell
 
 
 class Collider:
-    def __init__(self):
+    def __init__(self, logger):
+        self.logger = logger
         self.groups = {}
         self.tree = ifcopenshell.geom.tree()
 
     def create_group(self, name):
+        self.logger.info(f"Creating group {name}")
         self.groups[name] = {"elements": {}, "objects": {}}
 
     def create_objects(self, name, ifc_file, iterator, elements):
+        import time
+
+        start = time.time()
+        self.logger.info(f"Adding objects {name}")
         assert iterator.initialize()
         while True:
             self.tree.add_element(iterator.get_native())
@@ -38,7 +43,11 @@ class Collider:
             self.create_object(name, shape.guid, shape)
             if not iterator.next():
                 break
+        self.logger.info(f"Tree finished {time.time() - start}")
+        start = time.time()
         self.groups[name]["elements"].update({e.GlobalId: e for e in elements})
+        self.logger.info(f"Element metadata finished {time.time() - start}")
+        start = time.time()
 
     def create_object(self, group_name, id, shape):
         obj = hppfcl.CollisionObject(
@@ -53,6 +62,10 @@ class Collider:
         return self.collide_narrowphase(name1, name2, self.collide_broadphase(name1, name2))
 
     def collide_broadphase(self, name1, name2):
+        import time
+
+        start = time.time()
+        self.logger.info("Starting broadphase")
         potential_collisions = []
         checked_collisions = set()
         for id, element in self.groups[name1]["elements"].items():
@@ -64,9 +77,14 @@ class Collider:
                 if e.GlobalId not in checked_collisions and e.GlobalId in self.groups[name2]["elements"]
             ]
             potential_collisions.extend(pairs)
+        self.logger.info(f"Finished broadphase {time.time() - start}")
         return potential_collisions
 
     def collide_narrowphase(self, name1, name2, potential_collisions):
+        import time
+
+        start = time.time()
+        self.logger.info("Starting narrowphase")
         collisions = []
         for data in potential_collisions:
             result = hppfcl.CollisionResult()
@@ -78,6 +96,7 @@ class Collider:
             )
             if result.isCollision():
                 collisions.append({"id1": data["id1"], "id2": data["id2"], "collision": result})
+        self.logger.info(f"Finished narrowphase {time.time() - start}")
         return collisions
 
     def create_transform(self, m):

src/ifcclash/ifcclash/ifcclash.py

@@ -36,7 +36,7 @@ class Clasher:
         self.settings = settings
         self.geom_settings = ifcopenshell.geom.settings()
         self.clash_sets = []
-        self.collider = collider.Collider()
+        self.collider = collider.Collider(self.settings.logger)
         self.selector = ifcopenshell.util.selector.Selector()
         self.ifcs = {}
 
@@ -83,23 +83,32 @@ class Clasher:
         clash_set["clashes"] = processed_results
 
     def load_ifc(self, path):
+        import time
+
+        start = time.time()
+        self.settings.logger.info(f"Loading IFC {path}")
         ifc = self.ifcs.get(path, None)
         if not ifc:
             ifc = ifcopenshell.open(path)
             self.ifcs[path] = ifc
+        self.settings.logger.info(f"Loading finished {time.time() - start}")
         return ifc
 
     def add_collision_objects(self, name, ifc_file, mode=None, selector=None):
+        import time
+
+        start = time.time()
+        self.settings.logger.info("Creating iterator")
         if not mode:
             elements = ifc_file.by_type("IfcElement")
         elif mode == "e":
-            exclude = self.selector.parse(ifc_file, selector)
+            elements = set(ifc_file.by_type("IfcElement")) - set(self.selector.parse(ifc_file, selector))
-            elements = [e for e in ifc_file.by_type("IfcElement") if e not in exclude]
         elif mode == "i":
             elements = self.selector.parse(ifc_file, selector)
         iterator = ifcopenshell.geom.iterator(
             self.geom_settings, ifc_file, multiprocessing.cpu_count(), include=elements
         )
+        self.settings.logger.info(f"Iterator creation finished {time.time() - start}")
         self.collider.create_objects(name, ifc_file, iterator, elements)
 
     def export(self):
@@ -205,11 +214,15 @@ class Clasher:
 
         for clash_set in clash_sets:
             if not "clashes" in clash_set.keys():
-                print(f"Skipping clash set [{clash_set['name']}] since it contains no clash results.")
+                self.settings.logger.info(
+                    f"Skipping clash set [{clash_set['name']}] since it contains no clash results."
+                )
                 continue
             clashes = clash_set["clashes"]
             if len(clashes) == 0:
-                print(f"Skipping clash set [{clash_set['name']}] since it contains no clash results.")
+                self.settings.logger.info(
+                    f"Skipping clash set [{clash_set['name']}] since it contains no clash results."
+                )
                 continue
 
             count_of_input_clashes += len(clashes)
@@ -272,9 +285,8 @@ class Clasher:
                 i += 1
 
         count_of_final_clash_sets = len(output_clash_sets)
-        print(
+        self.settings.logger.info(
-            f"Took {count_of_input_clashes} clashes in {count_of_clash_sets} clash sets and turned",
+            f"Took {count_of_input_clashes} clashes in {count_of_clash_sets} clash sets and turned them into {count_of_smart_groups} smart groups in {count_of_final_clash_sets} clash sets"
-            f"them into {count_of_smart_groups} smart groups in {count_of_final_clash_sets} clash sets",
         )
 
         return output_clash_sets