AllenNeuralDynamics / dynamic-foraging-task

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

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

Open alexpiet opened 1 week ago

alexpiet commented 1 week ago

This issue was automatically generated from GUI logs.

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

GUI Log snippet (click for full log)

03:31:37 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
03:31:37 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\740610\behavior_740610_2024-11-18_15-21-33
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:38 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 17.25%.
03:31:38 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 12.01%.
03:31:38 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 15.04%.
03:31:38 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box A mouse 740610 exceeded 10%

Full GUI log (first 200 and last 200 lines)

12:05:59 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4679:Starting logfile!
12:05:59 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4690:Python version: 3.11.9 | packaged by Anaconda, Inc. | (main, Apr 19 2024, 16:40:41) [MSC v.1916 64 bit (AMD64)]
12:05:59 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4707:Current git commit branch, hash: main, 60f8beb5cf259b096e71331217b2a631d1eaeb43
12:05:59 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4711:Current foraging_gui version: 1.6.9
12:05:59 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4721:local repository is clean
12:05:59 PM:INFO:Foraging:Foraging.py:<module>:line 4822:Setting QApplication attributes
12:05:59 PM:INFO:Foraging:Foraging.py:<module>:line 4830:Starting QApplication and Window
12:05:59 PM:INFO:Foraging:Foraging.py:__init__:line 69:Creating Window
12:05:59 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1166:Loaded settings_box file
12:05:59 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1194:Loaded settings file
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (FIP_workflow_path), using default: 
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (FIP_settings), using default: C:\Users\svc_aind_ephys\Documents\FIPSettings
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (bonsai_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.exe
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (bonsaiworkflow_path), using default: C:\Users\svc_aind_ephys\Documents\GitHub\dynamic-foraging-task\src\workflows\foraging.bonsai
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\metadata_dialog\
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\rig_metadata\
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (project_info_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\Project Name and Funding Source v2.csv
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box2), using default: 60
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box3), using default: 60
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box4), using default: 60
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box1), using default: 5000
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box2), using default: 5000
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box3), using default: 5000
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box4), using default: 5000
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\name_mapper.json
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (save_each_trial), using default: True
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (AutomaticUpload), using default: True
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_ephys\Documents\aind_watchdog_service\manifest
12:05:59 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (add_default_project_name), using default: True
12:05:59 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1092:Loaded behavior schedule
12:05:59 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
12:05:59 PM:INFO:Foraging:Foraging.py:_LoadRigJson:line 1536:Skipping rig metadata creation because create_rig_metadata=False
12:06:00 PM:INFO:Foraging:Foraging.py:_LoadUI:line 281:Using ForagingGUI_Ephys.ui interface
12:06:00 PM:INFO:Foraging:Foraging.py:__init__:line 119:Setting Window title: 323_EPHYS3
12:06:00 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1363:Trying to connect to already running Bonsai
12:06:00 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:06:01 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1367:Could not connect: timed out
12:06:01 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1376:Starting Bonsai
12:06:01 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4794:BONSAI logging starting
12:06:01 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:06:02 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 0.5 seconds: timed out
12:06:03 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:06:04 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 1.0 seconds: timed out
12:06:04 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:06:05 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 1.5 seconds: timed out
12:06:06 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:06:07 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 2.0 seconds: timed out
12:06:07 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
12:06:07 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1393:Connected to Bonsai after 2.5 seconds
12:06:07 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1394:Bonsai started successfully
12:06:07 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1273:Attempting to connect to Slims
12:06:08 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1290:Successfully connected to Slims
12:06:08 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 507:could not find water calibration parameters: C:\Users\svc_aind_ephys\Documents\ForagingSettings\WaterCalibrationPar_1.json
12:06:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:06:08 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 867:Scanning for newscale stages
12:06:08 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 882:found 1 newscale stages
12:06:08 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 906:Found the newscale stage from the settings file
12:06:08 PM:INFO:Foraging:Foraging.py:_connect_stage:line 933:Successfully connected to newscale stage: 46796
12:06:08 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 753:Checking stage connection
12:06:09 PM:INFO:Foraging:Foraging.py:_GetPositions:line 765:Grabbing current stage position
12:06:09 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1526:Found existing rig.json: rig_323_EPHYS3_2024-10-17.json
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.03 -> 0.057
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.03 -> 0.053
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterL, 0.03 -> 0.053
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterR, 0.03 -> 0.057
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.03 -> 0.057
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.03 -> 0.053
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterL, 0.03 -> 0.053
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterR, 0.03 -> 0.057
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionY,  -> 10112.5
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionX,  -> 4691.5
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionZ,  -> 9915.5
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:06:09 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:06:09 PM:WARNING:Foraging:Foraging.py:_show_disk_space:line 235:Low disk space  Used space: 1829.96GB    Free space: 33.05GB
12:06:09 PM:INFO:Foraging:Foraging.py:__init__:line 219:Start up complete
12:06:10 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) = 5495
12:06:11 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) = 4054
12:06:11 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
12:06:11 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
12:06:12 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_ephys/.aind_auto_train/curriculum_manager/
12:06:12 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_ephys/.aind_auto_train/curriculum_manager/
12:06:12 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2386:No entry found in df_training_manager for subject_id: 0
12:06:12 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2734:Override stage clicked: state=2
12:06:12 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2760:Current stage to apply: unknown training stage @unknown curriculum
12:10:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 6979566.526976, '127.0.0.1', 4003]
12:10:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 6979566.531488, '127.0.0.1', 4003]
12:10:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 6979570.748, '127.0.0.1', 4003]
12:10:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 6979570.750496, '127.0.0.1', 4003]
12:10:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 6979571.581984, '127.0.0.1', 4003]
12:10:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 6979571.585504, '127.0.0.1', 4003]
12:10:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 6979578.360992, '127.0.0.1', 4003]
12:10:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 6979578.362496, '127.0.0.1', 4003]
12:12:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979689.980192, '127.0.0.1', 4003]
12:12:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 6979689.980192, '127.0.0.1', 4003], displaying at 0.5 Hz
12:12:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979712.35648, '127.0.0.1', 4003]
12:12:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979712.424352, '127.0.0.1', 4003]
12:12:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979712.974112, '127.0.0.1', 4003]
12:12:40 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6979715.351264, '127.0.0.1', 4003]
12:12:40 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6979715.440416, '127.0.0.1', 4003]
12:12:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979730.817024, '127.0.0.1', 4003]
12:12:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979731.194112, '127.0.0.1', 4003]
12:12:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979731.354464, '127.0.0.1', 4003]
12:12:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979731.543872, '127.0.0.1', 4003]
12:12:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979731.685408, '127.0.0.1', 4003]
12:12:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979731.854112, '127.0.0.1', 4003]
12:12:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979732.208672, '127.0.0.1', 4003]
12:12:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979732.296, '127.0.0.1', 4003]
12:12:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979732.392736, '127.0.0.1', 4003]
12:13:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979735.94544, '127.0.0.1', 4003]
12:13:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979736.175008, '127.0.0.1', 4003]
12:13:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979736.2, '127.0.0.1', 4003]
12:13:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979752.884256, '127.0.0.1', 4003]
12:13:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979752.972992, '127.0.0.1', 4003]
12:13:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979753.220192, '127.0.0.1', 4003]
12:13:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979753.377312, '127.0.0.1', 4003]
12:13:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979772.134112, '127.0.0.1', 4003]
12:13:39 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979774.929152, '127.0.0.1', 4003]
12:13:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979779.083424, '127.0.0.1', 4003]
12:13:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979782.135072, '127.0.0.1', 4003]
12:13:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979789.833088, '127.0.0.1', 4003]
12:13:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979789.920992, '127.0.0.1', 4003]
12:14:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979810.286272, '127.0.0.1', 4003]
12:14:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979810.481664, '127.0.0.1', 4003]
12:14:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979813.353568, '127.0.0.1', 4003]
12:14:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979813.76672, '127.0.0.1', 4003]
12:14:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979814.160704, '127.0.0.1', 4003]
12:14:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979814.248, '127.0.0.1', 4003]
12:14:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979815.35984, '127.0.0.1', 4003]
12:14:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979815.573088, '127.0.0.1', 4003]
12:14:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979831.860032, '127.0.0.1', 4003]
12:14:36 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6979831.860128, '127.0.0.1', 4003]
12:15:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979873.7872, '127.0.0.1', 4003]
12:15:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6979873.787232, '127.0.0.1', 4003]
12:15:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979910.881088, '127.0.0.1', 4003]
12:15:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979910.972, '127.0.0.1', 4003]
12:15:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979911.055584, '127.0.0.1', 4003]
12:15:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979911.746752, '127.0.0.1', 4003]
12:15:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979911.933216, '127.0.0.1', 4003]
12:15:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979912.120704, '127.0.0.1', 4003]
12:15:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979912.308384, '127.0.0.1', 4003]
12:15:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979912.464064, '127.0.0.1', 4003]
12:15:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979912.634624, '127.0.0.1', 4003]
12:15:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979912.78832, '127.0.0.1', 4003]
12:15:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979914.215296, '127.0.0.1', 4003]
12:15:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979914.343648, '127.0.0.1', 4003]
12:16:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979920.333952, '127.0.0.1', 4003]
12:16:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979924.625664, '127.0.0.1', 4003]
12:16:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979924.731744, '127.0.0.1', 4003]
12:16:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979924.806976, '127.0.0.1', 4003]
12:16:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979924.891104, '127.0.0.1', 4003]
12:16:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979925.067424, '127.0.0.1', 4003]
12:16:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979925.247104, '127.0.0.1', 4003]
12:16:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979925.432128, '127.0.0.1', 4003]
12:16:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979926.419008, '127.0.0.1', 4003]
12:16:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979926.64, '127.0.0.1', 4003]
12:16:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979933.430432, '127.0.0.1', 4003]
12:16:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979933.825408, '127.0.0.1', 4003]
12:16:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979933.996608, '127.0.0.1', 4003]
12:16:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979935.041024, '127.0.0.1', 4003]
12:16:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979935.463936, '127.0.0.1', 4003]
12:16:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6979935.664512, '127.0.0.1', 4003]
12:16:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979935.872608, '127.0.0.1', 4003]
12:16:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979936.616928, '127.0.0.1', 4003]
12:16:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979936.728, '127.0.0.1', 4003]
12:16:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979939.731552, '127.0.0.1', 4003]
12:16:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979939.91536, '127.0.0.1', 4003]
12:16:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979940.131968, '127.0.0.1', 4003]
12:16:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979940.30944, '127.0.0.1', 4003]
12:16:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979940.364992, '127.0.0.1', 4003]
12:16:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979940.516096, '127.0.0.1', 4003]
12:16:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979944.689824, '127.0.0.1', 4003]
12:16:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6979946.255936, '127.0.0.1', 4003]
12:16:50 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3599:Stopping current trials
12:16:54 PM:INFO:Foraging:Foraging.py:_Open:line 2966:Quick load success: D:\BehaviorData\323_EPHYS3\744742\behavior_744742_2024-11-01_15-52-11\behavior\744742_2024-11-01_15-52-11.json
12:16:54 PM:INFO:Foraging:Foraging.py:_NewSession:line 3509:New Session pressed
12:16:54 PM:INFO:Foraging:Foraging.py:_NewSession:line 3541:Resetting session run flag
12:16:54 PM:INFO:Foraging:Foraging.py:_NewSession:line 3579:New Session complete
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: BlockMax, 60.0 -> 35.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayBeta, 1.0 -> 0.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayMin, 0.0 -> 1.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIBeta, 2.0 -> 3.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIMax, 8.0 -> 30.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Multiplier, 0.8 -> 0.5
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Unrewarded, 200.0 -> 10.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Ignored, 100.0 -> 10.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: StopIgnores, 20.0 -> 25.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.057 -> 0.037
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.053 -> 0.035
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: MaxTime, 120.0 -> 75.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue_volume, 3.0 -> 2.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue_volume, 3.0 -> 2.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: BlockMax, 60.0 -> 35.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayBeta, 1.0 -> 0.0
12:16:55 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayMin, 0.0 -> 1.0
_____SKIPPING_____
03:31:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6991618.07328, 4, '127.0.0.1']
03:31:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991618.07248, '127.0.0.1', 4002]
03:31:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/OptogeneticsTimeHarp', 6991618.073504, '127.0.0.1', 4003]
03:31:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6991619.064992, '127.0.0.1', 4002]
03:31:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'NoResponse', '127.0.0.1', 4002]
03:31:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991621.510912, '127.0.0.1', 4003]
03:31:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991621.71056, '127.0.0.1', 4003]
03:31:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991621.907008, '127.0.0.1', 4003]
03:31:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6991622.080992, '127.0.0.1', 4002]
03:31:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991622.082496, '127.0.0.1', 4002]
03:31:06 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:31:06 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:31:06 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 81
03:31:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6991622.16, '127.0.0.1', 4002]
03:31:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6991622.163488, '127.0.0.1', 4002]
03:31:07 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
03:31:07 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\740610\behavior_740610_2024-11-18_15-21-33
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:07 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991624.649376, '127.0.0.1', 4003]
03:31:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991625.093632, '127.0.0.1', 4003]
03:31:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991627.551488, '127.0.0.1', 4003]
03:31:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991629.10768, '127.0.0.1', 4003]
03:31:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991630.320256, '127.0.0.1', 4003]
03:31:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991632.028576, '127.0.0.1', 4003]
03:31:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991632.510816, '127.0.0.1', 4003]
03:31:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991632.868448, '127.0.0.1', 4003]
03:31:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991633.001344, '127.0.0.1', 4003]
03:31:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991633.210848, '127.0.0.1', 4003]
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6991633.74, '127.0.0.1', 4002]
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991633.742496, '127.0.0.1', 4002]
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6991633.743296, 4, '127.0.0.1']
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991633.856864, '127.0.0.1', 4003]
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6991633.856, '127.0.0.1', 4002]
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991634.044704, '127.0.0.1', 4003]
03:31:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991634.282112, '127.0.0.1', 4003]
03:31:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991634.4848, '127.0.0.1', 4003]
03:31:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991634.785248, '127.0.0.1', 4003]
03:31:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991634.804, '127.0.0.1', 4003]
03:31:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6991636.864, '127.0.0.1', 4002]
03:31:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991636.866496, '127.0.0.1', 4002]
03:31:21 PM:INFO:uncoupled_block:uncoupled_block.py:auto_shape_perseverance:line 137:persev at side = L, added 4 trials to both sides
03:31:21 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:persev at side = L, added 4 trials to both sides
03:31:21 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:31:21 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 82
03:31:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6991636.941984, '127.0.0.1', 4002]
03:31:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6991636.943488, '127.0.0.1', 4002]
03:31:22 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
03:31:22 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\740610\behavior_740610_2024-11-18_15-21-33
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991638.256288, '127.0.0.1', 4003]
03:31:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991638.515392, '127.0.0.1', 4003]
03:31:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991639.033312, '127.0.0.1', 4003]
03:31:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991639.205824, '127.0.0.1', 4003]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991639.3728, '127.0.0.1', 4003]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991639.651776, '127.0.0.1', 4003]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991639.701984, '127.0.0.1', 4003]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6991640.046976, '127.0.0.1', 4002]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6991640.05328, 4, '127.0.0.1']
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991640.05248, '127.0.0.1', 4002]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991640.186688, '127.0.0.1', 4003]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6991640.185984, '127.0.0.1', 4002]
03:31:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
03:31:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991640.499296, '127.0.0.1', 4003]
03:31:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991640.705632, '127.0.0.1', 4003]
03:31:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991640.9192, '127.0.0.1', 4003]
03:31:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6991643.196992, '127.0.0.1', 4002]
03:31:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991643.20048, '127.0.0.1', 4002]
03:31:27 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:31:27 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:31:27 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 83
03:31:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6991643.276992, '127.0.0.1', 4002]
03:31:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6991643.28048, '127.0.0.1', 4002]
03:31:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991643.7952, '127.0.0.1', 4003]
03:31:28 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
03:31:28 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\740610\behavior_740610_2024-11-18_15-21-33
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:28 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991644.279936, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6991644.618976, '127.0.0.1', 4002]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6991644.623264, 4, '127.0.0.1']
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991644.622496, '127.0.0.1', 4002]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991644.707456, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTime', 6991644.706976, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedLeftWaterStartTime', 6991644.706976, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6991644.706976, '127.0.0.1', 4002]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardLeft', '127.0.0.1', 4002]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 6991644.714496, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991644.896992, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991644.949984, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.044736, '127.0.0.1', 4003]
03:31:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.187936, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.396384, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.434976, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.544096, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.7104, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.752, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991645.870816, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991646.043776, '127.0.0.1', 4003]
03:31:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991646.213472, '127.0.0.1', 4003]
03:31:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991646.401056, '127.0.0.1', 4003]
03:31:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6991647.713984, '127.0.0.1', 4002]
03:31:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991647.71648, '127.0.0.1', 4002]
03:31:32 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:31:32 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:31:32 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 84
03:31:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6991647.802976, '127.0.0.1', 4002]
03:31:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6991647.805504, '127.0.0.1', 4002]
03:31:33 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
03:31:33 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\740610\behavior_740610_2024-11-18_15-21-33
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:33 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 6991649.326976, '127.0.0.1', 4002]
03:31:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 6991649.331264, 4, '127.0.0.1']
03:31:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991649.330496, '127.0.0.1', 4002]
03:31:34 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:34 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991649.440576, '127.0.0.1', 4003]
03:31:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 6991649.44, '127.0.0.1', 4002]
03:31:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
03:31:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991649.606784, '127.0.0.1', 4003]
03:31:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991649.833536, '127.0.0.1', 4003]
03:31:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 6991650.028448, '127.0.0.1', 4003]
03:31:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991650.91808, '127.0.0.1', 4003]
03:31:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 6991651.07552, '127.0.0.1', 4003]
03:31:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 6991652.446976, '127.0.0.1', 4002]
03:31:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 6991652.450496, '127.0.0.1', 4002]
03:31:37 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
03:31:37 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:31:37 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 85
03:31:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 6991652.525984, '127.0.0.1', 4002]
03:31:37 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 6991652.529504, '127.0.0.1', 4002]
03:31:37 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
03:31:37 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\BehaviorData\323_EPHYS3\740610\behavior_740610_2024-11-18_15-21-33
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_FindLatestCalibrationDate:line 1129:No dates found in the LaserCalibrationResults.
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
03:31:37 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
03:31:38 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 17.25%.
03:31:38 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 12.01%.
03:31:38 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 15.04%.
03:31:38 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box A mouse 740610 exceeded 10%