extensive logging

Author: abestroka

src/opentrons_resources.py

@@ -31,44 +31,66 @@ def parse_logfile(self, ot_log):
         if not log_path.exists():
             raise FileNotFoundError(f"Log file not found: {log_path}")
 
+        self.logger.log("Log File" + log_path + " Grabbed")
         with open(log_path, 'r') as file:
             ot_log = json.load(file)
 
+        self.logger.log(ot_log)
+        
         #two passes, one for all "load labware" commands, and one for all actions
 
+        self.logger.log("Processing setup commands")
         self.process_setup_commands(ot_log)
-        
+        self.logger.log("Processing protocol commands")
         self.process_protocol_commands(ot_log)
 
     def process_setup_commands(self, ot_log):
         """process setup commands (loadLabware, loadPipette)"""
         commands = ot_log.get('commands', {}).get('data', [])
+        self.logger.log("COMMANDS")
+        self.logger.log(commands)
 
         for command in commands:
             cmd_type = command.get('commandType')
+            self.logger.log("COMMAND")
+            self.logger.log(command)
+            self.logger.log("COMMAND TYPE")
+            self.logger.log(cmd_type)
 
             if cmd_type == 'loadLabware':
+                self.logger.log("LOADING LABWARE")
                 self.load_labware(command, ot_log)
             elif cmd_type == 'loadPipette':
+                self.logger.log("LAODING PIPETTE")
                 self.load_pipette(command, ot_log)
 
 
 
     def process_protocol_commands(self, ot_log):
         """process protocol actions"""
         commands = ot_log.get('commands', {}).get('data', [])
+        self.logger.log("COMMANDS")
+        self.logger.log(commands)
 
         for command in commands:
             cmd_type = command.get('commandType')
+            self.logger.log("COMMAND")
+            self.logger.log(command)
+            self.logger.log("COMMAND TYPE")
+            self.logger.log(cmd_type)
 
             try:
                 if cmd_type == 'pickUpTip':
                     self.pick_up_tip(command, ot_log)
+                    self.logger.log("PICKING UP TIP")
                 elif cmd_type == 'aspirate':
+                    self.logger.log("ASPIRATING")
                     self.aspirate(command, ot_log)
                 elif cmd_type == 'dispense':
+                    self.logger.log("DISPENSING")
                     self.dispense(command, ot_log)
                 elif cmd_type == 'dropTip':
+                    self.logger.log("DROPPING TIP")
                     self.drop_tip(command, ot_log)
             except Exception as e:
                 error_msg = f"Error processing {cmd_type} at {command.get('id', 'unknown')}: {str(e)}"
@@ -78,6 +100,9 @@ def load_labware(self, command, ot_log):
         """loads labware, tracks labware present in each deck slot"""
         params = command.get('params', {})
         result = command.get('result', {})
+        self.logger.log("LABWARE PARAMS AND RESULT")
+        self.logger.log("PARAMS", params)
+        self.logger.log("RESULT", result)
 
         #get labware id
         location = params.get('location', {})
@@ -86,23 +111,31 @@ def load_labware(self, command, ot_log):
         #string number 1-11
         slot_name = location.get('slotName', 'unknown')
 
+        self.logger.log("LOCATION, LOADNAME, AND SLOT NAME")
+        self.logger.log("LOCATION", location)
+        self.logger.log("LOADNAME", load_name)
+        self.logger.log("SLOTNAME", slot_name)
+
         #find matching id
         labware_id = None
         display_name = load_name
         for labware in ot_log.get('data', {}).get('labware', []):
             if (labware.get('loadName') == load_name and
                 labware.get('location', {}).get('slotName') == slot_name):
                 labware_id = labware.get('id')
+                self.logger.log("MATCHING ID FOUND")
                 break
 
         if not labware_id:
+            self.logger.log("MATCHING ID NOT FOUND")
             #just in case not found
             labware_id = f"labware_{slot_name}_{load_name}"
 
         slot_name = location.get('slotName', 'unknown')
 
 
         #store info
+        self.logger.log("STORING LABWARE INFO")
         self.labware_id_to_info[labware_id] = {
             'load_name': load_name,
             'display_name': display_name,
@@ -112,14 +145,21 @@ def load_labware(self, command, ot_log):
         }
 
         #get or create labware in deck slot
+        self.logger.log("LOOK FOR SLOT NAME IN DECK SLOTS")
+        self.logger.log("SLOT NAME", slot_name)
+        self.logger.log("DECK SLOTS", self.deck_slots)
         if slot_name in self.deck_slots:
+            self.logger.log("FOUND SLOT RESOURCE", slot_resource)
             slot_resource = self.deck_slots[slot_name]
             try:
             #    #check if slot already has labware (child)
             #    # query for existing labware in slot
 
             #    # Grid resource if tip rack
+                self.logger.log("CHECKING IF RESOURCE IS A TIP RACK")
+                self.logger.log("LOAD NAME LOWER", load_name.lower())
                 if 'tip' in load_name.lower():
+                    self.logger.log("IS TIP RACK")
                    #tip rack always 8x12 grid
             #        labware_resource = Grid(
             #            resource_name = f"{self.node_name}_{display_name}_{slot_name}",
@@ -133,18 +173,25 @@ def load_labware(self, command, ot_log):
             #            }
             #        )
             #        labware_resource = self.client.add_resource(labware_resource)
-
+                    self.logger.log("CREATING TIP RACK RESOURCE FROM TEMPLATE")
+                    self.logger.log("TEMPLATE NAME", load_name)
+                    self.logger.log("RESOURCE NAME", labware_id)
                     labware_resource = self.client.create_resource_from_template(
                         template_name = load_name,
                         resource_name = labware_id
                         )
 
 
                     #set as child of the deck slot
+                    self.logger.log("LABWARE RESOURCE", labware_resource)
+                    self.logger.log("SETTING LABWARE RESOURCE AS CHILD OF DECK SLOT")
+                    self.logger.log("SLOT RESOURCE", slot_resource)
                     self.client.set_child(resource=slot_resource, key="labware", child=labware_resource)
                     self.labware_id_to_resource[labware_id] = labware_resource
 
                 elif 'plate' in load_name.lower() or 'well' in load_name.loawer():
+                    self.logger.log("RESOURCE IS A PLATE")
+                    self.logger.log("LOAD NAME LOWER", load_name.lower())
                    #plate as grid, either 96 or 384
                     if '96' in load_name:
                        rows, cols = 8, 12
@@ -166,15 +213,23 @@ def load_labware(self, command, ot_log):
                     #     }
                     # )
                     # labware_resource = self.client.add_resource(labware_resource)
+                    self.logger.log("CREATING PLATE RESOURCE FROM TEMPLATE")
+                    self.logger.log("TEMPLATE NAME", load_name)
+                    self.logger.log("RESOURCE NAME", labware_id)
                     labware_resource = self.client.create_resource_from_template(
                         template_name = load_name,
                         resource_name = labware_id
                         )
+                    
+                    self.logger.log("LABWARE RESOURCE", labware_resource)
+                    self.logger.log("SETTING LABWARE RESOURCE AS CHILD OF DECK SLOT")
+                    self.logger.log("SLOT RESOURCE", slot_resource)
 
                     self.client.set_child(resource=slot_resource, key="labware", child=labware_resource)
                     self.labware_id_to_resource[labware_id] = labware_resource
 
                 else:
+                    self.logger.log("REGISTERING AS NEITHER PLATE OR TIP RACK")
                     #TODO: add addional labware types, tuberacks and modules etc, generic container for now
                     # labware_resource = Container(
                     #     resource_name=f"{self.node_name}_{display_name}_{slot_name}",
@@ -204,6 +259,10 @@ def load_pipette(self, command, ot_log):
         params = command.get('params', {})
         result = command.get('result', {})
 
+        self.logger.log("PIPETTE PARAMS AND RESULT")
+        self.logger.log("PARAMS", params)
+        self.logger.log("RESULT", result)
+
         pipette_id = result.get('pipetteId', params.get('pipetteId'))
         mount = params.get('mount', 'unknown')
         pipette_name = params.get('pipetteName', 'unknown')

src/ot2_rest_node.py

@@ -48,6 +48,8 @@ def startup_handler(self) -> None:
         # Create templates
         self._create_ot2_templates()
 
+        #TODO: delete instances if already exist
+
         # Create deck instance
         self.deck = self.resource_client.create_resource_from_template(
             template_name="ot2_deck",