Merge pull request #1745 from AllenNeuralDynamics/feat-lifecycle-logs

Adds lifecycle logger to log start, complete, and failure logs

Author: micahwoodard

pyproject.toml

@@ -48,6 +48,7 @@ dependencies = [
     "winkerberos; sys_platform == 'win32'",
     "ldap3; sys_platform == 'win32'",
     "msal; sys_platform == 'win32'",
+    "log-schema==0.2.10.dev1"
 ]
 
 [project.optional-dependencies]

src/foraging_gui/Foraging.py

@@ -28,6 +28,8 @@
 import requests
 import serial
 import yaml
+
+import log_schema
 from aind_auto_train.schema.task import TrainingStage
 from aind_behavior_services.session import AindBehaviorSessionModel
 from aind_data_schema.core.session import Session
@@ -351,6 +353,9 @@ def __init__(self, parent=None, box_number=1, start_bonsai_ide=True):
 
         # load the rig metadata
         self._load_rig_metadata()
+        
+        # setup life-cycle logger
+        self.lifecycle_logger = self.setup_lifecycle_logger()
 
         # Initializes session log handler as None
         self.session_log_handler = None
@@ -365,6 +370,27 @@ def __init__(self, parent=None, box_number=1, start_bonsai_ide=True):
             self._ReconnectBonsai()
         logging.info("Start up complete")
 
+    def setup_lifecycle_logger(self) -> logging.Logger:
+        
+        """
+        Creates logger for start, stop, and failure events with formatter adhering to aind log standards.
+        """
+
+        # Ensure the directory exists
+        os.makedirs(Path(self.Settings["lifecycle_log_dir"]), exist_ok=True)
+
+        lifecycle_logger = logging.getLogger("lifecycle")
+        lifecycle_logger.setLevel(logging.INFO)
+
+        timestamp = datetime.now().strftime("%Y%m%dT%H%M%SZ")
+        filename = f"lifecycle_log_{timestamp}.jsonl"
+        file_handler = logging.FileHandler(os.path.join(self.Settings["lifecycle_log_dir"], filename), encoding="utf-8")
+        file_handler.setLevel(logging.INFO)
+        file_handler.setFormatter(log_schema.DefaultFormatter())
+        lifecycle_logger.addHandler(file_handler)
+
+        return lifecycle_logger
+
     def _load_rig_metadata(self):
         """Load the latest rig metadata"""
 
@@ -1594,6 +1620,7 @@ def _restartlogging(self, log_folder=None,start_from_camera=False):
             self.Save.setStyleSheet(
                 "color: white;background-color : mediumorchid"
             )
+
         else:
             # temporary logging
             loggingtype = 1
@@ -1961,6 +1988,11 @@ def _GetSettings(self):
                 "aind_watchdog_service",
                 "manifest",
             ),
+            "lifecycle_log_dir": os.path.join(
+                os.path.expanduser("~"),
+                "Documents",
+                "lifecycle_logs",
+            ),
             "transfer_service_job_type": "dynamic_foraging_compression",
             "auto_engage": True,
             "clear_figure_after_save": True,
@@ -3937,7 +3969,7 @@ def _Save(self, ForceSave=0, SaveAs=0, SaveContinue=0, BackupSave=0):
         if self.CreateNewFolder == 1:
             self._GetSaveFolder()
             self.CreateNewFolder = 0
-
+            
         if not os.path.exists(os.path.dirname(self.SaveFileJson)):
             os.makedirs(os.path.dirname(self.SaveFileJson))
             logging.info(
@@ -4225,6 +4257,12 @@ def _Save(self, ForceSave=0, SaveAs=0, SaveContinue=0, BackupSave=0):
                 elif session is None:
                     logging.warning(f"Waterlog for mouse {self.behavior_session_model.subject} cannot be added to slims"
                                   f" due do metadata generation failure.")
+                    
+                # add complete log to lifecycle 
+                self.lifecycle_logger.info("Session ended.", extra={"subject_id": self.behavior_session_model.subject, 
+                                                                      "acquisition_name": self.behavior_session_model.session_name,
+                                                                      "event_type": "stage_complete"})
+                
         except Exception as e:
             logging.warning(
                 "Meta data is not saved!",
@@ -6186,6 +6224,10 @@ def _Start(self):
                 # Start logging if the formal logging is not started
                 if self.logging_type != 0:
                     self.Ot_log_folder = self._restartlogging()
+                # Need to log start event after session_name has been set in_restartlogging
+                self.lifecycle_logger.info("Session started.", extra={"subject_id": self.behavior_session_model.subject, 
+                                                                "acquisition_name": self.behavior_session_model.session_name,
+                                                                "event_type": "stage_start"})
             except Exception as e:
                 if "ConnectionAbortedError" in str(e):
                     logging.info("lost bonsai connection: restartlogging()")
@@ -6641,6 +6683,9 @@ def _StartTrialLoop(self, GeneratedTrials, worker1, worker_save):
                         self.ANewTrial = 1
                         self.Start.setChecked(False)
                         self.Start.setStyleSheet("background-color : none")
+                        self.lifecycle_logger.info("Session failed.", extra={"subject_id": self.behavior_session_model.subject, 
+                                                                      "acquisition_name": self.behavior_session_model.session_name,
+                                                                      "event_type": "stage_failure"})
                         break
                 # receive licks and update figures
                 if self.actionDrawing_after_stopping.isChecked() == False:
@@ -7432,7 +7477,6 @@ def setup_loki_logging(box_number):
     handler.setLevel(logging.INFO)
     logger.root.addHandler(handler)
 
-
 def start_gui_log_file(box_number):
     """
     Starts a log file for the gui.

src/foraging_gui/settings_model.py

@@ -1,7 +1,7 @@
 from typing import Literal, Optional
 
 from pydantic import BaseModel, Field
-
+from pathlib import Path
 
 class BonsaiSettingsModel(BaseModel):
     """
@@ -182,6 +182,7 @@ class DFTSettingsModel(BaseModel):
     save_each_trial: bool
     AutomaticUpload: bool
     manifest_flag_dir: str
+    lifecycle_log_dir: Path
     transfer_service_job_type: str
     auto_engage: bool
     clear_figure_after_save: bool