Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

Percentage of same side lick intervals under 100 ms in Box 4D mouse 1 exceeded 10% #1151

Open
alexpiet opened this issue Dec 10, 2024 · 0 comments
Open

Percentage of same side lick intervals under 100 ms in Box 4D mouse 1 exceeded 10% #1151

alexpiet opened this issue Dec 10, 2024 · 0 comments
Labels
low priority - auto-generated autogenerated issues that have only occurred once

Comments

@alexpiet
Copy link
Collaborator

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-09_15-16-48.txt
boxes: 6D
count: 1
text: Percentage of same side lick intervals under 100 ms in Box 4D mouse 1 exceeded 10%

GUI Log snippet (click for full log)

03:32:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:38 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 15.0, 1: 15.0, 2: 0.0, 3: 0.0}
03:32:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:32:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 15.0
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:32:41 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 0, 0, 0] to [12000, 12000, 0, 0]
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:33:16 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 15.0, 1: 15.0, 2: 15.0, 3: 15.0}
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 15.0
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 15.0
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:33:19 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 12000, 0, 0] to [12000, 12000, 12000, 12000]
03:33:46 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 80.93%.
03:33:46 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 73.28%.
03:33:46 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 78.38%.
03:33:46 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box 4D mouse 1 exceeded 10%
Full GUI log (first 200 and last 200 lines) 
03:16:48 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4786:Starting logfile!
03:16:49 PM:WARNING:Foraging:Foraging.py:<module>:line 4929:Failed to setup LOKI Handler: 'NoneType' object has no attribute 'username'
03:16:49 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4797:Python version: 3.11.9 | packaged by Anaconda, Inc. | (main, Apr 19 2024, 16:40:41) [MSC v.1916 64 bit (AMD64)]
03:16:49 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4814:Current git commit branch, hash: production_testing, 15b0d03623f243275f779e00596411083307693a
03:16:49 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4818:Current foraging_gui version: 1.6.10
03:16:49 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4828:local repository is clean
03:16:49 PM:INFO:Foraging:Foraging.py:<module>:line 4934:Setting QApplication attributes
03:16:49 PM:INFO:Foraging:Foraging.py:<module>:line 4942:Starting QApplication and Window
03:16:49 PM:INFO:Foraging:Foraging.py:__init__:line 77:Creating Window
03:16:49 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1211:Loaded settings_box file
03:16:49 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1239:Loaded settings file
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (FIP_settings), using default: C:\Users\svc_aind_behavior\Documents\FIPSettings
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (bonsai_config_path), using default: C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\bonsai\Bonsai.config
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\metadata_dialog\
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\rig_metadata\
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (project_info_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\Project Name and Funding Source v2.csv
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box1), using default: 60
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box2), using default: 60
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (go_cue_decibel_box3), using default: 60
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box1), using default: 5000
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box2), using default: 5000
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box3), using default: 5000
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (lick_spout_distance_box4), using default: 5000
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\name_mapper.json
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (create_rig_metadata), using default: True
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (save_each_trial), using default: True
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (AutomaticUpload), using default: True
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_behavior\Documents\aind_watchdog_service\manifest
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (auto_engage), using default: True
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (clear_figure_after_save), using default: True
03:16:49 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1249:Missing setting (add_default_project_name), using default: True
03:16:49 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1137:Loaded behavior schedule
03:16:49 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
03:16:49 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1571:Found existing rig.json: rig_446-6-D_2024-12-09_10_55_20.json
03:16:49 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 60:building rig json
03:16:49 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 624:finished building rig json
03:16:50 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json:line 42:differences with existing rig json: {'values_changed': {"root['daqs'][0]": {'new_value': {'device_type': 'Harp device', 'name': 'harp behavior board', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': 'Left lick spout and Right lick spout, as well as reward delivery solenoids are connected via ethernet cables', 'data_interface': 'Ethernet', 'computer_name': 'W10DT714674', 'channels': [{'channel_name': 'DI3', 'device_name': 'Photometry Clock', 'channel_type': 'Digital Input', 'port': None, 'channel_index': None, 'sample_rate': None, 'sample_rate_unit': 'hertz', 'event_based_sampling': None}], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Behavior', 'whoami': 1216}, 'core_version': '1.11', 'tag_version': None, 'is_clock_generator': False}, 'old_value': {'device_type': 'Harp device', 'name': 'Harp Behavior', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': 'Left lick spout and Right lick spout, as well as reward delivery solenoids are connected via ethernet cables', 'data_interface': 'Ethernet', 'computer_name': 'W10DT714674', 'channels': [{'channel_name': 'DI3', 'device_name': 'Photometry Clock', 'channel_type': 'Digital Input', 'port': None, 'channel_index': None, 'sample_rate': None, 'sample_rate_unit': 'hertz', 'event_based_sampling': None}], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Behavior', 'whoami': 1216}, 'core_version': '1.11', 'tag_version': None, 'is_clock_generator': False}}, "root['daqs'][1]": {'new_value': {'device_type': 'Harp device', 'name': 'harp sound card', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': None, 'data_interface': 'USB', 'computer_name': 'W10DT714674', 'channels': [], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Sound Card', 'whoami': 1280}, 'core_version': '1.4', 'tag_version': None, 'is_clock_generator': False}, 'old_value': {'device_type': 'Harp device', 'name': 'Harp Sound', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': None, 'data_interface': 'USB', 'computer_name': 'W10DT714674', 'channels': [], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Sound Card', 'whoami': 1280}, 'core_version': '1.4', 'tag_version': None, 'is_clock_generator': False}}, "root['daqs'][3]": {'new_value': {'device_type': 'Harp device', 'name': 'harp sound amplifier', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': None, 'data_interface': 'USB', 'computer_name': 'W10DT714674', 'channels': [], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Input Expander', 'whoami': 1106}, 'core_version': '', 'tag_version': None, 'is_clock_generator': False}, 'old_value': {'device_type': 'Harp device', 'name': 'Harp sound amplifier', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': None, 'data_interface': 'USB', 'computer_name': 'W10DT714674', 'channels': [], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Input Expander', 'whoami': 1106}, 'core_version': '', 'tag_version': None, 'is_clock_generator': False}}, "root['daqs'][2]": {'new_value': {'device_type': 'Harp device', 'name': 'harp clock synchronization board', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': None, 'data_interface': 'USB', 'computer_name': 'W10DT714674', 'channels': [], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Clock Synchronizer', 'whoami': 1152}, 'core_version': '', 'tag_version': None, 'is_clock_generator': True}, 'old_value': {'device_type': 'Harp device', 'name': 'Harp clock synchronization board', 'serial_number': None, 'manufacturer': {'name': 'Champalimaud Foundation', 'abbreviation': 'Champalimaud', 'registry': {'name': 'Research Organization Registry', 'abbreviation': 'ROR'}, 'registry_identifier': '03g001n57'}, 'model': None, 'path_to_cad': None, 'port_index': None, 'additional_settings': {}, 'notes': None, 'data_interface': 'USB', 'computer_name': 'W10DT714674', 'channels': [], 'firmware_version': None, 'hardware_version': None, 'harp_device_type': {'name': 'Clock Synchronizer', 'whoami': 1152}, 'core_version': '', 'tag_version': None, 'is_clock_generator': True}}}}
03:16:50 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json:line 51:Saving new rig json: rig_446-6-D_2024-12-09_15_16_50.json
03:16:50 PM:INFO:Foraging:Foraging.py:_LoadUI:line 299:Using ForagingGUI.ui interface
03:16:50 PM:INFO:Foraging:Foraging.py:__init__:line 143:Setting Window title: 446-6-D
03:16:50 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1408:Trying to connect to already running Bonsai
03:16:50 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1455:connecting to GUI and Bonsai through OSC
03:16:51 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1412:Could not connect: timed out
03:16:51 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1421:Starting Bonsai
03:16:51 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4901:BONSAI logging starting
03:16:51 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1455:connecting to GUI and Bonsai through OSC
03:16:52 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1435:Could not connect, total waiting time 0.5 seconds: timed out
03:16:53 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1455:connecting to GUI and Bonsai through OSC
03:16:54 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1435:Could not connect, total waiting time 1.0 seconds: timed out
03:16:54 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1455:connecting to GUI and Bonsai through OSC
03:16:55 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1438:Connected to Bonsai after 1.5 seconds
03:16:55 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1439:Bonsai started successfully
03:16:55 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1318:Attempting to connect to Slims
03:16:55 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1335:Successfully connected to Slims
03:16:56 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_behavior\Documents\ForagingSettings\WaterCalibrationPar_4.json
03:16:56 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 912:Scanning for newscale stages
03:16:56 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 922:Could not find any instances of NewScale Stage
03:16:56 PM:INFO:Foraging:Foraging.py:_insert_stage_widget:line 279:Inserting Stage Widget
03:16:56 PM:INFO:connection:connection.py:_connect:line 688:Connecting to aibspi(10.128.108.106):2181, use_ssl: False
03:16:56 PM:INFO:client:client.py:_session_callback:line 561:Zookeeper connection established, state: CONNECTED
03:16:56 PM:INFO:connection:connection.py:_connect_attempt:line 655:Closing connection to aibspi:2181
03:16:56 PM:INFO:client:client.py:_session_callback:line 567:Zookeeper session closed, state: CLOSED
03:16:56 PM:INFO:main:main.py:get_stage_widget:line 23:Getting Stage Controller Widget - 1.0.4.dev1+g5cafa8d.b163669
03:16:56 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM3 - device may be being used by another program
03:16:56 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 52:Skipping COM4 - device may be being used by another program
03:16:56 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 70:Connected to COM6, device id: 1130
03:16:56 PM:INFO:stepper_motor_device:stepper_motor_device.py:load_registers:line 151:Getting available registers on device
03:16:56 PM:WARNING:stepper_motor_device:stepper_motor_device.py:load_registers:line 159:Firmware version 0.5 doesn't match config version 0.7.
    Registers may be defined incorrectly
03:16:56 PM:INFO:stage_model:stage_model.py:configure_device:line 81:Configuring registers with default values (can be modified in config file)
03:16:56 PM:INFO:move_worker:move_worker.py:goto_origin:line 195:(move to origin): Moving stage to origin
03:16:56 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, -27200, -27200, 0]
03:16:56 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [-27200, 0, 0, 0]
03:16:56 PM:INFO:move_worker:move_worker.py:move_relative:line 337:(move relative): Moved motors by steps specified in [0, 0, 0, -27200]
03:16:56 PM:INFO:stage_model:stage_model.py:configure_device:line 87:Zeroed all motor positions
03:16:56 PM:INFO:stage_model:stage_model.py:configure_device:line 88:Finished configuring stepper motor device
#############################################################
03:16:56 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:16:56 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3512:Checking that photometry is not running
03:16:56 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3522:Photometry excitation stopped
03:16:56 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1571:Found existing rig.json: rig_446-6-D_2024-12-09_15_16_50.json
03:16:56 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1008:attempting to close bonsai connection
03:17:00 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1016:bonsai connection closed
03:17:00 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 1018:attempting to restart bonsai
03:17:00 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1408:Trying to connect to already running Bonsai
03:17:00 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1455:connecting to GUI and Bonsai through OSC
03:17:00 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1415:Connected to already running Bonsai
03:17:00 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1416:Bonsai started successfully
03:17:00 PM:INFO:Foraging:Foraging.py:__init__:line 243:Start up complete
03:17:01 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) = 5932
03:17:01 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) = 4440
03:17:02 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
03:17:02 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
03:17:02 PM:INFO:aws_util:aws_util.py:download_dir_from_s3:line 140:134 objects downloaded from s3://aind-behavior-data/foraging_auto_training/saved_curriculums/ to C:\Users\svc_aind_behavior/.aind_auto_train/curriculum_manager/
03:17:02 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/.aind_auto_train/curriculum_manager/
03:17:02 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 0
03:17:02 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2640:Override stage clicked: state=2
03:17:02 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
03:23:15 PM:INFO:Dialogs:Dialogs.py:update_auto_train_lock:line 2844:AutoTrain disengaged!
03:23:15 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2292:No entry found in df_training_manager for subject_id: 1
03:23:15 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2666:Current stage to apply: unknown training stage @unknown curriculum
03:23:15 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2421:Auto engage successful for mouse 1
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: RightValue, 0.03 -> 0.041
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: LeftValue, 0.03 -> 0.037
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: ID, 0.0 -> 1.0
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: RightValue, 0.03 -> 0.041
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: LeftValue, 0.03 -> 0.037
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: GiveWaterL, 0.03 -> 0.037
03:23:15 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: GiveWaterR, 0.03 -> 0.041
03:23:44 PM:INFO:Foraging:Foraging.py:_Start:line 3803:Start button pressed: starting trial loop
03:23:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:23:46 PM:INFO:Foraging:Foraging.py:_Start:line 3872:Starting session, with experimenter: the ghost in the shell
03:23:46 PM:INFO:Foraging:Foraging.py:_set_default_project:line 3740:Setting Project name: Behavior Platform
03:23:46 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:23:46 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:23:46 PM:INFO:Foraging:Foraging.py:_restartlogging:line 1034:Restarting logging
03:23:46 PM:INFO:Foraging:Foraging.py:_GetSaveFolder:line 2774:Created new folder: C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46
03:23:46 PM:INFO:Foraging:Foraging.py:_GetSaveFolder:line 2777:Created new folder: C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46\metadata-dir
03:23:46 PM:INFO:Foraging:Foraging.py:_GetSaveFolder:line 2780:Created new folder: C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46\behavior
03:23:46 PM:INFO:Foraging:Foraging.py:_GetSaveFolder:line 2783:Created new folder: C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46\behavior\raw.harp
03:23:46 PM:INFO:Foraging:Foraging.py:_GetSaveFolder:line 2786:Created new folder: C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46\behavior-videos
03:23:46 PM:INFO:Foraging:Foraging.py:_GetSaveFolder:line 2789:Created new folder: C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46\fib
03:23:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/loggerstarted', 'C:\\behavior_data\\446-6-D\\1\\behavior_1_2024-12-09_15-23-46\\behavior\\raw.harp', '127.0.0.1', 4032]
03:23:46 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:23:46 PM:INFO:Foraging:Foraging.py:log_session:line 4198:Starting log file at C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46\behavior
03:23:46 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4215:starting trial loop
03:23:46 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4236:Current trial: 1
03:23:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2768698.065984, '127.0.0.1', 4032]
03:23:46 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2768698.069504, '127.0.0.1', 4032]
03:23:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2768700.724992, '127.0.0.1', 4032]
03:23:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768700.72848, '127.0.0.1', 4032]
03:23:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2768701.708, '127.0.0.1', 4032]
03:23:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768701.711488, '127.0.0.1', 4032]
03:23:49 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2768701.712384, 4, '127.0.0.1']
03:23:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2768702.713984, '127.0.0.1', 4032]
03:23:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'NoResponse', '127.0.0.1', 4032]
03:23:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2768705.724, '127.0.0.1', 4032]
03:23:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768705.726496, '127.0.0.1', 4032]
03:23:53 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:23:53 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4236:Current trial: 2
03:23:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2768705.740992, '127.0.0.1', 4032]
03:23:53 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2768705.745504, '127.0.0.1', 4032]
03:23:53 PM:INFO:Foraging:Foraging.py:_Save:line 2478:Saving current session, ForceSave=1
03:23:53 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
03:23:53 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46
03:23:53 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
03:23:53 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 386:No laser calibration file for session metadata
03:23:53 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1304:No reward delivery metadata found!
03:23:53 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1139:No opto calibration results detected!
03:23:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 976:No ephys data stream detected!
03:23:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
03:23:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 624:No camera data stream detected!
03:23:54 PM:WARNING:Foraging:Foraging.py:_Save:line 2706:Meta data is not saved!
03:23:54 PM:ERROR:Foraging:Foraging.py:_Save:line 2707:Error generating session metadata: The truth value of an empty array is ambiguous. Use `array.size > 0` to check that an array is not empty.
03:23:54 PM:ERROR:Foraging:Foraging.py:_Save:line 2708:Traceback (most recent call last):
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Foraging.py", line 2688, in _Save
    generated_metadata=generate_metadata(Obj=Obj)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 112, in __init__
    self._session()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 523, in _session
    self._get_stimulus()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 746, in _get_stimulus
    self._get_behavior_stimulus()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 777, in _get_behavior_stimulus
    output_parameters=self._get_output_parameters(),
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 835, in _get_output_parameters
    'foraging_efficiency': _get_field(self.Obj, 'B_for_eff_optimal'),
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\TransferToNWB.py", line 53, in _get_field
    if value in reject_list:
       ^^^^^^^^^^^^^^^^^^^^
ValueError: The truth value of an empty array is ambiguous. Use `array.size > 0` to check that an array is not empty.

03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768706.845088, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768706.846976, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.316256, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.317984, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.409984, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.553984, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.556, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.805856, '127.0.0.1', 4033]
03:23:55 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.8072, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.808992, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.812992, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.820992, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.822976, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.842976, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.846976, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.851072, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.852992, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 2768707.85536, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2768708.259584, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2768708.268, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2768708.276, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2768708.280896, '127.0.0.1', 4033]
03:23:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 2768708.282976, '127.0.0.1', 4033]
_____SKIPPING_____
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 835, in _get_output_parameters
    'foraging_efficiency': _get_field(self.Obj, 'B_for_eff_optimal'),
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\TransferToNWB.py", line 53, in _get_field
    if value in reject_list:
       ^^^^^^^^^^^^^^^^^^^^
ValueError: The truth value of an empty array is ambiguous. Use `array.size > 0` to check that an array is not empty.

03:27:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2768935.673984, '127.0.0.1', 4032]
03:27:43 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768935.675488, '127.0.0.1', 4032]
03:27:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2768936.656992, '127.0.0.1', 4032]
03:27:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2768936.660224, 4, '127.0.0.1']
03:27:44 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768936.659488, '127.0.0.1', 4032]
03:27:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2768937.657984, '127.0.0.1', 4032]
03:27:45 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'NoResponse', '127.0.0.1', 4032]
03:27:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2768940.673984, '127.0.0.1', 4032]
03:27:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768940.67648, '127.0.0.1', 4032]
03:27:48 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:27:48 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4236:Current trial: 31
03:27:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2768940.68, '127.0.0.1', 4032]
03:27:48 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2768940.683488, '127.0.0.1', 4032]
03:27:48 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Visualization.py:160: RuntimeWarning: Mean of empty slice
  RewardedHistoryF[i+1-self.kernel_size]=np.nanmean(RewardedHistoryT[i+1-self.kernel_size:i+1])

03:27:48 PM:INFO:Foraging:Foraging.py:_Save:line 2478:Saving current session, ForceSave=1
03:27:48 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
03:27:48 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46
03:27:48 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
03:27:48 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1304:No reward delivery metadata found!
03:27:48 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1139:No opto calibration results detected!
03:27:49 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 976:No ephys data stream detected!
03:27:49 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
03:27:49 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 624:No camera data stream detected!
03:27:49 PM:WARNING:Foraging:Foraging.py:_Save:line 2706:Meta data is not saved!
03:27:49 PM:ERROR:Foraging:Foraging.py:_Save:line 2707:Error generating session metadata: The truth value of an empty array is ambiguous. Use `array.size > 0` to check that an array is not empty.
03:27:49 PM:ERROR:Foraging:Foraging.py:_Save:line 2708:Traceback (most recent call last):
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Foraging.py", line 2688, in _Save
    generated_metadata=generate_metadata(Obj=Obj)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 112, in __init__
    self._session()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 523, in _session
    self._get_stimulus()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 746, in _get_stimulus
    self._get_behavior_stimulus()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 777, in _get_behavior_stimulus
    output_parameters=self._get_output_parameters(),
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 835, in _get_output_parameters
    'foraging_efficiency': _get_field(self.Obj, 'B_for_eff_optimal'),
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\TransferToNWB.py", line 53, in _get_field
    if value in reject_list:
       ^^^^^^^^^^^^^^^^^^^^
ValueError: The truth value of an empty array is ambiguous. Use `array.size > 0` to check that an array is not empty.

03:27:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2768942.190976, '127.0.0.1', 4032]
03:27:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768942.19248, '127.0.0.1', 4032]
03:27:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2768942.240992, '127.0.0.1', 4032]
03:27:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2768942.243232, 4, '127.0.0.1']
03:27:50 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768942.242496, '127.0.0.1', 4032]
03:27:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2768943.240992, '127.0.0.1', 4032]
03:27:51 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'NoResponse', '127.0.0.1', 4032]
03:27:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2768946.257984, '127.0.0.1', 4032]
03:27:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768946.259488, '127.0.0.1', 4032]
03:27:54 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:27:54 PM:INFO:Foraging:Foraging.py:_StartTrialLoop:line 4236:Current trial: 32
03:27:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialStartTime', 2768946.262976, '127.0.0.1', 4032]
03:27:54 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ITIStartTimeHarp', 2768946.266496, '127.0.0.1', 4032]
03:27:54 PM:WARNING:warnings:warnings.py:_showwarnmsg:line 110:C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Visualization.py:160: RuntimeWarning: Mean of empty slice
  RewardedHistoryF[i+1-self.kernel_size]=np.nanmean(RewardedHistoryT[i+1-self.kernel_size:i+1])

03:27:54 PM:INFO:Foraging:Foraging.py:_Save:line 2478:Saving current session, ForceSave=1
03:27:54 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1101:Loaded Water Calibration
03:27:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:__init__:line 88:processing:C:\behavior_data\446-6-D\1\behavior_1_2024-12-09_15-23-46
03:27:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_handle_edge_cases:line 369:Cannot log reward delivery in session metadata - missing fields
03:27:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_reward_delivery:line 1304:No reward delivery metadata found!
03:27:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_opto_calibration:line 1139:No opto calibration results detected!
03:27:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ephys_stream:line 976:No ephys data stream detected!
03:27:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_ophys_stream:line 646:No photometry data stream detected!
03:27:54 PM:INFO:GenerateMetadata:GenerateMetadata.py:_get_high_speed_camera_stream:line 624:No camera data stream detected!
03:27:54 PM:WARNING:Foraging:Foraging.py:_Save:line 2706:Meta data is not saved!
03:27:54 PM:ERROR:Foraging:Foraging.py:_Save:line 2707:Error generating session metadata: The truth value of an empty array is ambiguous. Use `array.size > 0` to check that an array is not empty.
03:27:54 PM:ERROR:Foraging:Foraging.py:_Save:line 2708:Traceback (most recent call last):
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\Foraging.py", line 2688, in _Save
    generated_metadata=generate_metadata(Obj=Obj)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 112, in __init__
    self._session()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 523, in _session
    self._get_stimulus()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 746, in _get_stimulus
    self._get_behavior_stimulus()
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 777, in _get_behavior_stimulus
    output_parameters=self._get_output_parameters(),
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\GenerateMetadata.py", line 835, in _get_output_parameters
    'foraging_efficiency': _get_field(self.Obj, 'B_for_eff_optimal'),
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "C:\Users\svc_aind_behavior\Documents\GitHub\dynamic-foraging-task\src\foraging_gui\TransferToNWB.py", line 53, in _get_field
    if value in reject_list:
       ^^^^^^^^^^^^^^^^^^^^
ValueError: The truth value of an empty array is ambiguous. Use `array.size > 0` to check that an array is not empty.

03:27:55 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3665:Stopping current trials
03:27:55 PM:WARNING:Foraging:Foraging.py:_StopCurrentSession:line 3676:Waiting for the finish of the last trial!
03:27:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 2768948.006976, '127.0.0.1', 4032]
03:27:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768948.009504, '127.0.0.1', 4032]
03:27:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 2768948.256992, '127.0.0.1', 4032]
03:27:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 2768948.260256, 4, '127.0.0.1']
03:27:56 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768948.259488, '127.0.0.1', 4032]
03:27:57 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3665:Stopping current trials
03:27:57 PM:WARNING:Foraging:Foraging.py:_StopCurrentSession:line 3676:Waiting for the finish of the last trial!
03:27:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 2768949.257984, '127.0.0.1', 4032]
03:27:57 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'NoResponse', '127.0.0.1', 4032]
03:28:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 2768952.273984, '127.0.0.1', 4032]
03:28:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 2768952.275488, '127.0.0.1', 4032]
03:28:00 PM:WARNING:MyFunctions:MyFunctions.py:_CheckStop:line 1191:
03:31:16 PM:INFO:Foraging:Foraging.py:_Open:line 2983:Quick load failed, user hit cancel or X
03:31:18 PM:INFO:Foraging:Foraging.py:_Open:line 2983:Quick load failed, user hit cancel or X
03:31:37 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:31:37 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 10.0, 1: 5.0, 2: 5.0, 3: 5.0}
03:31:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 5.0
03:31:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 5.0
03:31:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 5.0
03:31:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 10.0
03:31:40 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 0, 0, 0] to [8000, 4000, 4000, 4000]
03:31:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:31:44 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 10.0, 1: 15.0, 2: 5.0, 3: 5.0}
03:31:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:31:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 5.0
03:31:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 5.0
03:31:44 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 10.0
03:31:47 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [8000, 4000, 4000, 4000] to [8000, 12000, 4000, 4000]
03:31:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:31:47 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 10.0, 1: 15.0, 2: 59.0, 3: 5.0}
03:31:47 PM:INFO:move_worker:move_worker.py:is_position_in_range:line 397:Position 59.0 is out of range for motor 2
03:31:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:31:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 5.0
03:31:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 59.0
03:31:47 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 10.0
03:31:48 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [8000, 12000, 4000, 4000] to [8000, 12000, 4000, 4000]
03:31:50 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:31:50 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 10.0, 1: 15.0, 2: 9.0, 3: 5.0}
03:31:50 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:31:50 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 5.0
03:31:50 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 9.0
03:31:50 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 10.0
03:31:51 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [8000, 12000, 4000, 4000] to [8000, 12000, 7200, 4000]
03:31:56 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:31:56 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 10.0, 1: 15.0, 2: 9.0, 3: 17.0}
03:31:56 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:31:56 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 17.0
03:31:56 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 9.0
03:31:56 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 10.0
03:31:58 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [8000, 12000, 7200, 4000] to [8000, 12000, 7200, 13600]
03:32:00 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:00 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 10.0, 1: 15.0, 2: 16.0, 3: 17.0}
03:32:00 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:32:00 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 17.0
03:32:00 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 16.0
03:32:00 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 10.0
03:32:02 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [8000, 12000, 7200, 13600] to [8000, 12000, 12800, 13600]
03:32:03 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:03 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 10.0, 1: 5.0, 2: 16.0, 3: 17.0}
03:32:03 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 5.0
03:32:03 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 17.0
03:32:03 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 16.0
03:32:03 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 10.0
03:32:05 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [8000, 12000, 12800, 13600] to [8000, 4000, 12800, 13600]
03:32:17 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:17 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 0.0, 1: 0.0, 2: 0.0, 3: 0.0}
03:32:21 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [8000, 4000, 12800, 13600] to [0, 0, 0, 0]
03:32:28 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:28 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 15.0, 1: 0.0, 2: 0.0, 3: 0.0}
03:32:28 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:32:30 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:30 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:32:30 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:32:31 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [0, 0, 0, 0] to [12000, 0, 0, 0]
03:32:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:38 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 15.0, 1: 15.0, 2: 0.0, 3: 0.0}
03:32:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:32:38 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 15.0
03:32:40 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:32:41 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 0, 0, 0] to [12000, 12000, 0, 0]
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1900:processing parameter changes
03:33:16 PM:INFO:move_worker:move_worker.py:move_to_position:line 144:(move to position): Moving motors to {0: 15.0, 1: 15.0, 2: 15.0, 3: 15.0}
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y1, 0.0 -> 15.0
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_z, 0.0 -> 15.0
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_y2, 0.0 -> 15.0
03:33:16 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1959:Changing parameter: lineEdit_x, 0.0 -> 15.0
03:33:19 PM:INFO:move_worker:move_worker.py:move_absolute:line 307:(move absolute): Moved motors from [12000, 12000, 0, 0] to [12000, 12000, 12000, 12000]
03:33:46 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 913:Percentage of left lick intervals under 100 ms is 80.93%.
03:33:46 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 919:Percentage of right lick intervals under 100 ms is 73.28%.
03:33:46 PM:INFO:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 926:Percentage of right and left lick intervals under 100 ms is 78.38%.
03:33:46 PM:ERROR:MyFunctions:MyFunctions.py:calculate_inter_lick_intervals:line 930:Percentage of same side lick intervals under 100 ms in Box 4D mouse 1 exceeded 10%
@alexpiet alexpiet added the low priority - auto-generated autogenerated issues that have only occurred once label Dec 10, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
low priority - auto-generated autogenerated issues that have only occurred once
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@alexpiet