Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10% #1289

Open
alexpiet opened this issue Jan 7, 2025 · 3 comments
Open

Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10% #1289

alexpiet opened this issue Jan 7, 2025 · 3 comments
Labels
low priority - auto-generated autogenerated issues that have only occurred once

Comments

@alexpiet
Copy link
Collaborator

alexpiet commented Jan 7, 2025

This issue was automatically generated from GUI logs.

file: MyFunctions.py
function: calculate_inter_lick_intervals
line 930
logfile: W10DT713883/W10DT713883-A_gui_log_2025-01-06_11-45-22.txt
boxes: ephys3
count: 6
text: Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10%

GUI Log snippet (click for full log)

12:12:54 PM:INFO:Foraging:Foraging.py:_Save:line 2479:Saving current session, ForceSave=1
12:12:54 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-06_11-52-57
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:13:02 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 23.45%.
12:13:02 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 5.00%.
12:13:02 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 11.32%.
12:13:02 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10%
Full GUI log (first 200 and last 200 lines) 
11:45:22 AM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4796:Starting logfile!
11:45:23 AM:WARNING:Foraging:Foraging.py:<module>:line 4939:Failed to setup LOKI Handler: [Errno 2] No such file or directory: 'c:\\ProgramData\\AIBS_MPE\\.secrets\\sipe_sw_passwords.keyx'
11:45:23 AM:INFO:Foraging:Foraging.py:log_git_hash:line 4807:Python version: 3.11.9 | packaged by Anaconda, Inc. | (main, Apr 19 2024, 16:40:41) [MSC v.1916 64 bit (AMD64)]
11:45:23 AM:INFO:Foraging:Foraging.py:log_git_hash:line 4824:Current git commit branch, hash: main, 698fb9fecded812fcf96d570658d9bc3766b14c6
11:45:23 AM:INFO:Foraging:Foraging.py:log_git_hash:line 4828:Current foraging_gui version: 1.6.19
11:45:23 AM:WARNING:Foraging:Foraging.py:log_git_hash:line 4838:local repository is clean
11:45:23 AM:INFO:Foraging:Foraging.py:<module>:line 4944:Setting QApplication attributes
11:45:23 AM:INFO:Foraging:Foraging.py:<module>:line 4952:Starting QApplication and Window
11:45:23 AM:INFO:Foraging:Foraging.py:__init__:line 77:Creating Window
11:45:23 AM:INFO:Foraging:Foraging.py:_GetSettings:line 1211:Loaded settings_box file
11:45:23 AM:INFO:Foraging:Foraging.py:_GetSettings:line 1239:Loaded settings file
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_workflow_path), using default: 
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_settings), using default: C:\Users\svc_aind_ephys\Documents\FIPSettings
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (bonsai_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.exe
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (bonsaiworkflow_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\src\workflows\foraging.bonsai
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\metadata_dialog\
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\rig_metadata\
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (project_info_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\Project Name and Funding Source v2.csv
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box2), using default: 60
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box3), using default: 60
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box4), using default: 60
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box1), using default: 5000
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box2), using default: 5000
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box3), using default: 5000
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box4), using default: 5000
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\name_mapper.json
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (save_each_trial), using default: True
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (AutomaticUpload), using default: True
11:45:23 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_ephys\Documents\aind_watchdog_service\manifest
11:45:23 AM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1137:Loaded behavior schedule
11:45:23 AM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
11:45:23 AM:INFO:Foraging:Foraging.py:_LoadRigJson:line 1582:Skipping rig metadata creation because create_rig_metadata=False
11:45:23 AM:INFO:Foraging:Foraging.py:_LoadUI:line 305:Using ForagingGUI_Ephys.ui interface
11:45:24 AM:INFO:Foraging:Foraging.py:__init__:line 143:Setting Window title: 323_EPHYS3
11:45:24 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1409:Trying to connect to already running Bonsai
11:45:24 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
11:45:25 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1413:Could not connect: timed out
11:45:25 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1422:Starting Bonsai
11:45:25 AM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4911:BONSAI logging starting
11:45:25 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
11:45:26 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 0.5 seconds: timed out
11:45:27 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
11:45:28 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 1.0 seconds: timed out
11:45:28 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
11:45:29 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 1.5 seconds: timed out
11:45:30 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
11:45:31 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 2.0 seconds: timed out
11:45:31 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
11:45:32 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 2.5 seconds: timed out
11:45:33 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
11:45:33 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1439:Connected to Bonsai after 3.0 seconds
11:45:33 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1440:Bonsai started successfully
11:45:33 AM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1318:Attempting to connect to Slims
11:45:33 AM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1335:Successfully connected to Slims
11:45:33 AM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_ephys\Documents\ForagingSettings\WaterCalibrationPar_1.json
11:45:33 AM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 912:Scanning for newscale stages
11:45:33 AM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 927:found 1 newscale stages
11:45:33 AM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 951:Found the newscale stage from the settings file
11:45:33 AM:INFO:Foraging:Foraging.py:_connect_stage:line 978:Successfully connected to newscale stage: 46796
11:45:33 AM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 793:Checking stage connection
11:45:33 AM:INFO:Foraging:Foraging.py:_GetPositions:line 805:Grabbing current stage position
11:45:34 AM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 793:Checking stage connection
11:45:34 AM:INFO:Foraging:Foraging.py:_GetPositions:line 805:Grabbing current stage position
11:45:34 AM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 793:Checking stage connection
11:45:34 AM:INFO:Foraging:Foraging.py:_GetPositions:line 805:Grabbing current stage position
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
11:45:34 AM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1572:Found existing rig.json: rig_323_EPHYS3_2024-10-17.json
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.057
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue, 0.03 -> 0.053
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterL, 0.03 -> 0.053
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR, 0.03 -> 0.057
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.057
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue, 0.03 -> 0.053
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterL, 0.03 -> 0.053
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR, 0.03 -> 0.057
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
11:45:34 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
11:45:34 AM:WARNING:Foraging:Foraging.py:_show_disk_space:line 259:Low disk space  Used space: 1716.20GB    Free space: 146.82GB
11:45:34 AM:INFO:Foraging:Foraging.py:__init__:line 243:Start up complete
11:45:36 AM: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) = 12795
11:45:37 AM: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) = 4833
11:45:38 AM: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/
11:45:38 AM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
11:45:38 AM: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/
11:45:38 AM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_ephys/.aind_auto_train/curriculum_manager/
11:45:38 AM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 0
11:45:38 AM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=2
11:45:38 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
11:46:58 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 11211769.358976, '127.0.0.1', 4003]
11:46:58 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 11211769.363488, '127.0.0.1', 4003]
11:47:00 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 11211771.758976, '127.0.0.1', 4003]
11:47:00 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 11211771.762496, '127.0.0.1', 4003]
11:47:08 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 11211779.348992, '127.0.0.1', 4003]
11:47:08 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 11211779.348992, '127.0.0.1', 4003]
11:47:08 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 11211779.350496, '127.0.0.1', 4003]
11:47:08 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 11211779.351488, '127.0.0.1', 4003]
11:47:10 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 11211781.749984, '127.0.0.1', 4003]
11:47:10 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 11211781.749984, '127.0.0.1', 4003]
11:47:10 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 11211781.75248, '127.0.0.1', 4003]
11:47:10 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 11211781.753504, '127.0.0.1', 4003]
11:47:18 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 11211789.354976, '127.0.0.1', 4003]
11:47:18 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 11211789.354976, '127.0.0.1', 4003]
11:47:18 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 11211789.357504, '127.0.0.1', 4003]
11:47:18 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 11211789.358496, '127.0.0.1', 4003]
11:47:20 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 11211791.758976, '127.0.0.1', 4003]
11:47:20 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 11211791.758976, '127.0.0.1', 4003]
11:47:20 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 11211791.76048, '127.0.0.1', 4003]
11:47:20 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 11211791.761504, '127.0.0.1', 4003]
11:47:25 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 11211796.772992, '127.0.0.1', 4003]
11:47:25 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 11211796.775488, '127.0.0.1', 4003]
11:47:26 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 11211797.506976, '127.0.0.1', 4003]
11:47:26 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 11211797.509504, '127.0.0.1', 4003]
11:49:01 AM:WARNING:Foraging:Foraging.py:_OpenBehaviorFolder:line 1743:Save folder unspecified, so opening D:\BehaviorData\323_EPHYS3\0
11:52:16 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212087.423552, '127.0.0.1', 4003]
11:52:16 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 11212087.423552, '127.0.0.1', 4003], displaying at 0.5 Hz
11:52:16 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212087.654848, '127.0.0.1', 4003]
11:52:16 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212087.788736, '127.0.0.1', 4003]
11:52:16 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212087.9496, '127.0.0.1', 4003]
11:52:16 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212088.081504, '127.0.0.1', 4003]
11:52:16 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212088.228256, '127.0.0.1', 4003]
11:52:17 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212088.540384, '127.0.0.1', 4003]
11:52:17 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212088.690592, '127.0.0.1', 4003]
11:52:17 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212088.843072, '127.0.0.1', 4003]
11:52:17 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212089.021376, '127.0.0.1', 4003]
11:52:17 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212089.1744, '127.0.0.1', 4003]
11:52:20 AM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3675:Stopping current trials
11:52:23 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212095.044288, '127.0.0.1', 4003]
11:52:24 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212095.234464, '127.0.0.1', 4003]
11:52:24 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212095.394016, '127.0.0.1', 4003]
11:52:24 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212095.583968, '127.0.0.1', 4003]
11:52:27 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212098.832768, '127.0.0.1', 4003]
11:52:27 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212099.01424, '127.0.0.1', 4003]
11:52:27 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212099.084992, '127.0.0.1', 4003]
11:52:27 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212099.198368, '127.0.0.1', 4003]
11:52:28 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212099.39136, '127.0.0.1', 4003]
11:52:28 AM:INFO:Foraging:Foraging.py:_Open:line 3005:User entered the ID for a mouse with no data: 764791
11:52:29 AM:INFO:Foraging:Foraging.py:_OpenNewMouse:line 2948:User starting a new mouse: 764791
11:52:29 AM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2844:AutoTrain disengaged!
11:52:29 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
11:52:29 AM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=0
11:52:29 AM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2586: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'}
11:52:29 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
11:52:29 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
11:52:29 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
11:52:29 AM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2586: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'}
11:52:29 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
11:52:29 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
11:52:29 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ID, 0.0 -> 764791.0
11:52:29 AM:INFO:Foraging:Foraging.py:_NewSession:line 3585:New Session pressed
11:52:29 AM:INFO:Foraging:Foraging.py:_NewSession:line 3617:Resetting session run flag
11:52:29 AM:INFO:Foraging:Foraging.py:_NewSession:line 3655:New Session complete
11:52:30 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212101.565984, '127.0.0.1', 4003]
11:52:30 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212101.739104, '127.0.0.1', 4003]
11:52:30 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212101.904992, '127.0.0.1', 4003]
11:52:30 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212101.965024, '127.0.0.1', 4003]
11:52:30 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212102.055936, '127.0.0.1', 4003]
11:52:30 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212102.219232, '127.0.0.1', 4003]
11:52:31 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212102.381376, '127.0.0.1', 4003]
11:52:31 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212102.555744, '127.0.0.1', 4003]
11:52:31 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212102.728416, '127.0.0.1', 4003]
11:52:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212104.210848, '127.0.0.1', 4003]
11:52:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212104.44096, '127.0.0.1', 4003]
11:52:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212104.492992, '127.0.0.1', 4003]
11:52:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212104.5752, '127.0.0.1', 4003]
11:52:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212104.734176, '127.0.0.1', 4003]
11:52:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212104.9072, '127.0.0.1', 4003]
11:52:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212105.08192, '127.0.0.1', 4003]
11:52:37 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
11:52:37 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
11:52:37 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
11:52:37 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
11:52:37 AM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2586: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'}
11:52:37 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
11:52:39 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212110.95248, '127.0.0.1', 4003]
11:52:39 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212110.989984, '127.0.0.1', 4003]
11:52:39 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212111.05072, '127.0.0.1', 4003]
11:52:39 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212111.052, '127.0.0.1', 4003]
11:52:39 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212111.141568, '127.0.0.1', 4003]
11:52:40 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11212111.334624, '127.0.0.1', 4003]
11:52:40 AM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2793:AutoTrain engaged! GRADUATED @ Uncoupled Baiting ([email protected])
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "training_stage" not found. skipped...
11:52:40 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2916:Task is set to Uncoupled Baiting
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_url" not found. skipped...
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_schema_version" not found. skipped...
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "description" not found. skipped...
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BaseRewardSum is set to 0.8
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:RewardFamily is set to 1
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:RewardPairsN is set to 1
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "UncoupledReward" has been disabled by the GUI. skipped...
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:Randomness is set to Exponential
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMin is set to 20
11:52:40 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMax is set to 35
11:52:41 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockBeta is set to 10
11:52:41 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMinReward is set to 0
11:52:41 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayMin is set to 1.0
_____SKIPPING_____
12:12:27 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:27 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:27 PM:INFO:bias_indicator:bias_indicator.py:calculate_bias:line 158:Bias: 0.32272890164048473 Trial Count: 129
12:12:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11213299.992, '127.0.0.1', 4002]
12:12:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213299.993504, '127.0.0.1', 4002]
12:12:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 11213300.974976, '127.0.0.1', 4002]
12:12:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 11213300.978144, 4, '127.0.0.1']
12:12:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213300.977504, '127.0.0.1', 4002]
12:12:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213301.106528, '127.0.0.1', 4003]
12:12:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 11213301.105984, '127.0.0.1', 4002]
12:12:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
12:12:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213301.220576, '127.0.0.1', 4003]
12:12:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213301.391872, '127.0.0.1', 4003]
12:12:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213303.897472, '127.0.0.1', 4003]
12:12:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213304.06912, '127.0.0.1', 4003]
12:12:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 11213304.124992, '127.0.0.1', 4002]
12:12:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213304.127488, '127.0.0.1', 4002]
12:12:32 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 793:Checking stage connection
12:12:32 PM:INFO:Foraging:Foraging.py:_GetPositions:line 805:Grabbing current stage position
12:12:33 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
12:12:33 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
12:12:33 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 131
12:12:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 11213304.264, '127.0.0.1', 4002]
12:12:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 11213304.268512, '127.0.0.1', 4002]
12:12:33 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:12:33 PM:INFO:Foraging:Foraging.py:_Save:line 2479:Saving current session, ForceSave=1
12:12:33 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-06_11-52-57
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11213306.274976, '127.0.0.1', 4002]
12:12:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213306.278496, '127.0.0.1', 4002]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 11213307.258976, '127.0.0.1', 4002]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213307.262496, '127.0.0.1', 4002]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 11213307.263424, 4, '127.0.0.1']
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213307.382592, '127.0.0.1', 4003]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 11213307.381984, '127.0.0.1', 4002]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213307.491008, '127.0.0.1', 4003]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11213307.526976, '127.0.0.1', 4003]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213307.651872, '127.0.0.1', 4003]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213307.87152, '127.0.0.1', 4003]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213308.0288, '127.0.0.1', 4003]
12:12:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213308.21024, '127.0.0.1', 4003]
12:12:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 11213310.392, '127.0.0.1', 4002]
12:12:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213310.394496, '127.0.0.1', 4002]
12:12:39 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 793:Checking stage connection
12:12:39 PM:INFO:Foraging:Foraging.py:_GetPositions:line 805:Grabbing current stage position
12:12:39 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
12:12:39 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
12:12:39 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 132
12:12:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 11213310.542976, '127.0.0.1', 4002]
12:12:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 11213310.546496, '127.0.0.1', 4002]
12:12: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:12:39 PM:INFO:Foraging:Foraging.py:_Save:line 2479:Saving current session, ForceSave=1
12:12:39 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-06_11-52-57
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:39 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:41 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11213312.641984, '127.0.0.1', 4002]
12:12:41 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213312.643488, '127.0.0.1', 4002]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 11213313.624992, '127.0.0.1', 4002]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213313.627488, '127.0.0.1', 4002]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 11213313.628352, 4, '127.0.0.1']
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213314.076928, '127.0.0.1', 4003]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 11213314.076, '127.0.0.1', 4003]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 11213314.076, '127.0.0.1', 4003]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 11213314.076, '127.0.0.1', 4002]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4002]
12:12:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 11213314.081504, '127.0.0.1', 4003]
12:12:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213314.741824, '127.0.0.1', 4003]
12:12:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.009024, '127.0.0.1', 4003]
12:12:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.1392, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.264576, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.427104, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.543072, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.684032, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.830304, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213315.957536, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.011008, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.104416, '127.0.0.1', 4003]
12:12:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.229632, '127.0.0.1', 4003]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.377024, '127.0.0.1', 4003]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.507296, '127.0.0.1', 4003]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.654112, '127.0.0.1', 4003]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.792608, '127.0.0.1', 4003]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213316.955232, '127.0.0.1', 4003]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213317.009024, '127.0.0.1', 4003]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 11213317.092, '127.0.0.1', 4002]
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213317.093504, '127.0.0.1', 4002]
12:12:45 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 793:Checking stage connection
12:12:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213317.127136, '127.0.0.1', 4003]
12:12:45 PM:INFO:Foraging:Foraging.py:_GetPositions:line 805:Grabbing current stage position
12:12:46 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
12:12:46 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
12:12:46 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 133
12:12:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213317.251136, '127.0.0.1', 4003]
12:12:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 11213317.245984, '127.0.0.1', 4002]
12:12:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 11213317.250496, '127.0.0.1', 4002]
12:12:46 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:12:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213317.412096, '127.0.0.1', 4003]
12:12:46 PM:INFO:Foraging:Foraging.py:_Save:line 2479:Saving current session, ForceSave=1
12:12:46 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-06_11-52-57
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:46 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213318.393088, '127.0.0.1', 4003]
12:12:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213318.538912, '127.0.0.1', 4003]
12:12:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213318.697984, '127.0.0.1', 4003]
12:12:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213318.846208, '127.0.0.1', 4003]
12:12:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11213318.958976, '127.0.0.1', 4002]
12:12:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213318.961504, '127.0.0.1', 4002]
12:12:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213319.01296, '127.0.0.1', 4003]
12:12:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213319.33008, '127.0.0.1', 4003]
12:12:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213319.496032, '127.0.0.1', 4003]
12:12:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11213320.724992, '127.0.0.1', 4002]
12:12:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213320.727488, '127.0.0.1', 4002]
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 11213321.708992, '127.0.0.1', 4002]
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 11213321.712224, 4, '127.0.0.1']
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213321.71248, '127.0.0.1', 4002]
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213321.930656, '127.0.0.1', 4003]
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 11213321.929984, '127.0.0.1', 4002]
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4002]
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213321.985024, '127.0.0.1', 4003]
12:12:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213322.068224, '127.0.0.1', 4003]
12:12:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213322.231136, '127.0.0.1', 4003]
12:12:52 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213323.298784, '127.0.0.1', 4003]
12:12:52 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11213323.456832, '127.0.0.1', 4003]
12:12:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 11213324.941984, '127.0.0.1', 4002]
12:12:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11213324.943488, '127.0.0.1', 4002]
12:12:53 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 793:Checking stage connection
12:12:53 PM:INFO:Foraging:Foraging.py:_GetPositions:line 805:Grabbing current stage position
12:12:53 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:

12:12:53 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
12:12:53 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 134
12:12:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 11213325.096, '127.0.0.1', 4002]
12:12:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 11213325.097504, '127.0.0.1', 4002]
12:12:53 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:12:54 PM:INFO:Foraging:Foraging.py:_Save:line 2479:Saving current session, ForceSave=1
12:12:54 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-06_11-52-57
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
12:12:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
12:13:02 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 23.45%.
12:13:02 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 5.00%.
12:13:02 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 11.32%.
12:13:02 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10%
@alexpiet alexpiet added the low priority - auto-generated autogenerated issues that have only occurred once label Jan 7, 2025
@ellahiltonvano
Copy link

no longer in training

@alexpiet alexpiet reopened this Jan 13, 2025
@alexpiet
Copy link
Collaborator Author

This issue reoccurred:

file: MyFunctions.py
function: calculate_inter_lick_intervals
line 930
logfile: W10DT713883/W10DT713883-A_gui_log_2025-01-09_13-04-40.txt
boxes: ephys3
count: 19
text: Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10%

GUI Log snippet (click for full log)

01:20:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476575.59936, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.425792, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.454976, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.550624, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.688896, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.850912, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11476576.930976, '127.0.0.1', 4002]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476576.937504, '127.0.0.1', 4002]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.996032, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.13296, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.271296, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.410624, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.546912, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.698144, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.76, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.866368, '127.0.0.1', 4003]
01:20:27 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 22.99%.
01:20:27 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 6.25%.
01:20:27 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 22.57%.
01:20:27 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10%
Full GUI log (first 200 and last 200 lines) 
01:04:40 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4807:Starting logfile!
01:04:40 PM:WARNING:Foraging:Foraging.py:<module>:line 4950:Failed to setup LOKI Handler: [Errno 2] No such file or directory: 'c:\\ProgramData\\AIBS_MPE\\.secrets\\sipe_sw_passwords.keyx'
01:04:40 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4818:Python version: 3.11.9 | packaged by Anaconda, Inc. | (main, Apr 19 2024, 16:40:41) [MSC v.1916 64 bit (AMD64)]
01:04:41 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4835:Current git commit branch, hash: main, cdfbe6a060acd79ea6048b0310e4259e421ee18c
01:04:41 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4839:Current foraging_gui version: 1.6.20
01:04:41 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4849:local repository is clean
01:04:41 PM:INFO:Foraging:Foraging.py:<module>:line 4955:Setting QApplication attributes
01:04:41 PM:INFO:Foraging:Foraging.py:<module>:line 4963:Starting QApplication and Window
01:04:41 PM:INFO:Foraging:Foraging.py:__init__:line 78:Creating Window
01:04:41 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1212:Loaded settings_box file
01:04:41 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1240:Loaded settings file
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (FIP_workflow_path), using default: 
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (FIP_settings), using default: C:\Users\svc_aind_ephys\Documents\FIPSettings
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (bonsai_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.exe
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (bonsaiworkflow_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\src\workflows\foraging.bonsai
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\metadata_dialog\
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\rig_metadata\
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (project_info_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\Project Name and Funding Source v2.csv
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (go_cue_decibel_box2), using default: 60
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (go_cue_decibel_box3), using default: 60
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (go_cue_decibel_box4), using default: 60
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (lick_spout_distance_box1), using default: 5000
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (lick_spout_distance_box2), using default: 5000
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (lick_spout_distance_box3), using default: 5000
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (lick_spout_distance_box4), using default: 5000
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\name_mapper.json
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (save_each_trial), using default: True
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (AutomaticUpload), using default: True
01:04:41 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1250:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_ephys\Documents\aind_watchdog_service\manifest
01:04:41 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1138:Loaded behavior schedule
01:04:41 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1102:Loaded Water Calibration
01:04:41 PM:INFO:Foraging:Foraging.py:_LoadRigJson:line 1583:Skipping rig metadata creation because create_rig_metadata=False
01:04:41 PM:INFO:Foraging:Foraging.py:_LoadUI:line 306:Using ForagingGUI_Ephys.ui interface
01:04:41 PM:INFO:Foraging:Foraging.py:__init__:line 144:Setting Window title: 323_EPHYS3
01:04:41 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1410:Trying to connect to already running Bonsai
01:04:41 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1457:connecting to GUI and Bonsai through OSC
01:04:42 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1414:Could not connect: timed out
01:04:42 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1423:Starting Bonsai
01:04:42 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4922:BONSAI logging starting
01:04:42 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1457:connecting to GUI and Bonsai through OSC
01:04:43 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1437:Could not connect, total waiting time 0.5 seconds: timed out
01:04:44 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1457:connecting to GUI and Bonsai through OSC
01:04:45 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1437:Could not connect, total waiting time 1.0 seconds: timed out
01:04:45 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1457:connecting to GUI and Bonsai through OSC
01:04:45 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1440:Connected to Bonsai after 1.5 seconds
01:04:45 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1441:Bonsai started successfully
01:04:45 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1319:Attempting to connect to Slims
01:04:46 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1336:Successfully connected to Slims
01:04:46 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_ephys\Documents\ForagingSettings\WaterCalibrationPar_1.json
01:04:46 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 913:Scanning for newscale stages
01:04:46 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 928:found 1 newscale stages
01:04:46 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 952:Found the newscale stage from the settings file
01:04:46 PM:INFO:Foraging:Foraging.py:_connect_stage:line 979:Successfully connected to newscale stage: 46796
01:04:46 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 794:Checking stage connection
01:04:46 PM:INFO:Foraging:Foraging.py:_GetPositions:line 806:Grabbing current stage position
01:04:46 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 794:Checking stage connection
01:04:46 PM:INFO:Foraging:Foraging.py:_GetPositions:line 806:Grabbing current stage position
01:04:46 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 794:Checking stage connection
01:04:47 PM:INFO:Foraging:Foraging.py:_GetPositions:line 806:Grabbing current stage position
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:04:47 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1573:Found existing rig.json: rig_323_EPHYS3_2024-10-17.json
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: RightValue, 0.03 -> 0.057
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: LeftValue, 0.03 -> 0.053
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterL, 0.03 -> 0.053
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterR, 0.03 -> 0.057
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: RightValue, 0.03 -> 0.057
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: LeftValue, 0.03 -> 0.053
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterL, 0.03 -> 0.053
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterR, 0.03 -> 0.057
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:04:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:04:47 PM:WARNING:Foraging:Foraging.py:_show_disk_space:line 260:Low disk space  Used space: 1734.46GB    Free space: 128.55GB
01:04:47 PM:INFO:Foraging:Foraging.py:__init__:line 244:Start up complete
01:04:49 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) = 12835
01:04:49 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) = 4872
01:04:50 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/
01:04:50 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
01:04:50 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/
01:04:50 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/
01:04:50 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 0
01:04:50 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=2
01:04:50 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
01:10:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11475951.510176, '127.0.0.1', 4003]
01:10:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 11475951.510176, '127.0.0.1', 4003], displaying at 0.5 Hz
01:10:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11475951.532992, '127.0.0.1', 4003]
01:10:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11475952.087968, '127.0.0.1', 4003]
01:10:03 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3676:Stopping current trials
01:10:08 PM:INFO:Foraging:Foraging.py:_Open:line 3018:Quick load success: D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-08_14-46-25\behavior\764791_2025-01-08_14-46-25.json
01:10:08 PM:INFO:Foraging:Foraging.py:_NewSession:line 3586:New Session pressed
01:10:08 PM:INFO:Foraging:Foraging.py:_NewSession:line 3618:Resetting session run flag
01:10:08 PM:INFO:Foraging:Foraging.py:_NewSession:line 3656:New Session complete
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: BlockBeta, 20.0 -> 10.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: BlockMax, 60.0 -> 35.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: DelayBeta, 1.0 -> 0.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: DelayMin, 0.0 -> 1.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: ITIBeta, 2.0 -> 3.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: ITIMax, 8.0 -> 30.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: Multiplier, 0.8 -> 0.5
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: Unrewarded, 200.0 -> 10.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: Ignored, 100.0 -> 10.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: RightValue, 0.057 -> 0.037
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: LeftValue, 0.053 -> 0.035
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterL, 0.053 -> 0.035
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterR, 0.057 -> 0.037
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterL_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterR_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: RightValue_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: LeftValue_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: MaxTime, 120.0 -> 75.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: BlockBeta, 20.0 -> 10.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: BlockMax, 60.0 -> 35.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: DelayBeta, 1.0 -> 0.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: DelayMin, 0.0 -> 1.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: ITIBeta, 2.0 -> 3.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: ITIMax, 8.0 -> 30.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: Multiplier, 0.8 -> 0.5
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: Unrewarded, 200.0 -> 10.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: Ignored, 100.0 -> 10.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: RightValue, 0.057 -> 0.037
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: LeftValue, 0.053 -> 0.035
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterL, 0.053 -> 0.035
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterR, 0.057 -> 0.037
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterL_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: GiveWaterR_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: RightValue_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: LeftValue_volume, 3.0 -> 2.0
01:10:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: MaxTime, 120.0 -> 75.0
01:10:09 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])

01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: ID, 0.0 -> 764791.0
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: BaseWeight,  -> 23.47
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: TargetWeight,  -> 19.949
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: SuggestedWater,  -> 0.504
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: PositionY, 8524.5 -> 9316.5
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: PositionX, 4308.5 -> 4350.5
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1961:Changing parameter: PositionZ, 8756.5 -> 8536.5
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:10 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:10 PM:INFO:Foraging:Foraging.py:_check_drop_frames:line 715:Correct: body_camera.avi has 2265963 frames and 2265963 triggers
Correct: bottom_camera.avi has 2265963 frames and 2265963 triggers
Correct: side_camera_left.avi has 2265963 frames and 2265963 triggers
Correct: side_camera_right.avi has 2265963 frames and 2265963 triggers

01:10:10 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:10 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2844:AutoTrain disengaged!
01:10:10 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'.
01:10:10 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=0
01:10:10 PM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2586: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'}
01:10:10 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'.
01:10:10 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
01:10:10 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
01:10:10 PM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2586: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'}
01:10:10 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'.
01:10:15 PM:INFO:Foraging:Foraging.py:_Start:line 3814:Start button pressed: starting trial loop
01:10:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1902:processing parameter changes
01:10:17 PM:INFO:Foraging:Foraging.py:_Start:line 3890:User declines using default name
01:10:18 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'.
01:10:18 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
01:10:18 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
01:10:18 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: GRADUATED @Uncoupled Baiting ([email protected])
01:10:18 PM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2586: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'}
01:10:18 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'.
01:10:19 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2793:AutoTrain engaged! GRADUATED @ Uncoupled Baiting ([email protected])
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "training_stage" not found. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2916:Task is set to Uncoupled Baiting
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_url" not found. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_schema_version" not found. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "description" not found. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BaseRewardSum" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "RewardFamily" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "RewardPairsN" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:UncoupledReward is set to 0.1, 0.4, 0.7
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:Randomness is set to Exponential
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMin is set to 20
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMax is set to 35
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BlockBeta" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BlockMinReward" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayMin is set to 1.0
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayMax is set to 1.0
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayBeta is set to 0.0
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:RewardDelay is set to 0.0
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:AutoReward is set to False
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "AutoWaterType" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "Multiplier" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "Unrewarded" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "Ignored" has been disabled by the GUI. skipped...
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:ITIMin is set to 1.0
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:ITIMax is set to 30.0
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:ITIBeta is set to 3.0
01:10:19 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "ITIIncrease" has been disabled by the GUI. skipped...
_____SKIPPING_____
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.328992, '127.0.0.1', 4003]
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.422848, '127.0.0.1', 4003]
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.536352, '127.0.0.1', 4003]
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.6544, '127.0.0.1', 4003]
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.753536, '127.0.0.1', 4003]
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.778976, '127.0.0.1', 4003]
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.876096, '127.0.0.1', 4003]
01:20:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476554.990336, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.101728, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.241344, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.382976, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.516928, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.538976, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.776704, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.921152, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476555.944, '127.0.0.1', 4003]
01:20:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.061536, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.207392, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.242976, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.353984, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.476896, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.516, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.623296, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 11476556.646976, '127.0.0.1', 4002]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476556.649504, '127.0.0.1', 4002]
01:20:05 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 794:Checking stage connection
01:20:05 PM:INFO:Foraging:Foraging.py:_GetPositions:line 806:Grabbing current stage position
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.762848, '127.0.0.1', 4003]
01:20:05 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
01:20:05 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
01:20:05 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4257:Current trial: 61
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 11476556.806976, '127.0.0.1', 4002]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 11476556.811488, '127.0.0.1', 4002]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.887552, '127.0.0.1', 4003]
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476556.925984, '127.0.0.1', 4003]
01:20:05 PM:INFO:Foraging:Foraging.py:_Save:line 2480:Saving current session, ForceSave=1
01:20:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476557.017312, '127.0.0.1', 4003]
01:20:05 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1102:Loaded Water Calibration
01:20:05 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-09_13-10-22
01:20:05 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
01:20:05 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
01:20:05 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:05 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476557.153728, '127.0.0.1', 4003]
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
01:20:06 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
01:20:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476558.792512, '127.0.0.1', 4003]
01:20:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476558.960096, '127.0.0.1', 4003]
01:20:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476559.272928, '127.0.0.1', 4003]
01:20:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476559.696224, '127.0.0.1', 4003]
01:20:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476559.815104, '127.0.0.1', 4003]
01:20:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476559.963936, '127.0.0.1', 4003]
01:20:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476559.996, '127.0.0.1', 4003]
01:20:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476560.11152, '127.0.0.1', 4003]
01:20:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476560.280032, '127.0.0.1', 4003]
01:20:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476560.974208, '127.0.0.1', 4003]
01:20:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476561.10128, '127.0.0.1', 4003]
01:20:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11476562.830976, '127.0.0.1', 4002]
01:20:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476562.833504, '127.0.0.1', 4002]
01:20:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 11476563.813984, '127.0.0.1', 4002]
01:20:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 11476563.82912, 4, '127.0.0.1']
01:20:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476563.81648, '127.0.0.1', 4002]
01:20:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.032992, '127.0.0.1', 4003]
01:20:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 11476564.032, '127.0.0.1', 4002]
01:20:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
01:20:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.072992, '127.0.0.1', 4003]
01:20:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.151488, '127.0.0.1', 4003]
01:20:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.192, '127.0.0.1', 4003]
01:20:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.579744, '127.0.0.1', 4003]
01:20:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.711552, '127.0.0.1', 4003]
01:20:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.736992, '127.0.0.1', 4003]
01:20:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476564.851936, '127.0.0.1', 4003]
01:20:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476565.001152, '127.0.0.1', 4003]
01:20:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476566.450752, '127.0.0.1', 4003]
01:20:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 11476567.048, '127.0.0.1', 4002]
01:20:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476567.049504, '127.0.0.1', 4002]
01:20:15 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 794:Checking stage connection
01:20:16 PM:INFO:Foraging:Foraging.py:_GetPositions:line 806:Grabbing current stage position
01:20:16 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
01:20:16 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
01:20:16 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4257:Current trial: 62
01:20:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 11476567.192, '127.0.0.1', 4002]
01:20:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 11476567.195488, '127.0.0.1', 4002]
01:20:16 PM:INFO:Foraging:Foraging.py:_Save:line 2480:Saving current session, ForceSave=1
01:20:16 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1102:Loaded Water Calibration
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-09_13-10-22
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
01:20:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
01:20:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11476569.646976, '127.0.0.1', 4002]
01:20:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476569.649504, '127.0.0.1', 4002]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 11476570.630976, '127.0.0.1', 4002]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 11476570.646432, 4, '127.0.0.1']
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476570.633504, '127.0.0.1', 4002]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476570.872672, '127.0.0.1', 4003]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTime', 11476570.872, '127.0.0.1', 4003]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedLeftWaterStartTime', 11476570.872, '127.0.0.1', 4003]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 11476570.872, '127.0.0.1', 4002]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardLeft', '127.0.0.1', 4002]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 11476570.87648, '127.0.0.1', 4003]
01:20:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476570.993152, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.1408, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.245408, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.358752, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.47664, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.498976, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.581632, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.687392, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.799488, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476571.909728, '127.0.0.1', 4003]
01:20:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.022208, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.144096, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.255232, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.374848, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.48544, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.61376, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.733984, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.867968, '127.0.0.1', 4003]
01:20:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476572.999904, '127.0.0.1', 4003]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476573.133696, '127.0.0.1', 4003]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476573.172, '127.0.0.1', 4003]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476573.278912, '127.0.0.1', 4003]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476573.640384, '127.0.0.1', 4003]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476573.765536, '127.0.0.1', 4003]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 11476573.880992, '127.0.0.1', 4002]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476573.883488, '127.0.0.1', 4002]
01:20:22 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 794:Checking stage connection
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476573.905216, '127.0.0.1', 4003]
01:20:22 PM:INFO:Foraging:Foraging.py:_GetPositions:line 806:Grabbing current stage position
01:20:22 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
01:20:22 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.036288, '127.0.0.1', 4003]
01:20:22 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4257:Current trial: 63
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 11476574.04, '127.0.0.1', 4002]
01:20:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 11476574.043488, '127.0.0.1', 4002]
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.092992, '127.0.0.1', 4003]
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.175872, '127.0.0.1', 4003]
01:20:23 PM:INFO:Foraging:Foraging.py:_Save:line 2480:Saving current session, ForceSave=1
01:20:23 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1102:Loaded Water Calibration
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\764791\behavior_764791_2025-01-09_13-10-22
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1297:No reward delivery metadata found!
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1234:No dates found in the LaserCalibrationResults.
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.35024, '127.0.0.1', 4003]
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 969:No ephys data stream detected!
01:20:23 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.47696, '127.0.0.1', 4003]
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.617248, '127.0.0.1', 4003]
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.757472, '127.0.0.1', 4003]
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476574.9, '127.0.0.1', 4003]
01:20:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476575.041728, '127.0.0.1', 4003]
01:20:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476575.179008, '127.0.0.1', 4003]
01:20:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476575.3016, '127.0.0.1', 4003]
01:20:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476575.457376, '127.0.0.1', 4003]
01:20:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476575.502976, '127.0.0.1', 4003]
01:20:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476575.59936, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.425792, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.454976, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.550624, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.688896, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.850912, '127.0.0.1', 4003]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 11476576.930976, '127.0.0.1', 4002]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 11476576.937504, '127.0.0.1', 4002]
01:20:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476576.996032, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.13296, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.271296, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.410624, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.546912, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.698144, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.76, '127.0.0.1', 4003]
01:20:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11476577.866368, '127.0.0.1', 4003]
01:20:27 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 22.99%.
01:20:27 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 6.25%.
01:20:27 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 22.57%.
01:20:27 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box 1A mouse 764791 exceeded 10%

@ellahiltonvano
Copy link

@KanghoonJ this is your mouse if you could investigate the validity of this warning

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
low priority - auto-generated autogenerated issues that have only occurred once
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@alexpiet @ellahiltonvano