Put slice-time in slice-data-sharing.

part of CURA-10299

plugins/CuraEngineBackend/CuraEngineBackend.py

@@ -143,7 +143,7 @@ class CuraEngineBackend(QObject, Backend):
         self._last_num_objects = defaultdict(int) #type: Dict[int, int] # Count number of objects to see if there is something changed
         self._postponed_scene_change_sources = [] #type: List[SceneNode] # scene change is postponed (by a tool)
 
-        self._slice_start_time = None #type: Optional[float]
+        self._time_start_process = None #type: Optional[float]
         self._is_disabled = False #type: bool
 
         application.getPreferences().addPreference("general/auto_slice", False)
@@ -171,10 +171,24 @@ class CuraEngineBackend(QObject, Backend):
         )
         self._slicing_error_message.actionTriggered.connect(self._reportBackendError)
 
+        self._resetLastSliceTimeStats()
         self._snapshot = None #type: Optional[QImage]
 
         application.initializationFinished.connect(self.initialize)
 
+    def _resetLastSliceTimeStats(self) -> None:
+        self._time_start_process = None
+        self._time_send_message = None
+        self._time_end_slice = None
+
+    def resetAndReturnLastSliceTimeStats(self) -> Dict[str, float]:
+        return {
+            "time_start_process": self._time_start_process,
+            "time_send_message": self._time_send_message,
+            "time_end_slice": self._time_end_slice
+        }
+        self._resetLastSliceTimeStats()
+
     def initialize(self) -> None:
         application = CuraApplication.getInstance()
         self._multi_build_plate_model = application.getMultiBuildPlateModel()
@@ -288,7 +302,7 @@ class CuraEngineBackend(QObject, Backend):
         self._createSnapshot()
 
         Logger.log("i", "Starting to slice...")
-        self._slice_start_time = time()
+        self._time_start_process = time()
         if not self._build_plates_to_be_sliced:
             self.processingProgress.emit(1.0)
             Logger.log("w", "Slice unnecessary, nothing has changed that needs reslicing.")
@@ -512,8 +526,10 @@ class CuraEngineBackend(QObject, Backend):
         # Notify the user that it's now up to the backend to do it's job
         self.setState(BackendState.Processing)
 
-        if self._slice_start_time:
-            Logger.log("d", "Sending slice message took %s seconds", time() - self._slice_start_time )
+        # Handle time reporting.
+        self._time_send_message = time()
+        if self._time_start_process:
+            Logger.log("d", "Sending slice message took %s seconds", self._time_send_message - self._time_start_process)
 
     def determineAutoSlicing(self) -> bool:
         """Determine enable or disable auto slicing. Return True for enable timer and False otherwise.
@@ -750,6 +766,7 @@ class CuraEngineBackend(QObject, Backend):
 
         self.setState(BackendState.Done)
         self.processingProgress.emit(1.0)
+        self._time_end_slice = time()
 
         try:
             gcode_list = self._scene.gcode_dict[self._start_slice_job_build_plate] #type: ignore #Because we generate this attribute dynamically.
@@ -766,8 +783,8 @@ class CuraEngineBackend(QObject, Backend):
             gcode_list[index] = replaced
 
         self._slicing = False
-        if self._slice_start_time:
-            Logger.log("d", "Slicing took %s seconds", time() - self._slice_start_time )
+        if self._time_start_process:
+            Logger.log("d", "Slicing took %s seconds", time() - self._time_start_process)
         Logger.log("d", "Number of models per buildplate: %s", dict(self._numObjectsPerBuildPlate()))
 
         # See if we need to process the sliced layers job.

plugins/SliceInfoPlugin/SliceInfo.py

@@ -1,4 +1,4 @@
-# Copyright (c) 2021 Ultimaker B.V.
+# Copyright (c) 2023 UltiMaker B.V.
 # Cura is released under the terms of the LGPLv3 or higher.
 
 import json
@@ -27,7 +27,7 @@ catalog = i18nCatalog("cura")
 
 
 class SliceInfo(QObject, Extension):
-    """This Extension runs in the background and sends several bits of information to the Ultimaker servers.
+    """This Extension runs in the background and sends several bits of information to the UltiMaker servers.
 
     The data is only sent when the user in question gave permission to do so. All data is anonymous and
     no model files are being sent (Just a SHA256 hash of the model).
@@ -277,6 +277,26 @@ class SliceInfo(QObject, Extension):
             # Send the name of the output device type that is used.
             data["output_to"] = type(output_device).__name__
 
+            # Engine Statistics (Slicing Time, ...)
+            # Call it backend-time, sice we might want to get the actual slice time from the engine itself,
+            #   to also identify problems in between the users pressing the button and the engine actually starting
+            #   (and the other way around with data that arrives back from the engine).
+            time_setup = 0.0
+            time_backend = 0.0
+            if not print_information.preSliced:
+                backend_info = self._application.getBackend().resetAndReturnLastSliceTimeStats()
+                time_start_process = backend_info["time_start_process"]
+                time_send_message = backend_info["time_send_message"]
+                time_end_slice = backend_info["time_end_slice"]
+                if time_start_process and time_send_message and time_end_slice:
+                    time_setup = time_send_message - time_start_process
+                    time_backend = time_end_slice - time_send_message
+            data["engine_stats"] = {
+                "is_presliced": int(print_information.preSliced),
+                "time_setup": int(round(time_setup)),
+                "time_backend": int(round(time_backend)),
+            }
+
             # Convert data to bytes
             binary_data = json.dumps(data).encode("utf-8")
 

plugins/SliceInfoPlugin/example_data.html

@@ -1,3 +1,7 @@
+<!-- Copyright (c) 2023 UltiMaker B.V.
+     Cura is released under the terms of the LGPLv3 or higher.
+-->
+
 <html>
 <body>
     <b>Cura Version:</b> 4.8<br/>
@@ -63,11 +67,18 @@
 
     <h3>Print Times:</h3>
     <ul>
-        <li>Infill: 61200 sec.</li>
-        <li>Support: 25480 sec.</li>
-        <li>Travel: 6224 sec.</li>
-        <li>Walls: 10225 sec.</li>
-        <li>Total: 103129 sec.</li>
+        <li><b>Infill:</b> 61200 sec.</li>
+        <li><b>Support:</b> 25480 sec.</li>
+        <li><b>Travel:</b> 6224 sec.</li>
+        <li><b>Walls:</b> 10225 sec.</li>
+        <li><b>Total:</b> 103129 sec.</li>
+    </ul>
+
+    <h3>Engine Statistics:</h3>
+    <ul>
+        <li><b>Is Pre-Sliced:</b> no</li>
+        <li><b>Pre-Process Time:</b> 7 sec.</li>
+        <li><b>Slicing Time:</b> 69 sec.</li>
     </ul>
 </body>
 </html>