diff --git a/pyproject.toml b/pyproject.toml index f034a5e98..7b714fedd 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -26,7 +26,6 @@ dependencies = [ "pyOSC3@git+https://github.com/glopesdev/pyosc3.git@master", "newscale@git+https://github.com/AllenNeuralDynamics/python-newscale@axes-on-target", "aind-auto-train@git+https://github.com/AllenNeuralDynamics/aind-foraging-behavior-bonsai-automatic-training.git@main", - "aind-slims-api@git+https://github.com/AllenNeuralDynamics/aind-slims-api@main", "aind-dynamic-foraging-models >= 0.12.2", "aind-dynamic-foraging-basic-analysis >= 0.3.34", "aind-behavior-services >=0.8, <0.9", @@ -48,6 +47,7 @@ dependencies = [ "winkerberos; sys_platform == 'win32'", "ldap3; sys_platform == 'win32'", "msal; sys_platform == 'win32'", + "log-schema==0.2.10.dev1" ] [project.optional-dependencies] diff --git a/src/foraging_gui/Foraging.py b/src/foraging_gui/Foraging.py index c9baca1bf..27f08ebbf 100644 --- a/src/foraging_gui/Foraging.py +++ b/src/foraging_gui/Foraging.py @@ -28,10 +28,11 @@ 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 -from aind_slims_api import SlimsClient, models from matplotlib.backends.backend_qt5agg import ( NavigationToolbar2QT as NavigationToolbar, ) @@ -238,9 +239,6 @@ def __init__(self, parent=None, box_number=1, start_bonsai_ide=True): # Connect to Bonsai self._InitializeBonsai() - # connect to Slims - self._ConnectSlims() - # Set up threads self.threadpool = QThreadPool() # get animal response self.threadpool2 = QThreadPool() # get animal lick @@ -351,6 +349,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 +366,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 +1616,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,11 +1984,17 @@ 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, "add_default_project_name": True, "check_schedule": False, + "waterlog_exe_path": "C://Program Files/AIBS_MPE/waterlog/waterlog.exe", } # Try to load the ForagingSettings.json file @@ -2097,71 +2126,8 @@ def _GetSettings(self): ] self.rig_name = "{}".format(self.current_box) - def _ConnectSlims(self): - """ - Connect to Slims - """ - try: - logging.info("Attempting to connect to Slims") - self.slims_client = SlimsClient( - username=os.environ["SLIMS_USERNAME"], - password=os.environ["SLIMS_PASSWORD"], - ) - except KeyError as e: - raise KeyError( - "SLIMS_USERNAME and SLIMS_PASSWORD do not exist as " - f"environment variables on machine. Please add. {e}" - ) - - try: - self.slims_client.fetch_model( - models.SlimsMouseContent, barcode="00000000" - ) - except Exception as e: - if "Status 401 – Unauthorized" in str( - e - ): # catch error if username and password are incorrect - raise Exception( - f"Exception trying to read from Slims: {e}.\n" - f" Please check credentials:\n" - f"Username: {os.environ['SLIMS_USERNAME']}\n" - f"Password: {os.environ['SLIMS_PASSWORD']}" - ) - elif "No record found" not in str( - e - ): # bypass if mouse doesn't exist - raise Exception(f"Exception trying to read from Slims: {e}.\n") - logging.info("Successfully connected to Slims") - - def _AddWaterLogResult(self, session: Session): - """ - Add WaterLogResult to slims based on current state of gui - - :param session: Session object to pull water information from - - """ - - try: # try and find mouse - logging.info( - f"Attempting to fetch mouse {session.subject_id} from Slims" - ) - mouse = self.slims_client.fetch_model( - models.SlimsMouseContent, barcode=session.subject_id - ) - except Exception as e: - if "No record found" in str( - e - ): # if no mouse found or validation errors on mouse - logging.warning( - f'"No record found" error while trying to fetch mouse {session.subject_id}. ' - f"Will not log water." - ) - return - else: - logging.error( - f"While fetching mouse {session.subject_id} model, unexpected error occurred: {e}" - ) - raise e + def _AddWaterlogResult(self, session: Session): + """Send weight/water information to databases via waterlog app cli""" # extract water information logging.info("Extracting water information from first stimulus epoch") @@ -2171,53 +2137,41 @@ def _AddWaterLogResult(self, session: Session): for k, v in water_json } - # extract software information + # extract software information to send to waterlog once it can accept it logging.info("Extracting software information from first data stream") software = session.stimulus_epochs[0].software[0] + # Access sw name/version with (software.url, software.version) + + waterlog_args = [ + self.Settings['waterlog_exe_path'], + '--username', + self.behavior_session_model.experimenter[0], + '--mouse-id', + session.subject_id, + '--mouse-weight', + session.animal_weight_post, + '--comment', + session.notes, + '--earned-water', + water["water_in_session_total"], + '--water-supplement-ml', + water["water_after_session"], + '--water-supplement-delivered', + ] - # create model - logging.info( - "Creating SlimsWaterlogResult based on session information." - ) - print(water) - model = models.SlimsWaterlogResult( - mouse_pk=mouse.pk, - date=datetime.now(), - weight_g=session.animal_weight_post, - operator=self.behavior_session_model.experimenter[0], - water_earned_ml=water["water_in_session_total"], - water_supplement_delivered_ml=water["water_after_session"], - water_supplement_recommended_ml=None, - total_water_ml=water["water_in_session_total"]+water["water_after_session"], - comments=session.notes, - workstation=session.rig_id, - sw_source=software.url, - sw_version=software.version, - test_pk=self.slims_client.fetch_pk( - "Test", test_name="test_waterlog" - ), - ) + logging.info("Sending water info to waterlog") + process = subprocess.run([str(arg) for arg in waterlog_args]) - # check if mouse already has waterlog for at session time and if, so update model - logging.info( - f"Fetching previous waterlog for mouse {session.subject_id}" - ) - waterlog = self.slims_client.fetch_models( - models.SlimsWaterlogResult, mouse_pk=mouse.pk, start=0, end=1 - ) - if waterlog != [] and waterlog[0].date.strftime( - "%Y-%m-%d %H:%M:%S" - ) == session.session_start_time.astimezone(timezone.utc).strftime( - "%Y-%m-%d %H:%M:%S" - ): - logging.info( - "Waterlog information already exists for this session. Updating waterlog in Slims." - ) - model.pk = waterlog[0].pk - self.slims_client.update_model(model=model) - else: - logging.info("Adding waterlog to Slims.") - self.slims_client.add_model(model) + QMessageBox.information(self, "Waterlog", "Go to waterlog app to submit water information.") + + try: + process.check_returncode() + except Exception: + logging.warning( + f"Waterlog data for mouse {self.behavior_session_model.subject} cannot be sent to waterlog exe" + f", message: {process.stdout}, {process.stderr}", + exc_info=True, + ) def _InitializeBonsai(self): """ @@ -3937,7 +3891,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( @@ -4171,7 +4125,7 @@ def _Save(self, ForceSave=0, SaveAs=0, SaveContinue=0, BackupSave=0): # save random reward parameters Obj['random_reward_par']=self.RandomReward_dialog.random_reward_par - # generate the metadata file and update slims + # generate the metadata file and update waterlog try: # save the metadata collected in the metadata dialogue self.Metadata_dialog._save_metadata_dialog_parameters() @@ -4218,13 +4172,19 @@ def _Save(self, ForceSave=0, SaveAs=0, SaveContinue=0, BackupSave=0): ] and session is not None ): - self._AddWaterLogResult(session) + self._AddWaterlogResult(session) elif self.BaseWeight.text() == "" or self.WeightAfter.text() == "": - logging.warning(f"Waterlog for mouse {self.behavior_session_model.subject} cannot be added to slims" + logging.warning(f"Waterlog for mouse {self.behavior_session_model.subject} cannot be added to database" f" due do unrecorded weight information.") elif session is None: - logging.warning(f"Waterlog for mouse {self.behavior_session_model.subject} cannot be added to slims" + logging.warning(f"Waterlog for mouse {self.behavior_session_model.subject} cannot be added to database" 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 +6146,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 +6605,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 +7399,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. diff --git a/src/foraging_gui/settings_model.py b/src/foraging_gui/settings_model.py index a2f2edfc0..77dac0bfd 100644 --- a/src/foraging_gui/settings_model.py +++ b/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