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 cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10% #1257

Open
alexpiet opened this issue Dec 24, 2024 · 2 comments
Open

Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10% #1257

alexpiet opened this issue Dec 24, 2024 · 2 comments
Labels
medium priority - auto-generated autogenerated issues that have occurred more than once in a month

Comments

@alexpiet
Copy link
Collaborator

This issue was automatically generated from GUI logs.

file: MyFunctions.py
function: calculate_inter_lick_intervals
line 957
logfile: W10DT714683/W10DT714683-C_gui_log_2024-12-23_13-48-15.txt
boxes: 7C
count: 4
text: Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%

GUI Log snippet (click for full log)

03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868720.95328, '127.0.0.1', 4023]
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868721.764, '127.0.0.1', 4022]
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868721.767488, '127.0.0.1', 4022]
03:56:46 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:46 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 88
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868721.782976, '127.0.0.1', 4022]
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868721.786496, '127.0.0.1', 4022]
03:56:46 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868722.535648, '127.0.0.1', 4023]
03:56:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868722.559872, '127.0.0.1', 4023]
03:56:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868722.707968, '127.0.0.1', 4023]
03:56:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868723.91664, '127.0.0.1', 4023]
03:56:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868724.126624, '127.0.0.1', 4023]
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 6.21%.
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 19.24%.
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 9.90%.
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 49.63%.
03:56:51 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%
Full GUI log (first 200 and last 200 lines) 
01:48:15 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4796:Starting logfile!
01:48:17 PM: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)]
01:48:17 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4824:Current git commit branch, hash: main, 698fb9fecded812fcf96d570658d9bc3766b14c6
01:48:17 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4828:Current foraging_gui version: 1.6.19
01:48:17 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4838:local repository is clean
01:48:17 PM:INFO:Foraging:Foraging.py:<module>:line 4944:Setting QApplication attributes
01:48:17 PM:INFO:Foraging:Foraging.py:<module>:line 4952:Starting QApplication and Window
01:48:17 PM:INFO:Foraging:Foraging.py:__init__:line 77:Creating Window
01:48:17 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1211:Loaded settings_box file
01:48:17 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1239:Loaded settings file
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_workflow_path), using default: 
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_settings), using default: C:\Users\svc_aind_behavior\Documents\FIPSettings
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\metadata_dialog\
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\rig_metadata\
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (project_info_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\Project Name and Funding Source v2.csv
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box1), using default: 60
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box2), using default: 60
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box4), using default: 60
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box1), using default: 5000
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box2), using default: 5000
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box3), using default: 5000
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box4), using default: 5000
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\name_mapper.json
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (create_rig_metadata), using default: True
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (AutomaticUpload), using default: True
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_behavior\Documents\aind_watchdog_service\manifest
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (auto_engage), using default: True
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (clear_figure_after_save), using default: True
01:48:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (add_default_project_name), using default: True
01:48:17 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1137:Loaded behavior schedule
01:48:17 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
01:48:17 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1572:Found existing rig.json: rig_446-7-C_2024-12-18_15_27_23.json
01:48:17 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 60:building rig json
01:48:17 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 624:finished building rig json
01:48:17 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json:line 53:Using existing rig json
01:48:17 PM:INFO:Foraging:Foraging.py:_LoadUI:line 299:Using ForagingGUI.ui interface
01:48:17 PM:INFO:Foraging:Foraging.py:__init__:line 143:Setting Window title: 446-7-C
01:48:17 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1409:Trying to connect to already running Bonsai
01:48:17 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
01:48:18 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1413:Could not connect: timed out
01:48:18 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1422:Starting Bonsai
01:48:18 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4911:BONSAI logging starting
01:48:19 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
01:48:20 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 0.5 seconds: timed out
01:48:20 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
01:48:21 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 1.0 seconds: timed out
01:48:22 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
01:48:22 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1439:Connected to Bonsai after 1.5 seconds
01:48:22 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1440:Bonsai started successfully
01:48:22 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1318:Attempting to connect to Slims
01:48:23 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1335:Successfully connected to Slims
01:48:23 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_behavior\Documents\ForagingSettings\WaterCalibrationPar_3.json
01:48:23 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 912:Scanning for newscale stages
01:48:23 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 922:Could not find any instances of NewScale Stage
01:48:23 PM:INFO:Foraging:Foraging.py:_insert_stage_widget:line 279:Inserting Stage Widget
01:48:23 PM:INFO:connection:connection.py:_connect:line 688:Connecting to aibspi(10.128.108.106):2181, use_ssl: False
01:48:23 PM:INFO:client:client.py:_session_callback:line 561:Zookeeper connection established, state: CONNECTED
01:48:23 PM:INFO:connection:connection.py:_connect_attempt:line 655:Closing connection to aibspi:2181
01:48:23 PM:INFO:client:client.py:_session_callback:line 567:Zookeeper session closed, state: CLOSED
01:48:24 PM:INFO:main:main.py:get_stage_widget:line 23:Getting Stage Controller Widget - 1.0.4.dev1+g5cafa8d.b163669
01:48:24 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM3 - device may be being used by another program
01:48:24 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM4 - device may be being used by another program
01:48:24 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 70:Connected to COM6, device id: 1130
01:48:24 PM:INFO:stepper_motor_device:stepper_motor_device.py:load_registers:line 151:Getting available registers on device
01:48:24 PM:WARNING:stepper_motor_device:stepper_motor_device.py:load_registers:line 159:Firmware version 0.5 doesn't match config version 0.7.
    Registers may be defined incorrectly
01:48:24 PM:INFO:stage_model:stage_model.py:configure_device:line 81:Configuring registers with default values (can be modified in config file)
01:48:24 PM:INFO:move_worker:move_worker.py:goto_origin:line 195:(move to origin): Moving stage to origin
01:48:24 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, -27200, -27200, 0]
01:48:24 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [-27200, 0, 0, 0]
01:48:31 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, 0, 0, -27200]
01:48:31 PM:INFO:stage_model:stage_model.py:configure_device:line 87:Zeroed all motor positions
01:48:31 PM:INFO:stage_model:stage_model.py:configure_device:line 88:Finished configuring stepper motor device
#############################################################
01:48:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
01:48:31 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1572:Found existing rig.json: rig_446-7-C_2024-12-18_15_27_23.json
01:48:31 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1008:attempting to close bonsai connection
01:48:34 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1016:bonsai connection closed
01:48:34 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1018:attempting to restart bonsai
01:48:34 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1409:Trying to connect to already running Bonsai
01:48:34 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
01:48:34 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1416:Connected to already running Bonsai
01:48:34 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1417:Bonsai started successfully
01:48:34 PM:INFO:Foraging:Foraging.py:__init__:line 243:Start up complete
01:48:39 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) = 11636
01:48:40 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) = 4708
01:48:40 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_behavior/capsule/scratch/saved_curriculums/
01:48:40 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
01:48:41 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_behavior/.aind_auto_train/curriculum_manager/
01:48:41 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/.aind_auto_train/curriculum_manager/
01:48:41 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 0
01:48:41 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=2
01:48:41 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
01:49:19 PM:INFO:Dialogs:Dialogs.py:_start_preview:line 1213:Camera is on
01:52:25 PM:INFO:move_worker:move_worker.py:move_to_preset_position:line 178:(move to preset position): Moving stage to preset initialize with coordinates [15, 16, 16, 12]
01:52:28 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 0, 0, 0] to [0, 12800, 12800, 0]
01:52:31 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 12800, 12800, 0] to [12000, 12800, 12800, 0]
01:52:34 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 12800, 12800, 0] to [12000, 12800, 12800, 9600]
01:54:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 861405.654976, '127.0.0.1', 4023]
01:54:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 861405.66048, '127.0.0.1', 4023]
01:54:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 861412.56, '127.0.0.1', 4023]
01:54:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 861412.562496, '127.0.0.1', 4023]
01:54:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 861413.512, '127.0.0.1', 4023]
01:54:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 861413.515488, '127.0.0.1', 4023]
01:55:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 861422.644992, '127.0.0.1', 4023]
01:55:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 861422.647488, '127.0.0.1', 4023]
03:26:59 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:00 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 12800, 12800, 9600] to [12000, 13600, 13600, 9600]
03:27:00 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:00 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 13600, 13600, 9600] to [12000, 14400, 14400, 9600]
03:27:01 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:01 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 14400, 14400, 9600] to [12000, 15200, 15200, 9600]
03:27:01 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:02 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 15200, 15200, 9600] to [12000, 16000, 16000, 9600]
03:27:02 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:03 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 16000, 16000, 9600] to [12000, 16800, 16800, 9600]
03:27:03 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:03 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 16800, 16800, 9600] to [12000, 17600, 17600, 9600]
03:27:04 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:04 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 17600, 17600, 9600] to [12000, 18400, 18400, 9600]
03:27:05 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:05 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 18400, 18400, 9600] to [12000, 19200, 19200, 9600]
03:27:06 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:06 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 19200, 19200, 9600] to [12000, 20000, 20000, 9600]
03:27:07 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:08 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 20000, 20000, 9600] to [12800, 20000, 20000, 9600]
03:27:09 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:10 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12800, 20000, 20000, 9600] to [13600, 20000, 20000, 9600]
03:27:10 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:11 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 9600] to [13600, 20000, 20000, 10400]
03:27:11 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:11 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 10400] to [13600, 20000, 20000, 11200]
03:27:13 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:14 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 11200] to [13600, 20000, 20000, 12000]
03:27:14 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:15 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 12000] to [13600, 20000, 20000, 12800]
03:27:15 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:16 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 12800] to [13600, 20000, 20000, 13600]
03:27:16 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:17 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 13600] to [13600, 20000, 20000, 14400]
03:27:20 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:21 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 14400] to [13600, 20000, 20000, 13600]
03:27:22 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 1 and 2
03:27:22 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20000, 20000, 13600] to [13600, 20800, 20800, 13600]
03:27:24 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:24 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20800, 20800, 13600] to [13600, 20800, 20800, 14400]
03:27:26 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:27 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20800, 20800, 14400] to [12800, 20800, 20800, 14400]
03:27:28 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:28 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12800, 20800, 20800, 14400] to [13600, 20800, 20800, 14400]
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:27:31 PM:INFO:move_worker:move_worker.py:update_step_size:line 261:(update step size): Setting step size to 0.1
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.044
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.044
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR, 0.03 -> 0.044
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y1, 0.0 -> 26.0
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_z, 0.0 -> 18.0
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y2, 0.0 -> 26.0
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_x, 0.0 -> 17.0
03:27:31 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_step_size, 1.0 -> 0.1
03:27:33 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:33 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13600, 20800, 20800, 14400] to [13519, 20800, 20800, 14400]
03:27:33 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:34 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13519, 20800, 20800, 14400] to [13438, 20800, 20800, 14400]
03:27:35 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:35 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13438, 20800, 20800, 14400] to [13357, 20800, 20800, 14400]
03:27:35 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 0
03:27:35 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13357, 20800, 20800, 14400] to [13276, 20800, 20800, 14400]
03:27:38 PM:INFO:move_worker:move_worker.py:axis_motion:line 94:(axis motion): Moving motor 3
03:27:38 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [13276, 20800, 20800, 14400] to [13276, 20800, 20800, 14480]
03:27:58 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 762206
03:27:59 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
03:28:01 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'}
03:28:01 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'.
03:28:01 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'}
03:28:01 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'.
03:28:02 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Dialogs.py:2684: FutureWarning: The behavior of DataFrame concatenation with empty or all-NA entries is deprecated. In a future version, this will no longer exclude empty or all-NA columns when determining the result dtypes. To retain the old behavior, exclude the relevant entries before the concat operation.
  self.df_training_manager = pd.concat(

03:28:02 PM:INFO:Dialogs:Dialogs.py:_apply_curriculum:line 2707:Added a dummy session 0 for mouse 762206 
03:28:02 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=0
03:28:02 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'}
03:28:02 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'.
03:28:02 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'.
03:28:02 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: STAGE_1_WARMUP @Uncoupled Baiting ([email protected])
03:28:02 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: STAGE_1_WARMUP @Uncoupled Baiting ([email protected])
03:28:02 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'}
03:28:02 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'.
03:28:02 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2793:AutoTrain engaged! STAGE_1_WARMUP @ Uncoupled Baiting ([email protected])
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "training_stage" not found. skipped...
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2916:Task is set to Coupled Baiting
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_url" not found. skipped...
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_schema_version" not found. skipped...
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "description" not found. skipped...
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BaseRewardSum is set to 0.8
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:RewardFamily is set to 3
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:RewardPairsN is set to 1
03:28:02 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "UncoupledReward" has been disabled by the GUI. skipped...
_____SKIPPING_____
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 868693.472992, '127.0.0.1', 4022]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868693.666656, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868693.883968, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868693.923264, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868694.1136, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868694.318752, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868694.464, '127.0.0.1', 4022]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868694.467488, '127.0.0.1', 4022]
03:56:19 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:19 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 82
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868694.482976, '127.0.0.1', 4022]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868694.485504, '127.0.0.1', 4022]
03:56:19 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868694.539744, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868694.880288, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868695.013376, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868695.21232, '127.0.0.1', 4023]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868695.680576, '127.0.0.1', 4023]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868695.846272, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 868696.580992, '127.0.0.1', 4022]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868696.583488, '127.0.0.1', 4022]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 868696.680992, '127.0.0.1', 4022]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868696.68448, '127.0.0.1', 4022]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 868696.684192, 4, '127.0.0.1']
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868696.694368, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 868696.693984, '127.0.0.1', 4022]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTime', 868696.693984, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardLeft', '127.0.0.1', 4022]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedLeftWaterStartTime', 868696.693984, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 868696.697504, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868696.848096, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868696.973088, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868697.116704, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868697.249088, '127.0.0.1', 4023]
03:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868697.39712, '127.0.0.1', 4023]
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868697.544448, '127.0.0.1', 4023]
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868697.68, '127.0.0.1', 4022]
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868697.683488, '127.0.0.1', 4022]
03:56:22 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:22 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 83
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868697.697088, '127.0.0.1', 4023]
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868697.704, '127.0.0.1', 4022]
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868697.707488, '127.0.0.1', 4022]
03:56:22 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868697.873024, '127.0.0.1', 4023]
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868698.058496, '127.0.0.1', 4023]
03:56:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868698.294784, '127.0.0.1', 4023]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868698.46, '127.0.0.1', 4023]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868698.65392, '127.0.0.1', 4023]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868698.797568, '127.0.0.1', 4023]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868698.826464, '127.0.0.1', 4023]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 868699.148, '127.0.0.1', 4022]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868699.150496, '127.0.0.1', 4022]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 868699.248, '127.0.0.1', 4022]
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 868699.2512, 4, '127.0.0.1']
03:56:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868699.251488, '127.0.0.1', 4022]
03:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868699.817856, '127.0.0.1', 4023]
03:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 868699.816992, '127.0.0.1', 4022]
03:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
03:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868699.950272, '127.0.0.1', 4023]
03:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868699.96704, '127.0.0.1', 4023]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868700.813984, '127.0.0.1', 4022]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868700.817504, '127.0.0.1', 4022]
03:56:25 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:25 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 84
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868700.838976, '127.0.0.1', 4022]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868700.842496, '127.0.0.1', 4022]
03:56:25 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868701.223776, '127.0.0.1', 4023]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868701.3616, '127.0.0.1', 4023]
03:56:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868702.751456, '127.0.0.1', 4023]
03:56:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868703.21552, '127.0.0.1', 4023]
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868703.442528, '127.0.0.1', 4023]
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868703.649728, '127.0.0.1', 4023]
03:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868704.451264, '127.0.0.1', 4023]
03:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868704.784352, '127.0.0.1', 4023]
03:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868704.81472, '127.0.0.1', 4023]
03:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 868706.196992, '127.0.0.1', 4022]
03:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868706.20048, '127.0.0.1', 4022]
03:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 868706.296992, '127.0.0.1', 4022]
03:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 868706.301248, 4, '127.0.0.1']
03:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868706.301504, '127.0.0.1', 4022]
03:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868706.581664, '127.0.0.1', 4023]
03:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 868706.580992, '127.0.0.1', 4022]
03:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
03:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868707.580992, '127.0.0.1', 4022]
03:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868707.583488, '127.0.0.1', 4022]
03:56:32 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:32 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 85
03:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868707.598976, '127.0.0.1', 4022]
03:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868707.602496, '127.0.0.1', 4022]
03:56:32 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868707.864, '127.0.0.1', 4023]
03:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868708.022432, '127.0.0.1', 4023]
03:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868708.263392, '127.0.0.1', 4023]
03:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 868708.914976, '127.0.0.1', 4022]
03:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868708.917504, '127.0.0.1', 4022]
03:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 868709.014976, '127.0.0.1', 4022]
03:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 868709.018272, 4, '127.0.0.1']
03:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868709.018496, '127.0.0.1', 4022]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868710.633408, '127.0.0.1', 4023]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 868710.632992, '127.0.0.1', 4022]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868710.661952, '127.0.0.1', 4023]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868711.630976, '127.0.0.1', 4022]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868711.633504, '127.0.0.1', 4022]
03:56:36 PM:WARNING:MyFunctions:MyFunctions.py:_CheckAutoWater:line 1236:Auto water because unrewarded trials exceed: 3
03:56:36 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:36 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 86
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868711.652, '127.0.0.1', 4022]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868711.655488, '127.0.0.1', 4022]
03:56:36 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868712.319904, '127.0.0.1', 4023]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 868713.080992, '127.0.0.1', 4022]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868713.083488, '127.0.0.1', 4022]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 868713.180992, '127.0.0.1', 4022]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868713.18448, '127.0.0.1', 4022]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 868713.18528, 4, '127.0.0.1']
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/AutoLeftWaterStartTime', 868713.188, '127.0.0.1', 4023]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/AutoRightWaterStartTime', 868713.188992, '127.0.0.1', 4023]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 868713.190496, '127.0.0.1', 4023]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 868713.191488, '127.0.0.1', 4023]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868713.239552, '127.0.0.1', 4023]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 868713.238976, '127.0.0.1', 4022]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868713.281792, '127.0.0.1', 4023]
03:56:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868713.384544, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868713.476672, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868713.588512, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868713.604416, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868713.604448, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868713.736096, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868713.878688, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868713.99648, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868714.18848, '127.0.0.1', 4023]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868714.230976, '127.0.0.1', 4022]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868714.233504, '127.0.0.1', 4022]
03:56:38 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:38 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 87
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868714.253984, '127.0.0.1', 4022]
03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868714.25648, '127.0.0.1', 4022]
03:56:38 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:38 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868714.349632, '127.0.0.1', 4023]
03:56:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868714.456896, '127.0.0.1', 4023]
03:56:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868714.63008, '127.0.0.1', 4023]
03:56:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868714.863616, '127.0.0.1', 4023]
03:56:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868715.017952, '127.0.0.1', 4023]
03:56:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868715.205312, '127.0.0.1', 4023]
03:56:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868715.402688, '127.0.0.1', 4023]
03:56:40 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868715.653888, '127.0.0.1', 4023]
03:56:40 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868715.860768, '127.0.0.1', 4023]
03:56:40 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868715.998368, '127.0.0.1', 4023]
03:56:40 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868716.350016, '127.0.0.1', 4023]
03:56:41 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868716.557248, '127.0.0.1', 4023]
03:56:41 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868716.574176, '127.0.0.1', 4023]
03:56:41 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868716.708224, '127.0.0.1', 4023]
03:56:41 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868716.964, '127.0.0.1', 4023]
03:56:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868718.479232, '127.0.0.1', 4023]
03:56:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868718.7176, '127.0.0.1', 4023]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 868720.464, '127.0.0.1', 4022]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868720.467488, '127.0.0.1', 4022]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 868720.564, '127.0.0.1', 4022]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 868720.568352, 4, '127.0.0.1']
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868720.56848, '127.0.0.1', 4022]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 868720.777792, '127.0.0.1', 4023]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 868720.776992, '127.0.0.1', 4022]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:56:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868720.95328, '127.0.0.1', 4023]
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 868721.764, '127.0.0.1', 4022]
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 868721.767488, '127.0.0.1', 4022]
03:56:46 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:46 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 88
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 868721.782976, '127.0.0.1', 4022]
03:56:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 868721.786496, '127.0.0.1', 4022]
03:56:46 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868722.535648, '127.0.0.1', 4023]
03:56:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868722.559872, '127.0.0.1', 4023]
03:56:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868722.707968, '127.0.0.1', 4023]
03:56:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868723.91664, '127.0.0.1', 4023]
03:56:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 868724.126624, '127.0.0.1', 4023]
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 6.21%.
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 19.24%.
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 9.90%.
03:56:51 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 49.63%.
03:56:51 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%
@alexpiet alexpiet added the low priority - auto-generated autogenerated issues that have only occurred once label Dec 24, 2024
@alexpiet
Copy link
Collaborator Author

This issue reoccurred:

file: MyFunctions.py
function: calculate_inter_lick_intervals
line 957
logfile: W10DT714683/W10DT714683-C_gui_log_2024-12-27_15-19-08.txt
boxes: 7C
count: 17
text: Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%

GUI Log snippet (click for full log)

04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215631.717312, '127.0.0.1', 4023]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1215631.716992, '127.0.0.1', 4022]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215631.852032, '127.0.0.1', 4023]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215632.059296, '127.0.0.1', 4023]
04:18:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215632.237248, '127.0.0.1', 4023]
04:18:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215632.885792, '127.0.0.1', 4023]
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1215634.732, '127.0.0.1', 4022]
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215634.735488, '127.0.0.1', 4022]
04:18:39 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
04:18:39 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
04:18:39 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 213
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1215634.752, '127.0.0.1', 4022]
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1215634.755488, '127.0.0.1', 4022]
04:18:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215637.663168, '127.0.0.1', 4023]
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 2.00%.
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 5.59%.
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 3.47%.
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 10.30%.
04:18:44 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%
Full GUI log (first 200 and last 200 lines) 
03:19:08 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4796:Starting logfile!
03:19:09 PM: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)]
03:19:09 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4824:Current git commit branch, hash: main, 698fb9fecded812fcf96d570658d9bc3766b14c6
03:19:09 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4828:Current foraging_gui version: 1.6.19
03:19:09 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4838:local repository is clean
03:19:09 PM:INFO:Foraging:Foraging.py:<module>:line 4944:Setting QApplication attributes
03:19:09 PM:INFO:Foraging:Foraging.py:<module>:line 4952:Starting QApplication and Window
03:19:09 PM:INFO:Foraging:Foraging.py:__init__:line 77:Creating Window
03:19:09 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1211:Loaded settings_box file
03:19:09 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1239:Loaded settings file
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_workflow_path), using default: 
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_settings), using default: C:\Users\svc_aind_behavior\Documents\FIPSettings
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\metadata_dialog\
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\rig_metadata\
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (project_info_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\Project Name and Funding Source v2.csv
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box1), using default: 60
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box2), using default: 60
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box4), using default: 60
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box1), using default: 5000
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box2), using default: 5000
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box3), using default: 5000
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box4), using default: 5000
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\name_mapper.json
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (create_rig_metadata), using default: True
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (AutomaticUpload), using default: True
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_behavior\Documents\aind_watchdog_service\manifest
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (auto_engage), using default: True
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (clear_figure_after_save), using default: True
03:19:09 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (add_default_project_name), using default: True
03:19:09 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1137:Loaded behavior schedule
03:19:09 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
03:19:09 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1572:Found existing rig.json: rig_446-7-C_2024-12-18_15_27_23.json
03:19:09 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 60:building rig json
03:19:09 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 624:finished building rig json
03:19:09 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json:line 53:Using existing rig json
03:19:09 PM:INFO:Foraging:Foraging.py:_LoadUI:line 299:Using ForagingGUI.ui interface
03:19:09 PM:INFO:Foraging:Foraging.py:__init__:line 143:Setting Window title: 446-7-C
03:19:09 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1409:Trying to connect to already running Bonsai
03:19:09 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:19:10 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1413:Could not connect: timed out
03:19:10 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1422:Starting Bonsai
03:19:10 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4911:BONSAI logging starting
03:19:11 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:19:12 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 0.5 seconds: timed out
03:19:12 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:19:12 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1439:Connected to Bonsai after 1.0 seconds
03:19:12 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1440:Bonsai started successfully
03:19:12 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1318:Attempting to connect to Slims
03:19:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 1212068.12352, '127.0.0.1', 4023], displaying at 0.5 Hz
03:19:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 1212068.131488, '127.0.0.1', 4023]
03:19:13 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1335:Successfully connected to Slims
03:19:13 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_behavior\Documents\ForagingSettings\WaterCalibrationPar_3.json
03:19:13 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 912:Scanning for newscale stages
03:19:13 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 922:Could not find any instances of NewScale Stage
03:19:13 PM:INFO:Foraging:Foraging.py:_insert_stage_widget:line 279:Inserting Stage Widget
03:19:13 PM:INFO:connection:connection.py:_connect:line 688:Connecting to aibspi(10.128.108.106):2181, use_ssl: False
03:19:13 PM:INFO:client:client.py:_session_callback:line 561:Zookeeper connection established, state: CONNECTED
03:19:13 PM:INFO:connection:connection.py:_connect_attempt:line 655:Closing connection to aibspi:2181
03:19:13 PM:INFO:client:client.py:_session_callback:line 567:Zookeeper session closed, state: CLOSED
03:19:13 PM:INFO:main:main.py:get_stage_widget:line 23:Getting Stage Controller Widget - 1.0.4.dev1+g5cafa8d.b163669
03:19:13 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM3 - device may be being used by another program
03:19:13 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM4 - device may be being used by another program
03:19:13 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 70:Connected to COM6, device id: 1130
03:19:13 PM:INFO:stepper_motor_device:stepper_motor_device.py:load_registers:line 151:Getting available registers on device
03:19:13 PM:WARNING:stepper_motor_device:stepper_motor_device.py:load_registers:line 159:Firmware version 0.5 doesn't match config version 0.7.
    Registers may be defined incorrectly
03:19:13 PM:INFO:stage_model:stage_model.py:configure_device:line 81:Configuring registers with default values (can be modified in config file)
03:19:13 PM:INFO:move_worker:move_worker.py:goto_origin:line 195:(move to origin): Moving stage to origin
03:19:13 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, -27200, -27200, 0]
03:19:15 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [-27200, 0, 0, 0]
03:19:22 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, 0, 0, -27200]
03:19:24 PM:INFO:stage_model:stage_model.py:configure_device:line 87:Zeroed all motor positions
03:19:24 PM:INFO:stage_model:stage_model.py:configure_device:line 88:Finished configuring stepper motor device
#############################################################
03:19:24 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:19:24 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1572:Found existing rig.json: rig_446-7-C_2024-12-18_15_27_23.json
03:19:24 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1008:attempting to close bonsai connection
03:19:26 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1016:bonsai connection closed
03:19:26 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1018:attempting to restart bonsai
03:19:26 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1409:Trying to connect to already running Bonsai
03:19:26 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:19:26 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1416:Connected to already running Bonsai
03:19:26 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1417:Bonsai started successfully
03:19:26 PM:INFO:Foraging:Foraging.py:__init__:line 243:Start up complete
03:19:29 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) = 12511
03:19:29 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) = 4724
03:19:30 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_behavior/capsule/scratch/saved_curriculums/
03:19:30 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
03:19:31 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_behavior/.aind_auto_train/curriculum_manager/
03:19:31 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/.aind_auto_train/curriculum_manager/
03:19:31 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 0
03:19:31 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=2
03:19:31 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
03:19:55 PM:INFO:Dialogs:Dialogs.py:_start_preview:line 1213:Camera is on
03:19:57 PM:INFO:move_worker:move_worker.py:move_to_preset_position:line 178:(move to preset position): Moving stage to preset initialize with coordinates [15, 16, 16, 12]
03:20:00 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 0, 0, 0] to [0, 12800, 12800, 0]
03:20:04 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 12800, 12800, 0] to [12000, 12800, 12800, 0]
03:20:06 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 12800, 12800, 0] to [12000, 12800, 12800, 9600]
03:26:34 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3675:Stopping current trials
03:26:47 PM:INFO:Foraging:Foraging.py:_Open:line 3017:Quick load success: C:\behavior_data\446-7-C\762206\behavior_762206_2024-12-26_14-04-21\behavior\762206_2024-12-26_14-04-21.json
03:26:47 PM:INFO:Foraging:Foraging.py:_NewSession:line 3585:New Session pressed
03:26:47 PM:INFO:Foraging:Foraging.py:_NewSession:line 3617:Resetting session run flag
03:26:47 PM:INFO:Foraging:Foraging.py:_NewSession:line 3655:New Session complete
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayMin, 0.0 -> 0.5
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayBeta, 1.0 -> 0.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayMax, 1.0 -> 0.5
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.044
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue, 0.03 -> 0.019
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue_volume, 3.0 -> 2.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ID, 0.0 -> 762206.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayMin, 0.0 -> 0.5
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayBeta, 1.0 -> 0.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayMax, 1.0 -> 0.5
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.044
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue, 0.03 -> 0.019
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue_volume, 3.0 -> 2.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterL, 0.03 -> 0.019
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR, 0.03 -> 0.044
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterL_volume, 3.0 -> 2.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y1, 0.0 -> 16.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_z, 0.0 -> 12.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y2, 0.0 -> 16.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:26:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:26:48 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:26:48 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 16.6938, 1: 25.7975, 2: 25.7975, 3: 18.3987}
03:26:48 PM:INFO:Foraging:Foraging.py:_check_drop_frames:line 714:
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockMax, 60.0 -> 35.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIMax, 8.0 -> 15.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIBeta, 2.0 -> 3.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ResponseTime, 1.0 -> 2.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Ignored, 100.0 -> 10.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockBeta, 20.0 -> 10.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: MaxTime, 120.0 -> 75.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RewardConsumeTime, 3.0 -> 1.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Multiplier, 0.8 -> 0.5
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue_volume, 3.0 -> 2.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.044 -> 0.029
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Unrewarded, 200.0 -> 10.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: warm_min_trial, 60.0 -> 50.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockMax, 60.0 -> 35.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIMax, 8.0 -> 15.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIBeta, 2.0 -> 3.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ResponseTime, 1.0 -> 2.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Ignored, 100.0 -> 10.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockBeta, 20.0 -> 10.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: MaxTime, 120.0 -> 75.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RewardConsumeTime, 3.0 -> 1.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Multiplier, 0.8 -> 0.5
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue_volume, 3.0 -> 2.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.044 -> 0.029
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Unrewarded, 200.0 -> 10.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: warm_min_trial, 60.0 -> 50.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR, 0.044 -> 0.029
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR_volume, 3.0 -> 2.0
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y1, 16.0 -> 25.7975
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_z, 12.0 -> 18.3987
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y2, 16.0 -> 25.7975
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_x, 15.0 -> 16.6938
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_step_size, 1.0 -> 0.1
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: SuggestedWater,  -> 0.372
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BaseWeight,  -> 24.97
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: TargetWeight,  -> 21.224
03:26:48 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2844:AutoTrain disengaged!
03:26:48 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'.
03:26:48 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=0
03:26:48 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'}
03:26:48 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'.
03:26:48 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: STAGE_2 @Uncoupled Baiting ([email protected])
03:26:48 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: STAGE_2 @Uncoupled Baiting ([email protected])
03:26:48 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'}
03:26:48 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'.
03:26:48 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2793:AutoTrain engaged! STAGE_2 @ Uncoupled Baiting ([email protected])
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "training_stage" not found. skipped...
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:26:48 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2916:Task is set to Coupled Baiting
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_url" not found. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_schema_version" not found. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "description" not found. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BaseRewardSum" has been disabled by the GUI. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "RewardFamily" has been disabled by the GUI. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "RewardPairsN" has been disabled by the GUI. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:UncoupledReward is set to 
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:Randomness is set to Exponential
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMin is set to 20
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMax is set to 35
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BlockBeta" has been disabled by the GUI. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BlockMinReward" has been disabled by the GUI. skipped...
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayMin is set to 0.3
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayMax is set to 0.3
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayBeta is set to 0.0
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:RewardDelay is set to 0.0
03:26:48 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:AutoReward is set to True
_____SKIPPING_____
04:16:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215519.485248, '127.0.0.1', 4023]
04:16:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215519.652352, '127.0.0.1', 4023]
04:16:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215520.494528, '127.0.0.1', 4023]
04:16:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1215522.332, '127.0.0.1', 4022]
04:16:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215522.334496, '127.0.0.1', 4022]
04:16:47 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
04:16:47 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
04:16:47 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 208
04:16:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1215522.352, '127.0.0.1', 4022]
04:16:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1215522.355488, '127.0.0.1', 4022]
04:16:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215522.858624, '127.0.0.1', 4023]
04:16:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215525.09392, '127.0.0.1', 4023]
04:16:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215526.060128, '127.0.0.1', 4023]
04:16:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215528.525888, '127.0.0.1', 4023]
04:16:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215529.148992, '127.0.0.1', 4022]
04:16:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215529.151488, '127.0.0.1', 4022]
04:16:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215530.096224, '127.0.0.1', 4023]
04:16:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215531.39424, '127.0.0.1', 4023]
04:16:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215533.920736, '127.0.0.1', 4023]
04:16:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215534.753856, '127.0.0.1', 4023]
04:17:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215536.881984, '127.0.0.1', 4022]
04:17:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215536.885504, '127.0.0.1', 4022]
04:17:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1215537.865984, '127.0.0.1', 4022]
04:17:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1215537.869216, 4, '127.0.0.1']
04:17:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215537.869504, '127.0.0.1', 4022]
04:17:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215537.957856, '127.0.0.1', 4023]
04:17:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1215537.956992, '127.0.0.1', 4022]
04:17:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
04:17:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215538.140768, '127.0.0.1', 4023]
04:17:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215538.329248, '127.0.0.1', 4023]
04:17:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215538.509888, '127.0.0.1', 4023]
04:17:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215538.700544, '127.0.0.1', 4023]
04:17:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1215540.965984, '127.0.0.1', 4022]
04:17:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215540.96848, '127.0.0.1', 4022]
04:17:05 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
04:17:05 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
04:17:05 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 209
04:17:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1215540.985984, '127.0.0.1', 4022]
04:17:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1215540.98848, '127.0.0.1', 4022]
04:17:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215541.23248, '127.0.0.1', 4023]
04:17:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215542.193568, '127.0.0.1', 4023]
04:17:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215544.198976, '127.0.0.1', 4022]
04:17:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215544.201504, '127.0.0.1', 4022]
04:17:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1215545.181984, '127.0.0.1', 4022]
04:17:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215545.185504, '127.0.0.1', 4022]
04:17:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1215545.186272, 4, '127.0.0.1']
04:17:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215545.198272, '127.0.0.1', 4023]
04:17:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1215545.197984, '127.0.0.1', 4022]
04:17:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
04:17:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215545.392096, '127.0.0.1', 4023]
04:17:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215545.52272, '127.0.0.1', 4023]
04:17:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1215548.198976, '127.0.0.1', 4022]
04:17:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215548.201504, '127.0.0.1', 4022]
04:17:12 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
04:17:12 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
04:17:12 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 210
04:17:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1215548.22, '127.0.0.1', 4022]
04:17:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1215548.223488, '127.0.0.1', 4022]
04:17:13 PM:INFO:bias_indicator:bias_indicator.py:calculate_bias:line 158:Bias: -0.1904065095360435 Trial Count: 200
04:17:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215548.895584, '127.0.0.1', 4023]
04:17:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215548.918144, '127.0.0.1', 4023]
04:17:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215550.409856, '127.0.0.1', 4023]
04:17:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215553.73568, '127.0.0.1', 4023]
04:17:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215553.764992, '127.0.0.1', 4022]
04:17:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215553.76848, '127.0.0.1', 4022]
04:17:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215553.91008, '127.0.0.1', 4023]
04:17:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215554.34288, '127.0.0.1', 4023]
04:17:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215557.094432, '127.0.0.1', 4023]
04:17:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215558.628448, '127.0.0.1', 4023]
04:17:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215559.448992, '127.0.0.1', 4022]
04:17:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215559.451488, '127.0.0.1', 4022]
04:17:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215559.891904, '127.0.0.1', 4023]
04:17:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215561.50608, '127.0.0.1', 4023]
04:17:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215561.668448, '127.0.0.1', 4023]
04:17:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215561.877088, '127.0.0.1', 4023]
04:17:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215562.587264, '127.0.0.1', 4023]
04:17:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215564.534688, '127.0.0.1', 4023]
04:17:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215564.652416, '127.0.0.1', 4023]
04:17:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215565.432, '127.0.0.1', 4022]
04:17:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215565.43552, '127.0.0.1', 4022]
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1215566.416, '127.0.0.1', 4022]
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1215566.419424, 4, '127.0.0.1']
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215566.41952, '127.0.0.1', 4022]
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215566.576096, '127.0.0.1', 4023]
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1215566.576, '127.0.0.1', 4022]
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215566.780416, '127.0.0.1', 4023]
04:17:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215566.931424, '127.0.0.1', 4023]
04:17:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1215569.581984, '127.0.0.1', 4022]
04:17:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215569.585504, '127.0.0.1', 4022]
04:17:34 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
04:17:34 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
04:17:34 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 211
04:17:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1215569.605984, '127.0.0.1', 4022]
04:17:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1215569.609504, '127.0.0.1', 4022]
04:17:41 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215576.309728, '127.0.0.1', 4023]
04:17:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215580.214976, '127.0.0.1', 4022]
04:17:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215580.218496, '127.0.0.1', 4022]
04:17:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215581.104832, '127.0.0.1', 4023]
04:17:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215586.58064, '127.0.0.1', 4023]
04:17:52 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215587.88608, '127.0.0.1', 4023]
04:17:52 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215588.055776, '127.0.0.1', 4023]
04:17:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.075168, '127.0.0.1', 4023]
04:17:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215589.076704, '127.0.0.1', 4023]
04:17:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.097376, '127.0.0.1', 4023]
04:17:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.101312, '127.0.0.1', 4023]
04:17:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.12528, '127.0.0.1', 4023]
04:17:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215589.14032, '127.0.0.1', 4023]
04:17:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215589.143616, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215589.40112, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.430944, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215589.510528, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.876, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.901408, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215589.915424, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215589.956128, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215590.058464, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215590.071168, '127.0.0.1', 4023]
04:17:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215590.096384, '127.0.0.1', 4023]
04:17:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215590.23312, '127.0.0.1', 4023]
04:17:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215590.504416, '127.0.0.1', 4023]
04:17:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215590.542176, '127.0.0.1', 4023]
04:17:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215590.55136, '127.0.0.1', 4023]
04:17:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215590.867968, '127.0.0.1', 4023]
04:17:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215590.993632, '127.0.0.1', 4023]
04:17:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215591.574304, '127.0.0.1', 4023]
04:17:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215591.716, '127.0.0.1', 4022]
04:17:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215591.718496, '127.0.0.1', 4022]
04:17:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215592.285888, '127.0.0.1', 4023]
04:17:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215592.292864, '127.0.0.1', 4023]
04:17:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215592.545376, '127.0.0.1', 4023]
04:17:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215593.409856, '127.0.0.1', 4023]
04:17:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215593.482304, '127.0.0.1', 4023]
04:17:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215593.488864, '127.0.0.1', 4023]
04:17:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215593.72928, '127.0.0.1', 4023]
04:18:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215595.865216, '127.0.0.1', 4023]
04:18:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215595.985984, '127.0.0.1', 4023]
04:18:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215602.898976, '127.0.0.1', 4022]
04:18:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215602.902496, '127.0.0.1', 4022]
04:18:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215603.570368, '127.0.0.1', 4023]
04:18:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215603.73872, '127.0.0.1', 4023]
04:18:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215605.807328, '127.0.0.1', 4023]
04:18:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215605.810368, '127.0.0.1', 4023]
04:18:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215607.829728, '127.0.0.1', 4023]
04:18:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215608.01664, '127.0.0.1', 4023]
04:18:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215612.589792, '127.0.0.1', 4023]
04:18:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215614.181984, '127.0.0.1', 4022]
04:18:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215614.185504, '127.0.0.1', 4022]
04:18:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215614.859904, '127.0.0.1', 4023]
04:18:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215614.970304, '127.0.0.1', 4023]
04:18:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215616.520608, '127.0.0.1', 4023]
04:18:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215618.735904, '127.0.0.1', 4023]
04:18:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215625.358432, '127.0.0.1', 4023]
04:18:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215625.465984, '127.0.0.1', 4022]
04:18:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215625.469504, '127.0.0.1', 4022]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1215626.449984, '127.0.0.1', 4022]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1215626.453216, 4, '127.0.0.1']
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215626.453504, '127.0.0.1', 4022]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215626.569088, '127.0.0.1', 4023]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1215626.568992, '127.0.0.1', 4022]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTime', 1215626.568992, '127.0.0.1', 4023]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardLeft', '127.0.0.1', 4022]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedLeftWaterStartTime', 1215626.568992, '127.0.0.1', 4023]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 1215626.571488, '127.0.0.1', 4023]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215626.701856, '127.0.0.1', 4023]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215626.8744, '127.0.0.1', 4023]
04:18:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215627.02736, '127.0.0.1', 4023]
04:18:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215627.291232, '127.0.0.1', 4023]
04:18:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1215629.581984, '127.0.0.1', 4022]
04:18:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215629.585504, '127.0.0.1', 4022]
04:18:34 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
04:18:34 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
04:18:34 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 212
04:18:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1215629.612992, '127.0.0.1', 4022]
04:18:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1215629.61648, '127.0.0.1', 4022]
04:18:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1215630.632992, '127.0.0.1', 4022]
04:18:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215630.635488, '127.0.0.1', 4022]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1215631.616, '127.0.0.1', 4022]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215631.619488, '127.0.0.1', 4022]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1215631.620256, 4, '127.0.0.1']
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215631.717312, '127.0.0.1', 4023]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1215631.716992, '127.0.0.1', 4022]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215631.852032, '127.0.0.1', 4023]
04:18:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215632.059296, '127.0.0.1', 4023]
04:18:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1215632.237248, '127.0.0.1', 4023]
04:18:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215632.885792, '127.0.0.1', 4023]
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1215634.732, '127.0.0.1', 4022]
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1215634.735488, '127.0.0.1', 4022]
04:18:39 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
04:18:39 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
04:18:39 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 213
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1215634.752, '127.0.0.1', 4022]
04:18:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1215634.755488, '127.0.0.1', 4022]
04:18:42 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1215637.663168, '127.0.0.1', 4023]
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 2.00%.
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 5.59%.
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 3.47%.
04:18:44 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 10.30%.
04:18:44 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%

@alexpiet alexpiet added medium priority - auto-generated autogenerated issues that have occurred more than once in a month and removed low priority - auto-generated autogenerated issues that have only occurred once labels Dec 30, 2024
@alexpiet
Copy link
Collaborator Author

This issue reoccurred:

file: MyFunctions.py
function: calculate_inter_lick_intervals
line 957
logfile: W10DT714683/W10DT714683-C_gui_log_2024-12-30_15-33-41.txt
boxes: 7C
count: 5
text: Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%

GUI Log snippet (click for full log)

03:56:28 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:56:28 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:28 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 61
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473503.353984, '127.0.0.1', 4022]
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473503.35648, '127.0.0.1', 4022]
03:56:28 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473506.73824, '127.0.0.1', 4023]
03:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473506.886944, '127.0.0.1', 4023]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473510.901984, '127.0.0.1', 4022]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473510.90448, '127.0.0.1', 4022]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473511.444576, '127.0.0.1', 4023]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473511.600352, '127.0.0.1', 4023]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473511.79616, '127.0.0.1', 4023]
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 7.95%.
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 3.99%.
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 5.38%.
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 11.63%.
03:56:41 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%
Full GUI log (first 200 and last 200 lines) 
03:33:41 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4796:Starting logfile!
03:33:43 PM: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)]
03:33:43 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4824:Current git commit branch, hash: main, 698fb9fecded812fcf96d570658d9bc3766b14c6
03:33:43 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4828:Current foraging_gui version: 1.6.19
03:33:43 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4838:local repository is clean
03:33:43 PM:INFO:Foraging:Foraging.py:<module>:line 4944:Setting QApplication attributes
03:33:43 PM:INFO:Foraging:Foraging.py:<module>:line 4952:Starting QApplication and Window
03:33:43 PM:INFO:Foraging:Foraging.py:__init__:line 77:Creating Window
03:33:43 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1211:Loaded settings_box file
03:33:43 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1239:Loaded settings file
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_workflow_path), using default: 
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_settings), using default: C:\Users\svc_aind_behavior\Documents\FIPSettings
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\metadata_dialog\
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\rig_metadata\
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (project_info_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\Project Name and Funding Source v2.csv
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box1), using default: 60
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box2), using default: 60
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box4), using default: 60
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box1), using default: 5000
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box2), using default: 5000
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box3), using default: 5000
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box4), using default: 5000
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\name_mapper.json
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (create_rig_metadata), using default: True
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (AutomaticUpload), using default: True
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_behavior\Documents\aind_watchdog_service\manifest
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (auto_engage), using default: True
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (clear_figure_after_save), using default: True
03:33:43 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (add_default_project_name), using default: True
03:33:43 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1137:Loaded behavior schedule
03:33:43 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
03:33:43 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1572:Found existing rig.json: rig_446-7-C_2024-12-18_15_27_23.json
03:33:43 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 60:building rig json
03:33:43 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 624:finished building rig json
03:33:43 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json:line 53:Using existing rig json
03:33:44 PM:INFO:Foraging:Foraging.py:_LoadUI:line 299:Using ForagingGUI.ui interface
03:33:44 PM:INFO:Foraging:Foraging.py:__init__:line 143:Setting Window title: 446-7-C
03:33:44 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1409:Trying to connect to already running Bonsai
03:33:44 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:33:45 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1413:Could not connect: timed out
03:33:45 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1422:Starting Bonsai
03:33:45 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4911:BONSAI logging starting
03:33:45 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:33:46 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 0.5 seconds: timed out
03:33:47 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:33:48 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 1.0 seconds: timed out
03:33:48 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:33:49 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1436:Could not connect, total waiting time 1.5 seconds: timed out
03:33:50 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:33:50 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1439:Connected to Bonsai after 2.0 seconds
03:33:50 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1440:Bonsai started successfully
03:33:50 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1318:Attempting to connect to Slims
03:33:51 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1335:Successfully connected to Slims
03:33:51 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_behavior\Documents\ForagingSettings\WaterCalibrationPar_3.json
03:33:51 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 912:Scanning for newscale stages
03:33:51 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 922:Could not find any instances of NewScale Stage
03:33:51 PM:INFO:Foraging:Foraging.py:_insert_stage_widget:line 279:Inserting Stage Widget
03:33:51 PM:INFO:connection:connection.py:_connect:line 688:Connecting to aibspi(10.128.108.106):2181, use_ssl: False
03:33:51 PM:INFO:client:client.py:_session_callback:line 561:Zookeeper connection established, state: CONNECTED
03:33:51 PM:INFO:connection:connection.py:_connect_attempt:line 655:Closing connection to aibspi:2181
03:33:51 PM:INFO:client:client.py:_session_callback:line 567:Zookeeper session closed, state: CLOSED
03:33:51 PM:INFO:main:main.py:get_stage_widget:line 23:Getting Stage Controller Widget - 1.0.4.dev1+g5cafa8d.b163669
03:33:51 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM3 - device may be being used by another program
03:33:51 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM4 - device may be being used by another program
03:33:51 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 70:Connected to COM6, device id: 1130
03:33:51 PM:INFO:stepper_motor_device:stepper_motor_device.py:load_registers:line 151:Getting available registers on device
03:33:51 PM:WARNING:stepper_motor_device:stepper_motor_device.py:load_registers:line 159:Firmware version 0.5 doesn't match config version 0.7.
    Registers may be defined incorrectly
03:33:51 PM:INFO:stage_model:stage_model.py:configure_device:line 81:Configuring registers with default values (can be modified in config file)
03:33:51 PM:INFO:move_worker:move_worker.py:goto_origin:line 195:(move to origin): Moving stage to origin
03:33:51 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, -27200, -27200, 0]
03:33:55 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [-27200, 0, 0, 0]
03:34:01 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, 0, 0, -27200]
03:34:04 PM:INFO:stage_model:stage_model.py:configure_device:line 87:Zeroed all motor positions
03:34:04 PM:INFO:stage_model:stage_model.py:configure_device:line 88:Finished configuring stepper motor device
#############################################################
03:34:04 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:34:04 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1572:Found existing rig.json: rig_446-7-C_2024-12-18_15_27_23.json
03:34:04 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1008:attempting to close bonsai connection
03:34:06 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1016:bonsai connection closed
03:34:06 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1018:attempting to restart bonsai
03:34:06 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1409:Trying to connect to already running Bonsai
03:34:06 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1456:connecting to GUI and Bonsai through OSC
03:34:06 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1416:Connected to already running Bonsai
03:34:06 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1417:Bonsai started successfully
03:34:06 PM:INFO:Foraging:Foraging.py:__init__:line 243:Start up complete
03:34:08 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) = 12709
03:34:09 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) = 4750
03:34:09 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_behavior/capsule/scratch/saved_curriculums/
03:34:09 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
03:34:10 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_behavior/.aind_auto_train/curriculum_manager/
03:34:10 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/.aind_auto_train/curriculum_manager/
03:34:10 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 0
03:34:10 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=2
03:34:10 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
03:34:43 PM:INFO:move_worker:move_worker.py:move_to_preset_position:line 178:(move to preset position): Moving stage to preset initialize with coordinates [15, 16, 16, 12]
03:34:46 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 0, 0, 0] to [0, 12800, 12800, 0]
03:34:50 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 12800, 12800, 0] to [12000, 12800, 12800, 0]
03:34:52 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 12800, 12800, 0] to [12000, 12800, 12800, 9600]
03:36:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 1472289.410976, '127.0.0.1', 4023]
03:36:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 1472289.415488, '127.0.0.1', 4023]
03:36:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 1472293.824992, '127.0.0.1', 4023]
03:36:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 1472293.82848, '127.0.0.1', 4023]
03:36:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 1472294.518976, '127.0.0.1', 4023]
03:36:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 1472294.522496, '127.0.0.1', 4023]
03:36:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 1472298.590976, '127.0.0.1', 4023]
03:36:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 1472298.593504, '127.0.0.1', 4023]
03:39:39 PM:INFO:Dialogs:Dialogs.py:_start_preview:line 1213:Camera is on
03:45:32 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3675:Stopping current trials
03:45:44 PM:INFO:Foraging:Foraging.py:_Open:line 3017:Quick load success: C:\behavior_data\446-7-C\762206\behavior_762206_2024-12-29_14-04-38\behavior\762206_2024-12-29_14-04-38.json
03:45:44 PM:INFO:Foraging:Foraging.py:_NewSession:line 3585:New Session pressed
03:45:44 PM:INFO:Foraging:Foraging.py:_NewSession:line 3617:Resetting session run flag
03:45:44 PM:INFO:Foraging:Foraging.py:_NewSession:line 3655:New Session complete
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayMin, 0.0 -> 1.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayBeta, 1.0 -> 0.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.044
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue, 0.03 -> 0.019
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue_volume, 3.0 -> 2.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ID, 0.0 -> 762206.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayMin, 0.0 -> 1.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: DelayBeta, 1.0 -> 0.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.03 -> 0.044
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue, 0.03 -> 0.019
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: LeftValue_volume, 3.0 -> 2.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterL, 0.03 -> 0.019
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR, 0.03 -> 0.044
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterL_volume, 3.0 -> 2.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y1, 0.0 -> 16.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_z, 0.0 -> 12.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y2, 0.0 -> 16.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:45:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:45:45 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:45:45 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 16.5912, 1: 25.6975, 2: 25.6975, 3: 18.3975}
03:45:45 PM:INFO:Foraging:Foraging.py:_check_drop_frames:line 714:
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1901:processing parameter changes
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockMax, 60.0 -> 35.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIMax, 8.0 -> 30.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIBeta, 2.0 -> 3.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Ignored, 100.0 -> 7.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockBeta, 20.0 -> 10.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: MaxTime, 120.0 -> 75.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Multiplier, 0.8 -> 0.5
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue_volume, 3.0 -> 2.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.044 -> 0.029
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Unrewarded, 200.0 -> 7.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: warm_min_trial, 60.0 -> 50.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockMax, 60.0 -> 35.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIMax, 8.0 -> 30.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: ITIBeta, 2.0 -> 3.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Ignored, 100.0 -> 7.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BlockBeta, 20.0 -> 10.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: MaxTime, 120.0 -> 75.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Multiplier, 0.8 -> 0.5
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue_volume, 3.0 -> 2.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: RightValue, 0.044 -> 0.029
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: Unrewarded, 200.0 -> 7.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: warm_min_trial, 60.0 -> 50.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR, 0.044 -> 0.029
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: GiveWaterR_volume, 3.0 -> 2.0
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y1, 16.0 -> 25.6975
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_z, 12.0 -> 18.3975
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_y2, 16.0 -> 25.6975
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_x, 15.0 -> 16.5912
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: lineEdit_step_size, 1.0 -> 0.1
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: SuggestedWater,  -> 0.582
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: BaseWeight,  -> 24.97
03:45:45 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1960:Changing parameter: TargetWeight,  -> 21.224
03:45:45 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2844:AutoTrain disengaged!
03:45:45 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'.
03:45:45 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=0
03:45:45 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'}
03:45:45 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'.
03:45:45 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: STAGE_FINAL @Uncoupled Baiting ([email protected])
03:45:45 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: STAGE_FINAL @Uncoupled Baiting ([email protected])
03:45:45 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'}
03:45:45 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'.
03:45:45 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2793:AutoTrain engaged! STAGE_FINAL @ Uncoupled Baiting ([email protected])
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "training_stage" not found. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2916:Task is set to Uncoupled Baiting
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_url" not found. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "task_schema_version" not found. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2924: Widget "description" not found. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BaseRewardSum" has been disabled by the GUI. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "RewardFamily" has been disabled by the GUI. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "RewardPairsN" has been disabled by the GUI. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:UncoupledReward is set to 0.1, 0.4, 0.7
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:Randomness is set to Exponential
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMin is set to 20
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:BlockMax is set to 35
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BlockBeta" has been disabled by the GUI. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2936: Widget "BlockMinReward" has been disabled by the GUI. skipped...
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayMin is set to 1.0
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayMax is set to 1.0
03:45:45 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2971:DelayBeta is set to 0.0
_____SKIPPING_____
03:55:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473432.072224, 4, '127.0.0.1']
03:55:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473432.189984, '127.0.0.1', 4023]
03:55:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473432.188992, '127.0.0.1', 4022]
03:55:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:55:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473432.365728, '127.0.0.1', 4023]
03:55:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473432.528, '127.0.0.1', 4023]
03:55:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473435.201984, '127.0.0.1', 4022]
03:55:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473435.20448, '127.0.0.1', 4022]
03:55:20 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:55:20 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:55:20 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 53
03:55:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473435.222976, '127.0.0.1', 4022]
03:55:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473435.225504, '127.0.0.1', 4022]
03:55:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473437.434976, '127.0.0.1', 4022]
03:55:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473437.437504, '127.0.0.1', 4022]
03:55:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473438.418976, '127.0.0.1', 4022]
03:55:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473438.421536, '127.0.0.1', 4022]
03:55:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473438.422272, 4, '127.0.0.1']
03:55:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473438.51488, '127.0.0.1', 4023]
03:55:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473438.513984, '127.0.0.1', 4022]
03:55:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:55:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473438.679168, '127.0.0.1', 4023]
03:55:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473441.517984, '127.0.0.1', 4022]
03:55:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473441.521504, '127.0.0.1', 4022]
03:55:26 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:55:26 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:55:26 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 54
03:55:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473441.537984, '127.0.0.1', 4022]
03:55:26 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473441.54048, '127.0.0.1', 4022]
03:55:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473442.84432, '127.0.0.1', 4023]
03:55:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473442.868, '127.0.0.1', 4023]
03:55:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473443.006432, '127.0.0.1', 4023]
03:55:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473446.068, '127.0.0.1', 4022]
03:55:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473446.071488, '127.0.0.1', 4022]
03:55:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473447.050976, '127.0.0.1', 4022]
03:55:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473447.054496, '127.0.0.1', 4022]
03:55:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473447.055328, 4, '127.0.0.1']
03:55:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473447.160384, '127.0.0.1', 4023]
03:55:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473447.16, '127.0.0.1', 4022]
03:55:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:55:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473447.31088, '127.0.0.1', 4023]
03:55:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473447.51328, '127.0.0.1', 4023]
03:55:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473450.168, '127.0.0.1', 4022]
03:55:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473450.171488, '127.0.0.1', 4022]
03:55:35 PM:INFO:uncoupled_block:uncoupled_block.py:auto_shape_perseverance:line 137:persev at side = R, added 4 trials to both sides
03:55:35 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:persev at side = R, added 4 trials to both sides
03:55:35 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:55:35 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 55
03:55:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473450.192, '127.0.0.1', 4022]
03:55:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473450.194496, '127.0.0.1', 4022]
03:55:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473450.95856, '127.0.0.1', 4023]
03:55:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473451.115264, '127.0.0.1', 4023]
03:55:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473462.300992, '127.0.0.1', 4022]
03:55:47 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473462.30448, '127.0.0.1', 4022]
03:55:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473463.284, '127.0.0.1', 4022]
03:55:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473463.28848, '127.0.0.1', 4022]
03:55:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473463.288128, 4, '127.0.0.1']
03:55:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473463.410272, '127.0.0.1', 4023]
03:55:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473463.409984, '127.0.0.1', 4022]
03:55:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:55:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473463.551616, '127.0.0.1', 4023]
03:55:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473466.417984, '127.0.0.1', 4022]
03:55:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473466.421504, '127.0.0.1', 4022]
03:55:51 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:55:51 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:55:51 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 56
03:55:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473466.438976, '127.0.0.1', 4022]
03:55:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473466.441504, '127.0.0.1', 4022]
03:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473468.501984, '127.0.0.1', 4022]
03:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473468.50448, '127.0.0.1', 4022]
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473469.484992, '127.0.0.1', 4022]
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473469.489184, 4, '127.0.0.1']
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473469.48848, '127.0.0.1', 4022]
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473469.59424, '127.0.0.1', 4023]
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473469.593984, '127.0.0.1', 4022]
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473469.751456, '127.0.0.1', 4023]
03:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473469.909248, '127.0.0.1', 4023]
03:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473472.600992, '127.0.0.1', 4022]
03:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473472.60448, '127.0.0.1', 4022]
03:55:57 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:55:57 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:55:57 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 57
03:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473472.620992, '127.0.0.1', 4022]
03:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473472.62448, '127.0.0.1', 4022]
03:55:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473473.933376, '127.0.0.1', 4023]
03:56:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473477.600992, '127.0.0.1', 4022]
03:56:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473477.60448, '127.0.0.1', 4022]
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473478.585984, '127.0.0.1', 4022]
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473478.589504, '127.0.0.1', 4022]
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473478.589248, 4, '127.0.0.1']
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473478.703872, '127.0.0.1', 4023]
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473478.702976, '127.0.0.1', 4022]
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473478.85552, '127.0.0.1', 4023]
03:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473479.063264, '127.0.0.1', 4023]
03:56:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473479.794784, '127.0.0.1', 4023]
03:56:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473479.996288, '127.0.0.1', 4023]
03:56:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473481.717984, '127.0.0.1', 4022]
03:56:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473481.721504, '127.0.0.1', 4022]
03:56:06 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:56:06 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:06 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 58
03:56:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473481.737984, '127.0.0.1', 4022]
03:56:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473481.741504, '127.0.0.1', 4022]
03:56:06 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473483.718976, '127.0.0.1', 4022]
03:56:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473483.721504, '127.0.0.1', 4022]
03:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473484.701984, '127.0.0.1', 4022]
03:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473484.70528, 4, '127.0.0.1']
03:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473484.705504, '127.0.0.1', 4022]
03:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473484.841184, '127.0.0.1', 4023]
03:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473484.840992, '127.0.0.1', 4022]
03:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:56:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473485.16848, '127.0.0.1', 4023]
03:56:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473485.450048, '127.0.0.1', 4023]
03:56:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473485.61328, '127.0.0.1', 4023]
03:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473487.850976, '127.0.0.1', 4022]
03:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473487.854496, '127.0.0.1', 4022]
03:56:12 PM:INFO:uncoupled_block:uncoupled_block.py:auto_shape_perseverance:line 137:persev at side = R, added 4 trials to both sides
03:56:12 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:persev at side = R, added 4 trials to both sides
03:56:12 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:12 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 59
03:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473487.873984, '127.0.0.1', 4022]
03:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473487.877504, '127.0.0.1', 4022]
03:56:12 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473491.501984, '127.0.0.1', 4022]
03:56:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473491.50448, '127.0.0.1', 4022]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473492.484992, '127.0.0.1', 4022]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473492.48848, '127.0.0.1', 4022]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473492.489344, 4, '127.0.0.1']
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473492.60928, '127.0.0.1', 4023]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473492.608992, '127.0.0.1', 4022]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 1473492.608992, '127.0.0.1', 4023]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4022]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 1473492.608992, '127.0.0.1', 4023]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 1473492.61248, '127.0.0.1', 4023]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473492.759456, '127.0.0.1', 4023]
03:56:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473492.985504, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473493.480256, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473493.742976, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473493.879328, '127.0.0.1', 4023]
03:56:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473494.014816, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473494.185728, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473494.316576, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473494.46768, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473494.643712, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473494.823328, '127.0.0.1', 4023]
03:56:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473495.015968, '127.0.0.1', 4023]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473495.20688, '127.0.0.1', 4023]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473495.394592, '127.0.0.1', 4023]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473495.610176, '127.0.0.1', 4023]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473495.618976, '127.0.0.1', 4022]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473495.621504, '127.0.0.1', 4022]
03:56:20 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:56:20 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:20 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 60
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473495.641984, '127.0.0.1', 4022]
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473495.64448, '127.0.0.1', 4022]
03:56:20 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473495.832096, '127.0.0.1', 4023]
03:56:20 PM:INFO:bias_indicator:bias_indicator.py:calculate_bias:line 158:Bias: 0.5333507507597798 Trial Count: 59
03:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473495.988512, '127.0.0.1', 4023]
03:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473499.268992, '127.0.0.1', 4022]
03:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473499.271488, '127.0.0.1', 4022]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 1473500.252, '127.0.0.1', 4022]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 1473500.255424, 4, '127.0.0.1']
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473500.255488, '127.0.0.1', 4022]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473500.322912, '127.0.0.1', 4023]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 1473500.321984, '127.0.0.1', 4022]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4022]
03:56:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473500.507488, '127.0.0.1', 4023]
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 1473503.336, '127.0.0.1', 4022]
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473503.338496, '127.0.0.1', 4022]
03:56:28 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:56:28 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1194:
03:56:28 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4246:Current trial: 61
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 1473503.353984, '127.0.0.1', 4022]
03:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 1473503.35648, '127.0.0.1', 4022]
03:56:28 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\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])

03:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473506.73824, '127.0.0.1', 4023]
03:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473506.886944, '127.0.0.1', 4023]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 1473510.901984, '127.0.0.1', 4022]
03:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 1473510.90448, '127.0.0.1', 4022]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 1473511.444576, '127.0.0.1', 4023]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473511.600352, '127.0.0.1', 4023]
03:56:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1473511.79616, '127.0.0.1', 4023]
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 7.95%.
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 3.99%.
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 5.38%.
03:56:41 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 11.63%.
03:56:41 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box 3C mouse 762206 exceeded 10%

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

No branches or pull requests
1 participant
@alexpiet