You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
This issue was automatically generated from GUI logs.
file: MyFunctions.py function: calculate_inter_lick_intervals line 930 logfile: W10DT714674/W10DT714674-D_gui_log_2024-12-04_11-43-22.txt boxes: 6D count: 6 text: Percentage of same side lick intervals under 100 ms in Box D mouse 749472 exceeded 10%
GUI Log snippet (click for full log)
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325815.91696, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325816.03232, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325817.917024, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325818.032352, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325819.967104, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325820.082464, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 16.64%.
12:22:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 9.94%.
12:22:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 13.49%.
12:22:29 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box D mouse 749472 exceeded 10%
Full GUI log (first 200 and last 200 lines)
11:43:22 AM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4661:Starting logfile!
11:43:22 AM:INFO:Foraging:Foraging.py:log_git_hash:line 4672:Python version: 3.11.9 | packaged by Anaconda, Inc. | (main, Apr 19 2024, 16:40:41) [MSC v.1916 64 bit (AMD64)]
11:43:22 AM:INFO:Foraging:Foraging.py:log_git_hash:line 4689:Current git commit branch, hash: main, 1a7c9d3d1aa10284caed44ba9b223c6bfbb8ff5f
11:43:22 AM:INFO:Foraging:Foraging.py:log_git_hash:line 4693:Current foraging_gui version: 1.6.10
11:43:22 AM:WARNING:Foraging:Foraging.py:log_git_hash:line 4703:local repository is clean
11:43:22 AM:INFO:Foraging:Foraging.py:<module>:line 4804:Setting QApplication attributes
11:43:22 AM:INFO:Foraging:Foraging.py:<module>:line 4812:Starting QApplication and Window
11:43:22 AM:INFO:Foraging:Foraging.py:__init__:line 69:Creating Window
11:43:22 AM:INFO:Foraging:Foraging.py:_GetSettings:line 1174:Loaded settings_box file
11:43:22 AM:INFO:Foraging:Foraging.py:_GetSettings:line 1202:Loaded settings file
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (FIP_settings), using default: C:\Users\svc_aind_behavior\Documents\FIPSettings
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\metadata_dialog\
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\rig_metadata\
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (project_info_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\Project Name and Funding Source v2.csv
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (go_cue_decibel_box1), using default: 60
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (go_cue_decibel_box2), using default: 60
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (go_cue_decibel_box3), using default: 60
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box1), using default: 5000
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box2), using default: 5000
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box3), using default: 5000
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box4), using default: 5000
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\name_mapper.json
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (create_rig_metadata), using default: True
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (save_each_trial), using default: True
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (AutomaticUpload), using default: True
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_behavior\Documents\aind_watchdog_service\manifest
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (auto_engage), using default: True
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (clear_figure_after_save), using default: True
11:43:22 AM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (add_default_project_name), using default: True
11:43:22 AM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1100:Loaded behavior schedule
11:43:22 AM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1064:Loaded Water Calibration
11:43:22 AM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1534:Found existing rig.json: rig_446-6-D_2024-12-03_12_51_34.json
11:43:22 AM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 60:building rig json
11:43:22 AM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 624:finished building rig json
11:43:22 AM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json:line 53:Using existing rig json
11:43:22 AM:INFO:Foraging:Foraging.py:_LoadUI:line 275:Using ForagingGUI.ui interface
11:43:22 AM:INFO:Foraging:Foraging.py:__init__:line 119:Setting Window title: 446-6-D
11:43:22 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1371:Trying to connect to already running Bonsai
11:43:22 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
11:43:23 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1375:Could not connect: timed out
11:43:23 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1384:Starting Bonsai
11:43:23 AM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4776:BONSAI logging starting
11:43:23 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
11:43:24 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1398:Could not connect, total waiting time 0.5 seconds: timed out
11:43:25 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
11:43:25 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1401:Connected to Bonsai after 1.0 seconds
11:43:25 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1402:Bonsai started successfully
11:43:25 AM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1281:Attempting to connect to Slims
11:43:25 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2323477.90752, '127.0.0.1', 4033], displaying at 0.5 Hz
11:43:25 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2323477.915488, '127.0.0.1', 4032]
11:43:26 AM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1298:Successfully connected to Slims
11:43:26 AM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_behavior\Documents\ForagingSettings\WaterCalibrationPar_4.json
11:43:26 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1863:processing parameter changes
11:43:26 AM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 875:Scanning for newscale stages
11:43:26 AM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 885:Could not find any instances of NewScale Stage
11:43:26 AM:INFO:Foraging:Foraging.py:_insert_stage_widget:line 255:Inserting Stage Widget
11:43:26 AM:INFO:connection:connection.py:_connect:line 688:Connecting to aibspi(10.128.108.106):2181, use_ssl: False
11:43:26 AM:INFO:client:client.py:_session_callback:line 561:Zookeeper connection established, state: CONNECTED
11:43:26 AM:INFO:connection:connection.py:_connect_attempt:line 655:Closing connection to aibspi:2181
11:43:26 AM:INFO:client:client.py:_session_callback:line 567:Zookeeper session closed, state: CLOSED
11:43:26 AM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 68:Connected to COM6, device id: 1130
11:43:26 AM:INFO:stepper_motor_device:stepper_motor_device.py:load_registers:line 149:Getting available registers on device
11:43:26 AM:INFO:stage_model:stage_model.py:configure_device:line 81:Configuring registers with default values (can be modified in config file)
11:43:27 AM:INFO:move_worker:move_worker.py:goto_origin:line 194:(move to origin): Moving stage to origin
11:43:27 AM:INFO:move_worker:move_worker.py:move_relative:line 336:(move relative): Moved motors by steps specified in [0, -27200, -27200, 0]
11:43:27 AM:INFO:move_worker:move_worker.py:move_relative:line 336:(move relative): Moved motors by steps specified in [-27200, 0, 0, 0]
11:43:27 AM:INFO:move_worker:move_worker.py:move_relative:line 336:(move relative): Moved motors by steps specified in [0, 0, 0, -27200]
11:43:27 AM:INFO:stage_model:stage_model.py:configure_device:line 87:Zeroed all motor positions
11:43:27 AM:INFO:stage_model:stage_model.py:configure_device:line 88:Finished configuring stepper motor device
#############################################################
11:43:27 AM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3428:Checking that photometry is not running
11:43:27 AM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3438:Photometry excitation stopped
11:43:27 AM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1534:Found existing rig.json: rig_446-6-D_2024-12-03_12_51_34.json
11:43:27 AM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 971:attempting to close bonsai connection
11:43:29 AM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 979:bonsai connection closed
11:43:29 AM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 981:attempting to restart bonsai
11:43:29 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1371:Trying to connect to already running Bonsai
11:43:29 AM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
11:43:29 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1378:Connected to already running Bonsai
11:43:29 AM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1379:Bonsai started successfully
11:43:29 AM:INFO:Foraging:Foraging.py:__init__:line 219:Start up complete
11:43:30 AM:INFO:aws_util:aws_util.py:import_df_from_s3:line 115:Dataframe imported from s3://aind-behavior-data/foraging_nwb_bonsai_processed/df_sessions.pkl, len(df) = 5833
11:43:30 AM:INFO:aws_util:aws_util.py:import_df_from_s3:line 115:Dataframe imported from s3://aind-behavior-data/foraging_auto_training/df_manager_447_demo.pkl, len(df) = 4352
11:43:31 AM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
11:43:31 AM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
11:43:32 AM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_behavior/.aind_auto_train/curriculum_manager/
11:43:32 AM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/.aind_auto_train/curriculum_manager/
11:43:32 AM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2273:No entry found in df_training_manager for subject_id: 0
11:43:32 AM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2621:Override stage clicked: state=2
11:43:32 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2647:Current stage to apply: unknown training stage @unknown curriculum
11:43:41 AM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3581:Stopping current trials
11:43:47 AM:INFO:Foraging:Foraging.py:_Open:line 2948:Quick load success: C:\behavior_data\446-6-D\749472\behavior_749472_2024-12-02_11-12-54\behavior\749472_2024-12-02_11-12-54.json
11:43:47 AM:INFO:Foraging:Foraging.py:_NewSession:line 3491:New Session pressed
11:43:47 AM:INFO:Foraging:Foraging.py:_NewSession:line 3523:Resetting session run flag
11:43:47 AM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3428:Checking that photometry is not running
11:43:47 AM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3438:Photometry excitation stopped
11:43:47 AM:INFO:Foraging:Foraging.py:_NewSession:line 3561:New Session complete
11:43:47 AM:ERROR:Foraging:Foraging.py:exception_hook:line 4769:FATAL ERROR:
Traceback (most recent call last):
File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Foraging.py", line 2819, in _OpenLast
self._Open(open_last=True)
File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Foraging.py", line 2973, in _Open
Obj = json.loads(f.read())
^^^^^^^^^^^^^^^^^^^^
File "C:\Users\svc_aind_behavior\AppData\Local\miniconda3\envs\Foraging\Lib\json\__init__.py", line 346, in loads
return _default_decoder.decode(s)
^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Users\svc_aind_behavior\AppData\Local\miniconda3\envs\Foraging\Lib\json\decoder.py", line 337, in decode
obj, end = self.raw_decode(s, idx=_w(s, 0).end())
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "C:\Users\svc_aind_behavior\AppData\Local\miniconda3\envs\Foraging\Lib\json\decoder.py", line 353, in raw_decode
obj, end = self.scan_once(s, idx)
^^^^^^^^^^^^^^^^^^^^^^
json.decoder.JSONDecodeError: Expecting ',' delimiter: line 183817 column 10 (char 2868946)
11:43:55 AM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2825:AutoTrain disengaged!
11:43:55 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Without Baiting_curriculum_v2.3.1rwdDelay159_schema_v1.0.json'.
11:43:55 AM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2621:Override stage clicked: state=0
11:43:55 AM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2567:Selected curriculum: {'curriculum_name': 'Uncoupled Without Baiting', 'curriculum_version': '2.3.1rwdDelay159', 'curriculum_schema_version': '1.0', 'curriculum_description': '2024-08-16 max_len = 75 mins; decrease finished trial criterion'}
11:43:55 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Without Baiting_curriculum_v2.3.1rwdDelay159_schema_v1.0.json'.
11:43:55 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2647:Current stage to apply: STAGE_FINAL @Uncoupled Without Baiting ([email protected])
11:43:55 AM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2647:Current stage to apply: STAGE_FINAL @Uncoupled Without Baiting ([email protected])
11:43:55 AM:INFO:Dialogs:Dialogs.py:_update_curriculum_diagrams:line 2567:Selected curriculum: {'curriculum_name': 'Uncoupled Without Baiting', 'curriculum_version': '2.3.1rwdDelay159', 'curriculum_schema_version': '1.0', 'curriculum_description': '2024-08-16 max_len = 75 mins; decrease finished trial criterion'}
11:43:55 AM:INFO:curriculum_manager:curriculum_manager.py:get_curriculum:line 131:Loaded a DynamicForagingCurriculum model from 'Uncoupled Without Baiting_curriculum_v2.3.1rwdDelay159_schema_v1.0.json'.
11:43:55 AM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2774:AutoTrain engaged! STAGE_FINAL @ Uncoupled Without Baiting ([email protected])
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2905: Widget "training_stage" not found. skipped...
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1863:processing parameter changes
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: RightValue, 0.03 -> 0.041
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: LeftValue, 0.03 -> 0.037
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: ID, 0.0 -> 749472.0
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: RightValue, 0.03 -> 0.041
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: LeftValue, 0.03 -> 0.037
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: GiveWaterL, 0.03 -> 0.037
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: GiveWaterR, 0.03 -> 0.041
11:43:55 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1863:processing parameter changes
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2897:Task is set to Uncoupled Without Baiting
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2905: Widget "task_url" not found. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2905: Widget "task_schema_version" not found. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2905: Widget "description" not found. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "BaseRewardSum" has been disabled by the GUI. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "RewardFamily" has been disabled by the GUI. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "RewardPairsN" has been disabled by the GUI. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:UncoupledReward is set to 0.1, 0.5, 0.9
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:Randomness is set to Exponential
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:BlockMin is set to 20
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:BlockMax is set to 35
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "BlockBeta" has been disabled by the GUI. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "BlockMinReward" has been disabled by the GUI. skipped...
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:DelayMin is set to 1.0
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:DelayMax is set to 1.0
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:DelayBeta is set to 0.0
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:RewardDelay is set to 0.2
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:AutoReward is set to False
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:AutoWaterType is set to Natural
11:43:55 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:Multiplier is set to 0.5
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:Unrewarded is set to 10
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:Ignored is set to 10
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:ITIMin is set to 2.0
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:ITIMax is set to 15.0
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:ITIBeta is set to 3.0
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "ITIIncrease" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:ResponseTime is set to 1.5
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:RewardConsumeTime is set to 1.0
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:StopIgnores is set to 25
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "AdvancedBlockAuto" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "SwitchThr" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "PointsInARow" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:MaxTrial is set to 1000
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:MaxTime is set to 75
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:RightValue_volume is set to 2.0
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:LeftValue_volume is set to 2.0
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "warm_min_trial" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "warm_max_choice_ratio_bias" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "warm_min_finish_ratio" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2917: Widget "warm_windowsize" has been disabled by the GUI. skipped...
11:43:56 AM:INFO:Dialogs:Dialogs.py:_set_training_parameters:line 2952:warmup is set to off
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1863:processing parameter changes
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: ITIMin, 1.0 -> 2.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: DelayMin, 0.0 -> 1.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: DelayBeta, 1.0 -> 0.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: BlockMax, 60.0 -> 35.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: RewardDelay, 0.0 -> 0.2
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: ITIMax, 8.0 -> 15.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: ITIBeta, 2.0 -> 3.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: ResponseTime, 1.0 -> 1.5
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: Ignored, 100.0 -> 10.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: StopIgnores, 20.0 -> 25.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: MaxTime, 120.0 -> 75.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: RewardConsumeTime, 3.0 -> 1.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: Multiplier, 0.8 -> 0.5
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: RightValue_volume, 3.0 -> 2.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: RightValue, 0.041 -> 0.028
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: LeftValue, 0.037 -> 0.026
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: Unrewarded, 200.0 -> 10.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: LeftValue_volume, 3.0 -> 2.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: ITIMin, 1.0 -> 2.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: DelayMin, 0.0 -> 1.0
11:43:56 AM:INFO:Foraging:Foraging.py:keyPressEvent:line 1922:Changing parameter: DelayBeta, 1.0 -> 0.0
_____SKIPPING_____
12:21:52 PM:INFO:Foraging:Foraging.py:_Save:line 2441:Saving current session, ForceSave=1
12:21:52 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1064:Loaded Water Calibration
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\749472\behavior_749472_2024-12-04_11-52-11
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:21:52 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:21:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325785.46576, '127.0.0.1', 4033], displaying at 0.5 Hz
12:21:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325785.68112, '127.0.0.1', 4033], displaying at 0.5 Hz
12:21:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325787.51584, '127.0.0.1', 4033], displaying at 0.5 Hz
12:21:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325787.7312, '127.0.0.1', 4033], displaying at 0.5 Hz
12:21:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325789.565952, '127.0.0.1', 4033], displaying at 0.5 Hz
12:21:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325789.731296, '127.0.0.1', 4033], displaying at 0.5 Hz
12:21:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325791.566016, '127.0.0.1', 4033], displaying at 0.5 Hz
12:21:59 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325791.781376, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2325793.557984, '127.0.0.1', 4032]
12:22:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325793.559488, '127.0.0.1', 4032]
12:22:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325793.616096, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:01 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325793.78144, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2325794.540992, '127.0.0.1', 4032]
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325794.542496, '127.0.0.1', 4032]
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2325794.543296, 4, '127.0.0.1']
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2325794.929408, '127.0.0.1', 4033]
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2325794.928992, '127.0.0.1', 4032]
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4032]
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2325794.963296, '127.0.0.1', 4033]
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2325795.146304, '127.0.0.1', 4033]
12:22:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325795.368672, '127.0.0.1', 4033]
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325795.577696, '127.0.0.1', 4033]
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325795.616192, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325795.7312, '127.0.0.1', 4033]
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325795.781536, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325795.880576, '127.0.0.1', 4033]
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2325795.924, '127.0.0.1', 4032]
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325795.926496, '127.0.0.1', 4032]
12:22:03 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
12:22:03 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
12:22:03 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4141:Current trial: 149
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2325795.936, '127.0.0.1', 4032]
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2325795.939488, '127.0.0.1', 4032]
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325796.026752, '127.0.0.1', 4033]
12:22:03 PM:INFO:Foraging:Foraging.py:_Save:line 2441:Saving current session, ForceSave=1
12:22:03 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1064:Loaded Water Calibration
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\749472\behavior_749472_2024-12-04_11-52-11
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:03 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325796.197088, '127.0.0.1', 4033]
12:22:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325797.66624, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:05 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325797.831584, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325798.5536, '127.0.0.1', 4033]
12:22:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325798.563808, '127.0.0.1', 4033]
12:22:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2325799.240992, '127.0.0.1', 4032]
12:22:06 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325799.242496, '127.0.0.1', 4032]
12:22:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325799.666336, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325799.83168, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2325800.224, '127.0.0.1', 4032]
12:22:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325800.226496, '127.0.0.1', 4032]
12:22:07 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2325800.227328, 4, '127.0.0.1']
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325800.55312, '127.0.0.1', 4033]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2325800.552992, '127.0.0.1', 4032]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4032]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325800.594816, '127.0.0.1', 4033]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325800.693024, '127.0.0.1', 4033]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325800.805696, '127.0.0.1', 4033]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325800.82496, '127.0.0.1', 4033]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325800.990208, '127.0.0.1', 4033]
12:22:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325801.195072, '127.0.0.1', 4033]
12:22:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2325801.540992, '127.0.0.1', 4032]
12:22:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325801.542496, '127.0.0.1', 4032]
12:22:09 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
12:22:09 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
12:22:09 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4141:Current trial: 150
12:22:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2325801.552, '127.0.0.1', 4032]
12:22:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2325801.555488, '127.0.0.1', 4032]
12:22:09 PM:INFO:Foraging:Foraging.py:_Save:line 2441:Saving current session, ForceSave=1
12:22:09 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1064:Loaded Water Calibration
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\749472\behavior_749472_2024-12-04_11-52-11
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325801.716384, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:09 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325801.88176, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:10 PM:INFO:bias_indicator:bias_indicator.py:calculate_bias:line 139:Bias: -0.1295529835806754 Trial Count: 149
12:22:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325803.71648, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:11 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325803.93184, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325805.76656, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:13 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325805.98192, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2325806.957984, '127.0.0.1', 4032]
12:22:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325806.959488, '127.0.0.1', 4032]
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325807.766624, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2325807.940992, '127.0.0.1', 4032]
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325807.942496, '127.0.0.1', 4032]
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2325807.94336, 4, '127.0.0.1']
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325807.981984, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325808.0952, '127.0.0.1', 4033]
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2325808.094976, '127.0.0.1', 4032]
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorRight', '127.0.0.1', 4032]
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325808.272672, '127.0.0.1', 4033]
12:22:15 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325808.316448, '127.0.0.1', 4033]
12:22:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325808.478112, '127.0.0.1', 4033]
12:22:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325808.61632, '127.0.0.1', 4033]
12:22:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2325809.090976, '127.0.0.1', 4032]
12:22:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325809.09248, '127.0.0.1', 4032]
12:22:16 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
12:22:16 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
12:22:16 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4141:Current trial: 151
12:22:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2325809.101984, '127.0.0.1', 4032]
12:22:16 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2325809.105504, '127.0.0.1', 4032]
12:22:16 PM:INFO:Foraging:Foraging.py:_Save:line 2441:Saving current session, ForceSave=1
12:22:16 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1064:Loaded Water Calibration
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\749472\behavior_749472_2024-12-04_11-52-11
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:16 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325809.816704, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:17 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325809.98208, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325811.866816, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:19 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325812.032128, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2325812.724, '127.0.0.1', 4032]
12:22:20 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325812.726496, '127.0.0.1', 4032]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2325813.706976, '127.0.0.1', 4032]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325813.709504, '127.0.0.1', 4032]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2325813.7104, 4, '127.0.0.1']
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325813.796544, '127.0.0.1', 4033]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2325813.796, '127.0.0.1', 4032]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTime', 2325813.796, '127.0.0.1', 4033]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardRight', '127.0.0.1', 4032]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325813.819424, '127.0.0.1', 4033]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325813.916864, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedRightWaterStartTime', 2325814.008, '127.0.0.1', 4033]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 2325814.009504, '127.0.0.1', 4033]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325814.032224, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325814.058688, '127.0.0.1', 4033]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325814.248768, '127.0.0.1', 4033]
12:22:21 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325814.37808, '127.0.0.1', 4033]
12:22:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325814.538656, '127.0.0.1', 4033]
12:22:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2325814.688384, '127.0.0.1', 4033]
12:22:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2325814.790976, '127.0.0.1', 4032]
12:22:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2325814.79248, '127.0.0.1', 4032]
12:22:22 PM:WARNING:MyFunctions:MyFunctions.py:_GenerateATrial:line 172:
12:22:22 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
12:22:22 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4141:Current trial: 152
12:22:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2325814.805984, '127.0.0.1', 4032]
12:22:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2325814.810496, '127.0.0.1', 4032]
12:22:22 PM:INFO:Foraging:Foraging.py:_Save:line 2441:Saving current session, ForceSave=1
12:22:22 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1064:Loaded Water Calibration
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\749472\behavior_749472_2024-12-04_11-52-11
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 361:Cannot log reward delivery in session metadata - missing fields
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 114:Session metadata generated successfully: True
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 115:Rig metadata generated successfully: True
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1192:No reward delivery metadata found!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1027:No opto calibration results detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 865:No ephys data stream detected!
12:22:22 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 562:No camera data stream detected!
12:22:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325815.91696, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:23 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325816.03232, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325817.917024, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:25 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325818.032352, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryRising', 2325819.967104, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:27 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 2325820.082464, '127.0.0.1', 4033], displaying at 0.5 Hz
12:22:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 16.64%.
12:22:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 9.94%.
12:22:29 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 13.49%.
12:22:29 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box D mouse 749472 exceeded 10%
The text was updated successfully, but these errors were encountered:
This issue was automatically generated from GUI logs.
file: MyFunctions.py
function: calculate_inter_lick_intervals
line 930
logfile: W10DT714674/W10DT714674-D_gui_log_2024-12-04_11-43-22.txt
boxes: 6D
count: 6
text: Percentage of same side lick intervals under 100 ms in Box D mouse 749472 exceeded 10%
GUI Log snippet (click for full log)
Full GUI log (first 200 and last 200 lines)The text was updated successfully, but these errors were encountered: