This issue was automatically generated from GUI logs.
file: MyFunctions.py function: calculate_inter_lick_intervals line 957 logfile: W10DT713669/W10DT713669-A_gui_log_2024-11-13_13-36-33.txt boxes: ephys1 count: 2 text: Percentage of cross side lick intervals under 100 ms in Box A mouse 746896 exceeded 10% GUI Log snippet (click for full log)
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 4038.864992, '127.0.0.1', 4002]
01:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4038.867488, '127.0.0.1', 4002]
01:56:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 4039.848992, '127.0.0.1', 4002]
01:56:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 4039.851136, 4, '127.0.0.1']
01:56:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4039.850496, '127.0.0.1', 4002]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4039.991968, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 4039.990976, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 4039.992, '127.0.0.1', 4002]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 4039.990976, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4002]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 4039.993504, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4040.097856, '127.0.0.1', 4003]
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 4.07%.
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 2.60%.
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 3.49%.
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 19.27%.
01:56:35 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box A mouse 746896 exceeded 10%
Full GUI log (first 200 and last 200 lines)
01:36:33 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4679:Starting logfile!
01:36:33 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)]
01:36:33 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4707:Current git commit branch, hash: main, 60f8beb5cf259b096e71331217b2a631d1eaeb43
01:36:33 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4711:Current foraging_gui version: 1.6.9
01:36:33 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4721:local repository is clean
01:36:33 PM:INFO:Foraging:Foraging.py:<module>:line 4822:Setting QApplication attributes
01:36:33 PM:INFO:Foraging:Foraging.py:<module>:line 4830:Starting QApplication and Window
01:36:33 PM:INFO:Foraging:Foraging.py:__init__:line 69:Creating Window
01:36:33 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1166:Loaded settings_box file
01:36:33 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1194:Loaded settings file
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (FIP_workflow_path), using default:
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (FIP_settings), using default: C:\Users\svc_aind_ephys\Documents\FIPSettings
01:36:33 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
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\metadata_dialog\
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_ephys\Documents\ForagingSettings\rig_metadata\
01:36:33 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
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box1), using default: 60
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box2), using default: 60
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box3), using default: 60
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (go_cue_decibel_box4), using default: 60
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box1), using default: 5000
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box2), using default: 5000
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box3), using default: 5000
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (lick_spout_distance_box4), using default: 5000
01:36:33 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
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (save_each_trial), using default: True
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (AutomaticUpload), using default: True
01:36:33 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
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (auto_engage), using default: True
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (clear_figure_after_save), using default: True
01:36:33 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1204:Missing setting (add_default_project_name), using default: True
01:36:33 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1092:Loaded behavior schedule
01:36:33 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
01:36:33 PM:INFO:Foraging:Foraging.py:_LoadRigJson:line 1536:Skipping rig metadata creation because create_rig_metadata=False
01:36:34 PM:INFO:Foraging:Foraging.py:_LoadUI:line 275:Using ForagingGUI.ui interface
01:36:34 PM:INFO:Foraging:Foraging.py:__init__:line 119:Setting Window title: 323_EPHYS1
01:36:34 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1363:Trying to connect to already running Bonsai
01:36:34 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
01:36:35 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1367:Could not connect: timed out
01:36:35 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1376:Starting Bonsai
01:36:35 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4794:BONSAI logging starting
01:36:35 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
01:36:36 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 0.5 seconds: timed out
01:36:37 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
01:36:38 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 1.0 seconds: timed out
01:36:38 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
01:36:39 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1390:Could not connect, total waiting time 1.5 seconds: timed out
01:36:40 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1410:connecting to GUI and Bonsai through OSC
01:36:40 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1393:Connected to Bonsai after 2.0 seconds
01:36:40 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1394:Bonsai started successfully
01:36:40 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1273:Attempting to connect to Slims
01:36:52 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1290:Successfully connected to Slims
01:36:52 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 507:could not find water calibration parameters: C:\Users\svc_aind_ephys\Documents\ForagingSettings\WaterCalibrationPar_1.json
01:36:52 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:36:52 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 867:Scanning for newscale stages
01:36:53 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 882:found 3 newscale stages
01:36:53 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 906:Found the newscale stage from the settings file
01:36:53 PM:INFO:Foraging:Foraging.py:_connect_stage:line 933:Successfully connected to newscale stage: 46809
01:36:53 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 753:Checking stage connection
01:36:53 PM:INFO:Foraging:Foraging.py:_GetPositions:line 765:Grabbing current stage position
01:36:53 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1526:Found existing rig.json: rig_323_EPHYS1_2024-06-17.json
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.03 -> 0.036
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.03 -> 0.04
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.03 -> 0.036
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.03 -> 0.04
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterL, 0.03 -> 0.04
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: GiveWaterR, 0.03 -> 0.036
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionZ, -> 7127.5
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionY, -> 5.0
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionX, -> 6946.5
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:36:53 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:36:53 PM:INFO:Foraging:Foraging.py:__init__:line 219:Start up complete
01:36:55 PM:INFO:aws_util:aws_util.py:import_df_from_s3:line 115:Dataframe imported from s3://aind-behavior-data/foraging_nwb_bonsai_processed/df_sessions.pkl, len(df) = 5368
01:36:55 PM:INFO:aws_util:aws_util.py:import_df_from_s3:line 115:Dataframe imported from s3://aind-behavior-data/foraging_auto_training/df_manager_447_demo.pkl, len(df) = 3936
01:36:56 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
01:36:56 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 29 curriculums in C:\Users\svc_aind_ephys/capsule/scratch/saved_curriculums/
01:36:56 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_ephys/.aind_auto_train/curriculum_manager/
01:36:56 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 29 curriculums in C:\Users\svc_aind_ephys/.aind_auto_train/curriculum_manager/
01:36:56 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2386:No entry found in df_training_manager for subject_id: 0
01:36:56 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2734:Override stage clicked: state=2
01:36:56 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2760:Current stage to apply: unknown training stage @unknown curriculum
01:37:02 PM:INFO:Dialogs:Dialogs.py:_start_preview:line 1326:Camera is on
01:45:27 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3599:Stopping current trials
01:45:36 PM:INFO:Foraging:Foraging.py:_Open:line 2954:User entered the ID for a mouse with no data: 746896
01:45:38 PM:INFO:Foraging:Foraging.py:_OpenNewMouse:line 2906:User starting a new mouse: 746896
01:45:38 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2938:AutoTrain disengaged!
01:45:38 PM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
01:45:38 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2734:Override stage clicked: state=0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2680:Selected curriculum: {'curriculum_name': 'Uncoupled Baiting', 'curriculum_version': '2.3', 'curriculum_schema_version': '1.0', 'curriculum_description': '2024-08-16 max_len = 75 mins; decrease finished trial criterion'}
01:45:38 PM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
01:45:38 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2760:Current stage to apply: GRADUATED @Uncoupled Baiting (v2.3@1.0)
01:45:38 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2760:Current stage to apply: GRADUATED @Uncoupled Baiting (v2.3@1.0)
01:45:38 PM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2680:Selected curriculum: {'curriculum_name': 'Uncoupled Baiting', 'curriculum_version': '2.3', 'curriculum_schema_version': '1.0', 'curriculum_description': '2024-08-16 max_len = 75 mins; decrease finished trial criterion'}
01:45:38 PM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Baiting_curriculum_v2.3_schema_v1.0.json'.
01:45:38 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2887:AutoTrain engaged! GRADUATED @ Uncoupled Baiting (v2.3@1.0)
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3018: Widget "training_stage" not found. skipped...
01:45:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:45:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ID, 0.0 -> 746896.0
01:45:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3010:Task is set to Uncoupled Baiting
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3018: Widget "task_url" not found. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3018: Widget "task_schema_version" not found. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3018: Widget "description" not found. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "BaseRewardSum" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "RewardFamily" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "RewardPairsN" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:UncoupledReward is set to 0.1, 0.4, 0.7
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:Randomness is set to Exponential
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:BlockMin is set to 20
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:BlockMax is set to 35
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "BlockBeta" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "BlockMinReward" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:DelayMin is set to 1.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:DelayMax is set to 1.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:DelayBeta is set to 0.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:RewardDelay is set to 0.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:AutoReward is set to False
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:AutoWaterType is set to Natural
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:Multiplier is set to 0.5
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:Unrewarded is set to 10
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:Ignored is set to 10
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:ITIMin is set to 1.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:ITIMax is set to 30.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:ITIBeta is set to 3.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "ITIIncrease" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:ResponseTime is set to 1.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:RewardConsumeTime is set to 3.0
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:StopIgnores is set to 25
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "AdvancedBlockAuto" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "SwitchThr" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "PointsInARow" has been disabled by the GUI. skipped...
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:MaxTrial is set to 1000
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:MaxTime is set to 75
01:45:38 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:RightValue_volume is set to 2.0
01:45:39 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:LeftValue_volume is set to 2.0
01:45:39 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "warm_min_trial" has been disabled by the GUI. skipped...
01:45:39 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "warm_max_choice_ratio_bias" has been disabled by the GUI. skipped...
01:45:39 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "warm_min_finish_ratio" has been disabled by the GUI. skipped...
01:45:39 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3030: Widget "warm_windowsize" has been disabled by the GUI. skipped...
01:45:39 PM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 3065:warmup is set to off
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayMin, 0.0 -> 1.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayBeta, 1.0 -> 0.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: BlockMax, 60.0 -> 35.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIMax, 8.0 -> 30.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIBeta, 2.0 -> 3.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Ignored, 100.0 -> 10.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: StopIgnores, 20.0 -> 25.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: MaxTime, 120.0 -> 75.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Multiplier, 0.8 -> 0.5
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue_volume, 3.0 -> 2.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.036 -> 0.024
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.04 -> 0.028
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Unrewarded, 200.0 -> 10.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue_volume, 3.0 -> 2.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayMin, 0.0 -> 1.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: DelayBeta, 1.0 -> 0.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: BlockMax, 60.0 -> 35.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIMax, 8.0 -> 30.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: ITIBeta, 2.0 -> 3.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Ignored, 100.0 -> 10.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: StopIgnores, 20.0 -> 25.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: MaxTime, 120.0 -> 75.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Multiplier, 0.8 -> 0.5
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue_volume, 3.0 -> 2.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: RightValue, 0.036 -> 0.024
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue, 0.04 -> 0.028
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: Unrewarded, 200.0 -> 10.0
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: LeftValue_volume, 3.0 -> 2.0
01:45:39 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2515:Auto engage successful for mouse 746896
01:45:39 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:45:39 PM:INFO:Foraging:Foraging.py:_NewSession:line 3509:New Session pressed
01:45:39 PM:INFO:Foraging:Foraging.py:_NewSession:line 3541:Resetting session run flag
01:45:39 PM:INFO:Foraging:Foraging.py:_NewSession:line 3579:New Session complete
01:45:49 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:45:49 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionY, 5.0 -> 10000.0
01:46:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:46:08 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionY, 10000.0 -> 11000.0
01:46:12 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1881:processing parameter changes
01:46:12 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1940:Changing parameter: PositionY, 11000.0 -> 12000.0
01:46:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3423.6792, '127.0.0.1', 4003]
01:46:18 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3423.84912, '127.0.0.1', 4003]
01:46:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3424.051872, '127.0.0.1', 4003]
01:46:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3424.238784, '127.0.0.1', 4003]
01:46:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3424.423232, '127.0.0.1', 4003]
01:46:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 3424.808064, '127.0.0.1', 4003]
01:46:20 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 753:Checking stage connection
01:46:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3425.038912, '127.0.0.1', 4003]
01:46:20 PM:INFO:Foraging:Foraging.py:_Move:line 791:Moving stage
01:46:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3425.192672, '127.0.0.1', 4003]
01:46:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 3425.388928, '127.0.0.1', 4003]
01:46:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 3425.561376, '127.0.0.1', 4003]
01:46:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3425.723936, '127.0.0.1', 4003]
01:46:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 3426.357344, '127.0.0.1', 4003]
01:46:23 PM:INFO:Foraging:Foraging.py:_CheckStageConnection:line 753:Checking stage connection
_____SKIPPING_____
01:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 3998.002208, '127.0.0.1', 4003]
01:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3998.124768, '127.0.0.1', 4003]
01:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3998.301792, '127.0.0.1', 4003]
01:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3998.467872, '127.0.0.1', 4003]
01:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3998.619072, '127.0.0.1', 4003]
01:55:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3998.793696, '127.0.0.1', 4003]
01:55:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 3998.943872, '127.0.0.1', 4003]
01:55:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 4000.848, '127.0.0.1', 4002]
01:55:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4000.849504, '127.0.0.1', 4002]
01:55:56 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
01:55:56 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
01:55:56 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 41
01:55:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 4000.924992, '127.0.0.1', 4002]
01:55:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 4000.92848, '127.0.0.1', 4002]
01:55:56 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
01:55:56 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\dynamic-foraging\323_EPHYS1\746896\behavior_746896_2024-11-13_13-46-35
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:55:56 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 4002.164992, '127.0.0.1', 4002]
01:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4002.166496, '127.0.0.1', 4002]
01:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4002.279008, '127.0.0.1', 4003]
01:55:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4002.450592, '127.0.0.1', 4003]
01:55:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4002.927616, '127.0.0.1', 4003]
01:55:58 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4003.147424, '127.0.0.1', 4003]
01:55:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 4004.381984, '127.0.0.1', 4002]
01:55:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4004.383488, '127.0.0.1', 4002]
01:56:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 4005.364992, '127.0.0.1', 4002]
01:56:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4005.366496, '127.0.0.1', 4002]
01:56:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 4005.3672, 4, '127.0.0.1']
01:56:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4005.630368, '127.0.0.1', 4003]
01:56:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 4005.629984, '127.0.0.1', 4002]
01:56:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
01:56:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4005.797408, '127.0.0.1', 4003]
01:56:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4005.980256, '127.0.0.1', 4003]
01:56:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4006.114912, '127.0.0.1', 4003]
01:56:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4006.290016, '127.0.0.1', 4003]
01:56:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4006.455392, '127.0.0.1', 4003]
01:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 4008.630976, '127.0.0.1', 4002]
01:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4008.633504, '127.0.0.1', 4002]
01:56:03 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
01:56:03 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
01:56:03 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 42
01:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 4008.704, '127.0.0.1', 4002]
01:56:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 4008.70848, '127.0.0.1', 4002]
01:56:03 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
01:56:03 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\dynamic-foraging\323_EPHYS1\746896\behavior_746896_2024-11-13_13-46-35
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:56:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:04 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:04 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:04 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:04 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4009.563264, '127.0.0.1', 4003]
01:56:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4011.812864, '127.0.0.1', 4003]
01:56:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4011.993728, '127.0.0.1', 4003]
01:56:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 4013.280992, '127.0.0.1', 4002]
01:56:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4013.283488, '127.0.0.1', 4002]
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 4014.264992, '127.0.0.1', 4002]
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4014.266496, '127.0.0.1', 4002]
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 4014.267424, 4, '127.0.0.1']
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4014.509952, '127.0.0.1', 4003]
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 4014.514976, '127.0.0.1', 4002]
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4014.664, '127.0.0.1', 4003]
01:56:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4014.8104, '127.0.0.1', 4003]
01:56:10 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4014.949248, '127.0.0.1', 4003]
01:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 4017.532, '127.0.0.1', 4002]
01:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4017.533504, '127.0.0.1', 4002]
01:56:12 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
01:56:12 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
01:56:12 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 43
01:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 4017.605984, '127.0.0.1', 4002]
01:56:12 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 4017.609504, '127.0.0.1', 4002]
01:56:12 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
01:56:12 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\dynamic-foraging\323_EPHYS1\746896\behavior_746896_2024-11-13_13-46-35
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:12 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 4025.098976, '127.0.0.1', 4002]
01:56:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4025.10048, '127.0.0.1', 4002]
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 4026.081984, '127.0.0.1', 4002]
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 4026.084288, 4, '127.0.0.1']
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4026.083488, '127.0.0.1', 4002]
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4026.191072, '127.0.0.1', 4003]
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 4026.192, '127.0.0.1', 4002]
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4002]
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4026.317952, '127.0.0.1', 4003]
01:56:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4026.513664, '127.0.0.1', 4003]
01:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 4029.198976, '127.0.0.1', 4002]
01:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4029.20048, '127.0.0.1', 4002]
01:56:24 PM:INFO:uncoupled_block:uncoupled_block.py:auto_shape_perseverance:line 137:persev at side = L, added 4 trials to both sides
01:56:24 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:persev at side = L, added 4 trials to both sides
01:56:24 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
01:56:24 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 44
01:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 4029.272, '127.0.0.1', 4002]
01:56:24 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 4029.27648, '127.0.0.1', 4002]
01:56:24 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
01:56:24 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\dynamic-foraging\323_EPHYS1\746896\behavior_746896_2024-11-13_13-46-35
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:24 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 4033.332, '127.0.0.1', 4002]
01:56:28 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4033.333504, '127.0.0.1', 4002]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 4034.314976, '127.0.0.1', 4002]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 4034.318208, 4, '127.0.0.1']
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4034.317504, '127.0.0.1', 4002]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4034.485376, '127.0.0.1', 4003]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 4034.484992, '127.0.0.1', 4003]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 4034.484992, '127.0.0.1', 4003]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 4034.485984, '127.0.0.1', 4002]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4002]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 4034.487488, '127.0.0.1', 4003]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4034.570048, '127.0.0.1', 4003]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4034.746304, '127.0.0.1', 4003]
01:56:29 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4034.891424, '127.0.0.1', 4003]
01:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4035.026848, '127.0.0.1', 4003]
01:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4035.183872, '127.0.0.1', 4003]
01:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4035.322784, '127.0.0.1', 4003]
01:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4035.477856, '127.0.0.1', 4003]
01:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4035.75056, '127.0.0.1', 4003]
01:56:30 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4035.90032, '127.0.0.1', 4003]
01:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4036.068992, '127.0.0.1', 4003]
01:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4036.227872, '127.0.0.1', 4003]
01:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4036.364896, '127.0.0.1', 4003]
01:56:31 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4036.520864, '127.0.0.1', 4003]
01:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4036.97472, '127.0.0.1', 4003]
01:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4037.12864, '127.0.0.1', 4003]
01:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 4037.498976, '127.0.0.1', 4002]
01:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4037.50048, '127.0.0.1', 4002]
01:56:32 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
01:56:32 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
01:56:32 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4159:Current trial: 45
01:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 4037.576992, '127.0.0.1', 4002]
01:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 4037.581504, '127.0.0.1', 4002]
01:56:32 PM:INFO:Foraging:Foraging.py:_Save:line 2459:Saving current session, ForceSave=1
01:56:32 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1056:Loaded Water Calibration
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:D:\dynamic-foraging\323_EPHYS1\746896\behavior_746896_2024-11-13_13-46-35
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
01:56:32 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 4037.772032, '127.0.0.1', 4003]
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 584:No photometry data stream detected!
01:56:32 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
01:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 4038.864992, '127.0.0.1', 4002]
01:56:33 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4038.867488, '127.0.0.1', 4002]
01:56:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 4039.848992, '127.0.0.1', 4002]
01:56:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 4039.851136, 4, '127.0.0.1']
01:56:34 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 4039.850496, '127.0.0.1', 4002]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4039.991968, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 4039.990976, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 4039.992, '127.0.0.1', 4002]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 4039.990976, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4002]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 4039.993504, '127.0.0.1', 4003]
01:56:35 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 4040.097856, '127.0.0.1', 4003]
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 4.07%.
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 2.60%.
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 3.49%.
01:56:35 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 951:Percentage of cross side lick intervals under 100 ms is 19.27%.
01:56:35 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 957:Percentage of cross side lick intervals under 100 ms in Box A mouse 746896 exceeded 10%
This issue was automatically generated from GUI logs.
file: MyFunctions.py
function: calculate_inter_lick_intervals
line 957
logfile: W10DT713669/W10DT713669-A_gui_log_2024-11-13_13-36-33.txt
boxes: ephys1
count: 2
text: Percentage of cross side lick intervals under 100 ms in Box A mouse 746896 exceeded 10%
GUI Log snippet (click for full log)
Full GUI log (first 200 and last 200 lines)