search

AllenNeuralDynamics / dynamic-foraging-task

Bonsai/Harp workflow for Dynamic Foraging with Python GUI for visualization and control
MIT License
5 stars 4 forks source link

Percentage of same side lick intervals under 100 ms in Box ephys3A mouse 744330 exceeded 10% #1022

Open alexpiet opened 4 days ago

alexpiet commented 4 days ago

This issue was automatically generated from GUI logs.

file: MyFunctions.py
function: calculate_inter_lick_intervals
line 930
logfile: W10DT713883/W10DT713883-A_gui_log_2024-11-13_12-40-13.txt
boxes: ephys3
count: 8
text: Percentage of same side lick intervals under 100 ms in Box A mouse 744330 exceeded 10%

GUI Log snippet (click for full log)

02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6554724.724992, '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554724.727488, '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6554724.728384, 4, '127.0.0.1']
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554724.924896, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTime', 6554724.924, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6554724.924, '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedLeftWaterStartTime', 6554724.924, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardLeft', '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 6554724.927488, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.041504, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.175648, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.299008, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.426848, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.472, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.55648, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.600992, '127.0.0.1', 4003]
02:09:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 25.00%.
02:09:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 7.08%.
02:09:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 21.61%.
02:09:29 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box A mouse 744330 exceeded 10%

 Full GUI log (first 200 and last 200 lines)

12:40:13 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4679:Starting logfile!
12:40:13 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4690:Python version: 3.11.9 | packaged by Anaconda, Inc. | (main, Apr 19 2024, 16:40:41) [MSC v.1916 64 bit (AMD64)]
12:40:13 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4707:Current git commit branch, hash: main, 60f8beb5cf259b096e71331217b2a631d1eaeb43
12:40:13 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4711:Current foraging_gui version: 1.6.9
12:40:13 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4721:local repository is clean
12:40:13 PM:INFO:Foraging:Foraging.py:<module>:line 4822:Setting QApplication attributes
12:40:13 PM:INFO:Foraging:Foraging.py:<module>:line 4830:Starting QApplication and Window
12:40:13 PM:INFO:Foraging:Foraging.py:__init__:line 69:Creating Window
12:40:13 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1166:Loaded settings_box file
12:40:13 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1194:Loaded settings file
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (FIP_workflow_path), using default: 
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (FIP_settings), using default: C:\Users\svc_aind_ephys\Documents\FIPSettings
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (bonsai_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.exe
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (bonsaiworkflow_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\src\workflows\foraging.bonsai
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\metadata_dialog\
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\rig_metadata\
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (project_info_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\Project Name and Funding Source v2.csv
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box2), using default: 60
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box3), using default: 60
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box4), using default: 60
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box1), using default: 5000
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box2), using default: 5000
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box3), using default: 5000
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box4), using default: 5000
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\name_mapper.json
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (save_each_trial), using default: True
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (AutomaticUpload), using default: True
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_ephys\Documents\aind_watchdog_service\manifest
12:40:13 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (add_default_project_name), using default: True
12:40:13 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1092:Loaded behavior schedule
12:40:13 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
12:40:13 PM:INFO:Foraging:Foraging.py:_LoadRigJson:line 1536:Skipping rig metadata creation because create_rig_metadata=False
12:40:14 PM:INFO:Foraging:Foraging.py:_LoadUI:line 281:Using ForagingGUI_Ephys.ui interface
12:40:14 PM:INFO:Foraging:Foraging.py:__init__:line 119:Setting Window title: 323_EPHYS3
12:40:14 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1363:Trying to connect to already running Bonsai
12:40:14 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:40:15 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1367:Could not connect: timed out
12:40:15 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1376:Starting Bonsai
12:40:15 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4794:BONSAI logging starting
12:40:15 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:40:16 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 0.5 seconds: timed out
12:40:17 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:40:18 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 1.0 seconds: timed out
12:40:18 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:40:19 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 1.5 seconds: timed out
12:40:20 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:40:21 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 2.0 seconds: timed out
12:40:21 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:40:21 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1393:Connected to Bonsai after 2.5 seconds
12:40:21 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1394:Bonsai started successfully
12:40:21 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1273:Attempting to connect to Slims
12:40:22 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1290:Successfully connected to Slims
12:40:22 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 507:could not find water calibration parameters: C:\Users\svc_aind_ephys\Documents\ForagingSettings\WaterCalibrationPar_1.json
12:40:22 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:22 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 867:Scanning for newscale stages
12:40:22 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 882:found 1 newscale stages
12:40:22 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 906:Found the newscale stage from the settings file
12:40:22 PM:INFO:Foraging:Foraging.py:_connect_stage:line 933:Successfully connected to newscale stage: 46796
12:40:22 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 753:Checking stage connection
12:40:22 PM:INFO:Foraging:Foraging.py:_GetPositions:line 765:Grabbing current stage position
12:40:23 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1526:Found existing rig.json: rig_323_EPHYS3_2024-10-17.json
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.03 -> 0.057
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.03 -> 0.053
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterL, 0.03 -> 0.053
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterR, 0.03 -> 0.057
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.03 -> 0.057
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.03 -> 0.053
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterL, 0.03 -> 0.053
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterR, 0.03 -> 0.057
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionY,  -> 10111.0
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionX,  -> 4493.0
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionZ,  -> 9913.5
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:23 PM:INFO:Foraging:Foraging.py:__init__:line 219:Start up complete
12:40:24 PM:INFO:aws_util:aws_util.py:import_df_from_s3:line 115:Dataframe imported from s3://aind-behavior-data/foraging_nwb_bonsai_processed/df_sessions.pkl, len(df) = 5368
12:40:25 PM:INFO:aws_util:aws_util.py:import_df_from_s3:line 115:Dataframe imported from s3://aind-behavior-data/foraging_auto_training/df_manager_447_demo.pkl, len(df) = 3936
12:40:26 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
12:40:26 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
12:40:26 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_ephys/.aind_auto_train/curriculum_manager/
12:40:26 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_ephys/.aind_auto_train/curriculum_manager/
12:40:26 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2386:No entry found in df_training_manager for subject_id: 0
12:40:26 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2734:Override stage clicked: state=2
12:40:26 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2760:Current stage to apply: unknown training stage @unknown curriculum
12:40:30 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3599:Stopping current trials
12:40:38 PM:INFO:Foraging:Foraging.py:_Open:line 2966:Quick load success: D:\BehaviorData\323_EPHYS3\744329\behavior_744329_2024-10-31_13-58-00\behavior\744329_2024-10-31_13-58-00.json
12:40:38 PM:INFO:Foraging:Foraging.py:_NewSession:line 3509:New Session pressed
12:40:38 PM:INFO:Foraging:Foraging.py:_NewSession:line 3541:Resetting session run flag
12:40:38 PM:INFO:Foraging:Foraging.py:_NewSession:line 3579:New Session complete
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: BlockMax, 60.0 -> 35.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayBeta, 1.0 -> 0.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayMin, 0.0 -> 1.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIBeta, 2.0 -> 3.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIMax, 8.0 -> 30.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Multiplier, 0.8 -> 0.5
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Unrewarded, 200.0 -> 10.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Ignored, 100.0 -> 10.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: StopIgnores, 20.0 -> 25.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.057 -> 0.037
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.053 -> 0.035
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: MaxTime, 120.0 -> 75.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue_volume, 3.0 -> 2.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue_volume, 3.0 -> 2.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: BlockMax, 60.0 -> 35.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayBeta, 1.0 -> 0.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayMin, 0.0 -> 1.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIBeta, 2.0 -> 3.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIMax, 8.0 -> 30.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Multiplier, 0.8 -> 0.5
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Unrewarded, 200.0 -> 10.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Ignored, 100.0 -> 10.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: StopIgnores, 20.0 -> 25.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.057 -> 0.037
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.053 -> 0.035
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: MaxTime, 120.0 -> 75.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue_volume, 3.0 -> 2.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue_volume, 3.0 -> 2.0
12:40:39 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Visualization.py:160: RuntimeWarning: Mean of empty slice
  RewardedHistoryF[i+1-self.kernel_size]=np.nanmean(RewardedHistoryT[i+1-self.kernel_size:i+1])

12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ID, 0.0 -> 744329.0
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: BaseWeight,  -> 28.8
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: TargetWeight,  -> 24.48
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: SuggestedWater,  -> 0.68
12:40:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionY, 10111.0 -> 10111.5
12:40:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:40 PM:WARNING:Foraging:Foraging.py:_check_drop_frames:line 672:Correct: body_camera.avi has 2308737 frames and 2308737 triggers
Error: bottom_camera.avi has 923152 frames, but 2308737 triggers
Error: side_camera_left.avi has 329820 frames, but 2308737 triggers
Correct: side_camera_right.avi has 2308737 frames and 2308737 triggers

12:40:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:40 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2938:AutoTrain disengaged!
12:40:40 PM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
12:40:40 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2734:Override stage clicked: state=0
12:40:40 PM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2680:Selected curriculum: {'curriculum_name': 'Uncoupled Baiting', 'curriculum_version': '2.3', 'curriculum_schema_version': '1.0', 'curriculum_description': '2024-08-16 max_len = 75 mins; decrease finished trial criterion'}
12:40:40 PM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
12:40:40 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2760:Current stage to apply: GRADUATED @Uncoupled Baiting (v2.3@1.0)
12:40:40 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2760:Current stage to apply: GRADUATED @Uncoupled Baiting (v2.3@1.0)
12:40:40 PM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2680:Selected curriculum: {'curriculum_name': 'Uncoupled Baiting', 'curriculum_version': '2.3', 'curriculum_schema_version': '1.0', 'curriculum_description': '2024-08-16 max_len = 75 mins; decrease finished trial criterion'}
12:40:40 PM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
12:40:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6549399.161184, '127.0.0.1', 4003]
12:40:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 6549399.161184, '127.0.0.1', 4003], displaying at 0.5 Hz
12:40:53 PM:ERROR:Dialogs:Dialogs.py:_Frequency:line 183:''
12:40:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:54 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:54 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:54 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:54 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:54 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:54 PM:ERROR:Dialogs:Dialogs.py:_Frequency:line 183:''
12:40:54 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:54 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:56 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:40:58 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6549416.177984, '127.0.0.1', 4003]
12:41:02 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:10 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:10 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:10 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:10 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:11 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:11 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:11 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:11 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:11 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:11 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:11 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:12 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:12 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:12 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:19 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:41:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Probability_1, 0.25 -> 1.0
12:41:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Duration_1, 5.0 -> 50.0
12:41:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
_____SKIPPING_____
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6554667.890976, '127.0.0.1', 4002]
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554667.893504, '127.0.0.1', 4002]
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6554667.894432, 4, '127.0.0.1']
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554667.982976, '127.0.0.1', 4003]
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6554667.981984, '127.0.0.1', 4002]
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4002]
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554668.094976, '127.0.0.1', 4003]
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554668.251072, '127.0.0.1', 4003]
02:08:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554668.389216, '127.0.0.1', 4003]
02:08:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6554670.988, '127.0.0.1', 4002]
02:08:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554670.990496, '127.0.0.1', 4002]
02:08:35 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
02:08:35 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
02:08:35 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 79
02:08:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6554671.064, '127.0.0.1', 4002]
02:08:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6554671.067488, '127.0.0.1', 4002]
02:08:35 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
02:08:35 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\744330\behavior_744330_2024-11-13_13-59-24
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:08:35 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:08:36 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 753:Checking stage connection
02:08:36 PM:INFO:Foraging:Foraging.py:_Move:line 791:Moving stage
02:08:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6554674.644992, '127.0.0.1', 4002]
02:08:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6554674.647328, 4, '127.0.0.1']
02:08:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554674.646496, '127.0.0.1', 4002]
02:08:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554674.756096, '127.0.0.1', 4003]
02:08:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6554674.756, '127.0.0.1', 4002]
02:08:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4002]
02:08:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554674.880384, '127.0.0.1', 4003]
02:08:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6554677.770976, '127.0.0.1', 4002]
02:08:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554677.773504, '127.0.0.1', 4002]
02:08:42 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
02:08:42 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
02:08:42 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 80
02:08:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6554677.853984, '127.0.0.1', 4002]
02:08:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6554677.857504, '127.0.0.1', 4002]
02:08:42 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
02:08:42 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\744330\behavior_744330_2024-11-13_13-59-24
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:08:42 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:08:44 PM:INFO:bias_indicator:bias_indicator.py:calculate_bias:line 139:Bias: -0.03290978790480639 Trial Count: 79
02:08:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6554683.674976, '127.0.0.1', 4002]
02:08:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6554683.679232, 4, '127.0.0.1']
02:08:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554683.678496, '127.0.0.1', 4002]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554683.779136, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 6554683.778976, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6554683.778976, '127.0.0.1', 4002]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 6554683.778976, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4002]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 6554683.78752, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554683.88672, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554684.026848, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554684.145984, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554684.274176, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554684.4, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554684.524576, '127.0.0.1', 4003]
02:08:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554684.650016, '127.0.0.1', 4003]
02:08:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554685.052, '127.0.0.1', 4003]
02:08:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554685.372192, '127.0.0.1', 4003]
02:08:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554685.54848, '127.0.0.1', 4003]
02:08:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6554686.788, '127.0.0.1', 4002]
02:08:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554686.790496, '127.0.0.1', 4002]
02:08:51 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
02:08:51 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
02:08:51 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 81
02:08:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6554686.873984, '127.0.0.1', 4002]
02:08:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6554686.877504, '127.0.0.1', 4002]
02:08:51 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
02:08:51 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\744330\behavior_744330_2024-11-13_13-59-24
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:08:51 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6554693.82, '127.0.0.1', 4002]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6554693.823104, 4, '127.0.0.1']
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554693.822496, '127.0.0.1', 4002]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554693.94288, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 6554693.941984, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6554693.941984, '127.0.0.1', 4002]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 6554693.941984, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4002]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 6554693.946496, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554694.068512, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554694.199648, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554694.330592, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554694.461664, '127.0.0.1', 4003]
02:08:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554694.593152, '127.0.0.1', 4003]
02:08:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554694.728256, '127.0.0.1', 4003]
02:08:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554694.8728, '127.0.0.1', 4003]
02:09:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6554696.954976, '127.0.0.1', 4002]
02:09:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554696.95648, '127.0.0.1', 4002]
02:09:01 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:

02:09:01 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
02:09:01 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 82
02:09:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6554697.041984, '127.0.0.1', 4002]
02:09:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6554697.045504, '127.0.0.1', 4002]
02:09:01 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
02:09:01 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\744330\behavior_744330_2024-11-13_13-59-24
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:09:01 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:09:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6554700.633984, '127.0.0.1', 4002]
02:09:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554700.63648, '127.0.0.1', 4002]
02:09:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6554700.637344, 4, '127.0.0.1']
02:09:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554700.722272, '127.0.0.1', 4003]
02:09:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6554700.721984, '127.0.0.1', 4002]
02:09:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4002]
02:09:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554700.830976, '127.0.0.1', 4003]
02:09:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554700.896, '127.0.0.1', 4003]
02:09:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554700.981248, '127.0.0.1', 4003]
02:09:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6554703.737984, '127.0.0.1', 4002]
02:09:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554703.74048, '127.0.0.1', 4002]
02:09:08 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
02:09:08 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
02:09:08 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 83
02:09:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6554703.814976, '127.0.0.1', 4002]
02:09:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6554703.817504, '127.0.0.1', 4002]
02:09:08 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
02:09:08 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\744330\behavior_744330_2024-11-13_13-59-24
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
02:09:08 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
02:09:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6554707.573216, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6554724.724992, '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6554724.727488, '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6554724.728384, 4, '127.0.0.1']
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554724.924896, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTime', 6554724.924, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6554724.924, '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedLeftWaterStartTime', 6554724.924, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardLeft', '127.0.0.1', 4002]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 6554724.927488, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.041504, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.175648, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.299008, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.426848, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.472, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.55648, '127.0.0.1', 4003]
02:09:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6554725.600992, '127.0.0.1', 4003]
02:09:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 25.00%.
02:09:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 7.08%.
02:09:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 21.61%.
02:09:29 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box A mouse 744330 exceeded 10%