STAR-322: Improving logging and cluster connection

cura/OAuth2/AuthorizationService.py

@@ -52,7 +52,8 @@ class AuthorizationService:
         if not self._user_profile:
             # If no user profile was stored locally, we try to get it from JWT.
             self._user_profile = self._parseJWT()
-        if not self._user_profile:
+
+        if not self._user_profile and self._auth_data:
             # If there is still no user profile from the JWT, we have to log in again.
             Logger.log("w", "The user profile could not be loaded. The user must log in again!")
             self.deleteAuthData()

plugins/UM3NetworkPrinting/src/Cloud/CloudApiClient.py

@@ -2,6 +2,7 @@
 # Cura is released under the terms of the LGPLv3 or higher.
 import json
 from json import JSONDecodeError
+from time import time
 from typing import Callable, List, Type, TypeVar, Union, Optional, Tuple, Dict, Any
 
 from PyQt5.QtCore import QUrl
@@ -38,6 +39,8 @@ class CloudApiClient:
         self._account = account
         self._on_error = on_error
         self._upload = None  # type: Optional[MeshUploader]
+        # in order to avoid garbage collection we keep the callbacks in this list.
+        self._anti_gc_callbacks = []  # type: List[Callable[[QNetworkReply], None]]
 
     ## Gets the account used for the API.
     @property
@@ -49,8 +52,7 @@ class CloudApiClient:
     def getClusters(self, on_finished: Callable[[List[CloudClusterResponse]], Any]) -> None:
         url = "{}/clusters".format(self.CLUSTER_API_ROOT)
         reply = self._manager.get(self._createEmptyRequest(url))
-        callback = self._wrapCallback(reply, on_finished, CloudClusterResponse)
+        self._addCallbacks(reply, on_finished, CloudClusterResponse)
-        reply.finished.connect(callback)
 
     ## Retrieves the status of the given cluster.
     #  \param cluster_id: The ID of the cluster.
@@ -58,8 +60,7 @@ class CloudApiClient:
     def getClusterStatus(self, cluster_id: str, on_finished: Callable[[CloudClusterStatus], Any]) -> None:
         url = "{}/clusters/{}/status".format(self.CLUSTER_API_ROOT, cluster_id)
         reply = self._manager.get(self._createEmptyRequest(url))
-        callback = self._wrapCallback(reply, on_finished, CloudClusterStatus)
+        self._addCallbacks(reply, on_finished, CloudClusterStatus)
-        reply.finished.connect(callback)
 
     ## Requests the cloud to register the upload of a print job mesh.
     #  \param request: The request object.
@@ -69,8 +70,7 @@ class CloudApiClient:
         url = "{}/jobs/upload".format(self.CURA_API_ROOT)
         body = json.dumps({"data": request.toDict()})
         reply = self._manager.put(self._createEmptyRequest(url), body.encode())
-        callback = self._wrapCallback(reply, on_finished, CloudPrintJobResponse)
+        self._addCallbacks(reply, on_finished, CloudPrintJobResponse)
-        reply.finished.connect(callback)
 
     ## Requests the cloud to register the upload of a print job mesh.
     #  \param upload_response: The object received after requesting an upload with `self.requestUpload`.
@@ -90,8 +90,7 @@ class CloudApiClient:
     def requestPrint(self, cluster_id: str, job_id: str, on_finished: Callable[[CloudPrintResponse], Any]) -> None:
         url = "{}/clusters/{}/print/{}".format(self.CLUSTER_API_ROOT, cluster_id, job_id)
         reply = self._manager.post(self._createEmptyRequest(url), b"")
-        callback = self._wrapCallback(reply, on_finished, CloudPrintResponse)
+        self._addCallbacks(reply, on_finished, CloudPrintResponse)
-        reply.finished.connect(callback)
 
     ##  We override _createEmptyRequest in order to add the user credentials.
     #   \param url: The URL to request
@@ -116,9 +115,10 @@ class CloudApiClient:
             Logger.log("i", "Received a reply %s from %s with %s", status_code, reply.url().toString(), response)
             return status_code, json.loads(response)
         except (UnicodeDecodeError, JSONDecodeError, ValueError) as err:
-            error = {"code": type(err).__name__, "title": str(err), "http_code": str(status_code)}
+            error = CloudErrorObject(code=type(err).__name__, title=str(err), http_code=str(status_code),
+                                     id=str(time()), http_status="500")
             Logger.logException("e", "Could not parse the stardust response: %s", error)
-            return status_code, {"errors": [error]}
+            return status_code, {"errors": [error.toDict()]}
 
     ## The generic type variable used to document the methods below.
     Model = TypeVar("Model", bound=BaseModel)
@@ -143,12 +143,15 @@ class CloudApiClient:
     #  \param on_finished: The callback in case the response is successful.
     #  \param model: The type of the model to convert the response to. It may either be a single record or a list.
     #  \return: A function that can be passed to the
-    def _wrapCallback(self,
+    def _addCallbacks(self,
                       reply: QNetworkReply,
                       on_finished: Callable[[Union[Model, List[Model]]], Any],
                       model: Type[Model],
-                      ) -> Callable[[QNetworkReply], None]:
+                      ) -> None:
         def parse() -> None:
             status_code, response = self._parseReply(reply)
+            self._anti_gc_callbacks.remove(parse)
             return self._parseModels(response, on_finished, model)
-        return parse
+
+        self._anti_gc_callbacks.append(parse)
+        reply.finished.connect(parse)

plugins/UM3NetworkPrinting/src/Cloud/CloudOutputDevice.py

@@ -18,6 +18,7 @@ from cura.CuraApplication import CuraApplication
 from cura.PrinterOutput.NetworkedPrinterOutputDevice import AuthState, NetworkedPrinterOutputDevice
 from cura.PrinterOutput.PrinterOutputModel import PrinterOutputModel
 from plugins.UM3NetworkPrinting.src.Cloud.CloudOutputController import CloudOutputController
+from src.Cloud.Models.CloudClusterResponse import CloudClusterResponse
 from ..MeshFormatHandler import MeshFormatHandler
 from ..UM3PrintJobOutputModel import UM3PrintJobOutputModel
 from .CloudProgressMessage import CloudProgressMessage
@@ -84,18 +85,15 @@ class CloudOutputDevice(NetworkedPrinterOutputDevice):
     #  \param api_client: The client that will run the API calls
     #  \param device_id: The ID of the device (i.e. the cluster_id for the cloud API)
     #  \param parent: The optional parent of this output device.
-    def __init__(self, api_client: CloudApiClient, device_id: str, host_name: str, parent: QObject = None) -> None:
+    def __init__(self, api_client: CloudApiClient, cluster: CloudClusterResponse, parent: QObject = None) -> None:
-        super().__init__(device_id = device_id, address = "", properties = {}, parent = parent)
+        super().__init__(device_id = cluster.cluster_id, address = "", properties = {}, parent = parent)
         self._api = api_client
-        self._host_name = host_name
+        self._cluster = cluster
 
         self._setInterfaceElements()
 
-        self._device_id = device_id
         self._account = api_client.account
 
-        CuraApplication.getInstance().getBackend().backendStateChange.connect(self._onBackendStateChange)
-
         # We use the Cura Connect monitor tab to get most functionality right away.
         self._monitor_view_qml_path = os.path.join(os.path.dirname(os.path.abspath(__file__)),
                                                    "../../resources/qml/MonitorStage.qml")
@@ -124,7 +122,14 @@ class CloudOutputDevice(NetworkedPrinterOutputDevice):
         self._mesh = None  # type: Optional[bytes]
         self._uploaded_print_job = None  # type: Optional[CloudPrintJobResponse]
 
+    def connect(self) -> None:
+        super().connect()
+        Logger.log("i", "Connected to cluster %s", self.key)
+        CuraApplication.getInstance().getBackend().backendStateChange.connect(self._onBackendStateChange)
+
     def disconnect(self) -> None:
+        super().disconnect()
+        Logger.log("i", "Disconnected to cluster %s", self.key)
         CuraApplication.getInstance().getBackend().backendStateChange.disconnect(self._onBackendStateChange)
 
     def _onBackendStateChange(self, _: BackendState) -> None:
@@ -133,19 +138,19 @@ class CloudOutputDevice(NetworkedPrinterOutputDevice):
 
     ## Gets the host name of this device
     @property
-    def host_name(self) -> str:
+    def clusterData(self) -> CloudClusterResponse:
-        return self._host_name
+        return self._cluster
 
     ## Updates the host name of the output device
-    @host_name.setter
+    @clusterData.setter
-    def host_name(self, value: str) -> None:
+    def clusterData(self, value: CloudClusterResponse) -> None:
-        self._host_name = value
+        self._cluster = value
 
     ## Checks whether the given network key is found in the cloud's host name
     def matchesNetworkKey(self, network_key: str) -> bool:
         # A network key looks like "ultimakersystem-aabbccdd0011._ultimaker._tcp.local."
         # the host name should then be "ultimakersystem-aabbccdd0011"
-        return network_key.startswith(self._host_name)
+        return network_key.startswith(self.clusterData.host_name)
 
     ##  Set all the interface elements and texts for this output device.
     def _setInterfaceElements(self) -> None:
@@ -170,7 +175,7 @@ class CloudOutputDevice(NetworkedPrinterOutputDevice):
 
         if self._uploaded_print_job:
             # the mesh didn't change, let's not upload it again
-            self._api.requestPrint(self._device_id, self._uploaded_print_job.job_id, self._onPrintRequested)
+            self._api.requestPrint(self.key, self._uploaded_print_job.job_id, self._onPrintRequested)
             return
 
         # Indicate we have started sending a job.
@@ -194,12 +199,15 @@ class CloudOutputDevice(NetworkedPrinterOutputDevice):
     ##  Called when the network data should be updated.
     def _update(self) -> None:
         super()._update()
-        if self._last_response_time and time() - self._last_response_time < self.CHECK_CLUSTER_INTERVAL:
+        if self._last_request_time and time() - self._last_request_time < self.CHECK_CLUSTER_INTERVAL:
+            Logger.log("i", "Not updating: %s - %s < %s", time(), self._last_request_time, self.CHECK_CLUSTER_INTERVAL)
             return  # avoid calling the cloud too often
 
+        Logger.log("i", "Updating: %s - %s >= %s", time(), self._last_request_time, self.CHECK_CLUSTER_INTERVAL)
         if self._account.isLoggedIn:
             self.setAuthenticationState(AuthState.Authenticated)
-            self._api.getClusterStatus(self._device_id, self._onStatusCallFinished)
+            self._last_request_time = time()
+            self._api.getClusterStatus(self.key, self._onStatusCallFinished)
         else:
             self.setAuthenticationState(AuthState.NotAuthenticated)
 
@@ -315,7 +323,7 @@ class CloudOutputDevice(NetworkedPrinterOutputDevice):
     ## Requests the print to be sent to the printer when we finished uploading the mesh.
     def _onPrintJobUploaded(self) -> None:
         self._progress.update(100)
-        self._api.requestPrint(self._device_id, self._uploaded_print_job.job_id, self._onPrintRequested)
+        self._api.requestPrint(self.key, self._uploaded_print_job.job_id, self._onPrintRequested)
 
     ## Displays the given message if uploading the mesh has failed
     #  \param message: The message to display.

plugins/UM3NetworkPrinting/src/Cloud/CloudOutputDeviceManager.py

@@ -73,7 +73,8 @@ class CloudOutputDeviceManager:
 
         removed_devices, added_clusters, updates = findChanges(self._remote_clusters, online_clusters)
 
-        Logger.log("i", "Parsed remote clusters to %s", online_clusters)
+        Logger.log("i", "Parsed remote clusters to %s", [cluster.toDict() for cluster in online_clusters.values()])
+        Logger.log("i", "Removed: %s, added: %s, updates: %s", len(removed_devices), len(added_clusters), len(updates))
 
         # Remove output devices that are gone
         for removed_cluster in removed_devices:
@@ -86,12 +87,12 @@ class CloudOutputDeviceManager:
         # Add an output device for each new remote cluster.
         # We only add when is_online as we don't want the option in the drop down if the cluster is not online.
         for added_cluster in added_clusters:
-            device = CloudOutputDevice(self._api, added_cluster.cluster_id, added_cluster.host_name)
+            device = CloudOutputDevice(self._api, added_cluster)
             self._output_device_manager.addOutputDevice(device)
             self._remote_clusters[added_cluster.cluster_id] = device
 
         for device, cluster in updates:
-            device.host_name = cluster.host_name
+            device.clusterData = cluster
 
         self._connectToActiveMachine()
 
@@ -99,6 +100,7 @@ class CloudOutputDeviceManager:
     def _connectToActiveMachine(self) -> None:
         active_machine = CuraApplication.getInstance().getGlobalContainerStack()
         if not active_machine:
+            Logger.log("i", "no active machine")
             return
 
         # Check if the stored cluster_id for the active machine is in our list of remote clusters.
@@ -107,6 +109,7 @@ class CloudOutputDeviceManager:
             device = self._remote_clusters[stored_cluster_id]
             if not device.isConnected():
                 device.connect()
+            Logger.log("i", "Device connected by metadata %s", stored_cluster_id)
         else:
             self._connectByNetworkKey(active_machine)
 
@@ -122,6 +125,8 @@ class CloudOutputDeviceManager:
             active_machine.setMetaDataEntry(self.META_CLUSTER_ID, device.key)
             device.connect()
 
+        Logger.log("i", "Found cluster %s with network key %s", device, local_network_key)
+
     ## Handles an API error received from the cloud.
     #  \param errors: The errors received
     def _onApiError(self, errors: List[CloudErrorObject]) -> None:

plugins/UM3NetworkPrinting/src/ClusterUM3OutputDevice.py

@@ -390,10 +390,10 @@ class ClusterUM3OutputDevice(NetworkedPrinterOutputDevice):
 
     ##  Called when the connection to the cluster changes.
     def connect(self) -> None:
-        pass
         # TODO: uncomment this once cloud implementation works for testing
         # super().connect()
         # self.sendMaterialProfiles()
+        pass
 
     def _onGetPreviewImageFinished(self, reply: QNetworkReply) -> None:
         reply_url = reply.url().toString()

plugins/UM3NetworkPrinting/src/ClusterUM3PrinterOutputController.py

@@ -18,4 +18,3 @@ class ClusterUM3PrinterOutputController(PrinterOutputController):
     def setJobState(self, job: "PrintJobOutputModel", state: str):
         data = "{\"action\": \"%s\"}" % state
         self._output_device.put("print_jobs/%s/action" % job.key, data, on_finished=None)
-