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.

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

FATAL:json.decoder.JSONDecodeError: Expecting ',' delimiter: line 38728 column 13 (char 583263) #1104

Open
alexpiet opened this issue Dec 2, 2024 · 1 comment
Assignees
Labels
low priority - auto-generated autogenerated issues that have only occurred once

Comments

@alexpiet
Copy link
Collaborator

alexpiet commented Dec 2, 2024

This issue was automatically generated from GUI logs.

file: Foraging.py
function: exception_hook
line 4769
logfile: W10DT714688/W10DT714688-D_gui_log_2024-11-27_16-06-17.txt
boxes: 8D
count: 3
text: FATAL:json.decoder.JSONDecodeError: Expecting ',' delimiter: line 38728 column 13 (char 583263)

GUI Log snippet (click for full log)

04:30:18 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3428:Checking that photometry is not running
04:30:18 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3438:Photometry excitation stopped
04:30:18 PM:INFO:Foraging:Foraging.py:_NewSession:line 3561:New Session complete
04:30:18 PM: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 38728 column 13 (char 583263)
Full GUI log
04:06:17 PM:INFO:Foraging:Foraging.py:start_gui_log_file:line 4661:Starting logfile!
04:06:17 PM: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)]
04:06:17 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4689:Current git commit branch, hash: main, 1a7c9d3d1aa10284caed44ba9b223c6bfbb8ff5f
04:06:17 PM:INFO:Foraging:Foraging.py:log_git_hash:line 4693:Current foraging_gui version: 1.6.10
04:06:17 PM:WARNING:Foraging:Foraging.py:log_git_hash:line 4703:local repository is clean
04:06:17 PM:INFO:Foraging:Foraging.py:<module>:line 4804:Setting QApplication attributes
04:06:17 PM:INFO:Foraging:Foraging.py:<module>:line 4812:Starting QApplication and Window
04:06:17 PM:INFO:Foraging:Foraging.py:__init__:line 69:Creating Window
04:06:17 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1174:Loaded settings_box file
04:06:17 PM:INFO:Foraging:Foraging.py:_GetSettings:line 1202:Loaded settings file
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (FIP_settings), using default: C:\Users\svc_aind_behavior\Documents\FIPSettings
04:06:17 PM: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
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (metadata_dialog_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\metadata_dialog\
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (rig_metadata_folder), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\rig_metadata\
04:06:17 PM: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
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (schedule_path), using default: Z:\dynamic_foraging\DynamicForagingSchedule.csv
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (go_cue_decibel_box1), using default: 60
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (go_cue_decibel_box2), using default: 60
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (go_cue_decibel_box3), using default: 60
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box1), using default: 5000
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box2), using default: 5000
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box3), using default: 5000
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (lick_spout_distance_box4), using default: 5000
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (name_mapper_file), using default: C:\Users\svc_aind_behavior\Documents\ForagingSettings\name_mapper.json
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (create_rig_metadata), using default: True
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (save_each_trial), using default: True
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (AutomaticUpload), using default: True
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (manifest_flag_dir), using default: C:\Users\svc_aind_behavior\Documents\aind_watchdog_service\manifest
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (auto_engage), using default: True
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (clear_figure_after_save), using default: True
04:06:17 PM:WARNING:Foraging:Foraging.py:_GetSettings:line 1212:Missing setting (add_default_project_name), using default: True
04:06:17 PM:INFO:Foraging:Foraging.py:_LoadSchedule:line 1100:Loaded behavior schedule
04:06:17 PM:INFO:Foraging:Foraging.py:_GetWaterCalibration:line 1064:Loaded Water Calibration
04:06:17 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1534:Found existing rig.json: rig_446-8-D_2024-11-26_11_16_28.json
04:06:17 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 60:building rig json
04:06:17 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json_core:line 624:finished building rig json
04:06:17 PM:INFO:RigJsonBuilder:RigJsonBuilder.py:build_rig_json:line 53:Using existing rig json
04:06:17 PM:INFO:Foraging:Foraging.py:_LoadUI:line 275:Using ForagingGUI.ui interface
04:06:17 PM:INFO:Foraging:Foraging.py:__init__:line 119:Setting Window title: 446-8-D
04:06:17 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1371:Trying to connect to already running Bonsai
04:06:17 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
04:06:18 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1375:Could not connect: timed out
04:06:18 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1384:Starting Bonsai
04:06:18 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4776:BONSAI logging starting
04:06:19 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
04:06:20 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1398:Could not connect, total waiting time 0.5 seconds: timed out
04:06:20 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
04:06:21 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1398:Could not connect, total waiting time 1.0 seconds: timed out
04:06:22 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
04:06:22 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1401:Connected to Bonsai after 1.5 seconds
04:06:22 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1402:Bonsai started successfully
04:06:22 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1281:Attempting to connect to Slims
04:06:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 52:['/PhotometryFalling', 12342682.405536, '127.0.0.1', 4033], displaying at 0.5 Hz
04:06:22 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 12342682.413504, '127.0.0.1', 4033]
04:06:23 PM:INFO:Foraging:Foraging.py:_ConnectSlims:line 1298:Successfully connected to Slims
04:06:23 PM:WARNING:Dialogs:Dialogs.py:_LoadCalibrationParameters:line 480:could not find water calibration parameters: C:\Users\svc_aind_behavior\Documents\ForagingSettings\WaterCalibrationPar_4.json
04:06:23 PM:INFO:Foraging:Foraging.py:keyPressEvent:line 1863:processing parameter changes
04:06:23 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 875:Scanning for newscale stages
04:06:23 PM:INFO:Foraging:Foraging.py:_InitializeMotorStage:line 885:Could not find any instances of NewScale Stage
04:06:23 PM:INFO:Foraging:Foraging.py:_insert_stage_widget:line 255:Inserting Stage Widget
04:06:23 PM:INFO:connection:connection.py:_connect:line 688:Connecting to aibspi(10.128.108.106):2181, use_ssl: False
04:06:23 PM:INFO:client:client.py:_session_callback:line 561:Zookeeper connection established, state: CONNECTED
04:06:23 PM:INFO:connection:connection.py:_connect_attempt:line 655:Closing connection to aibspi:2181
04:06:23 PM:INFO:client:client.py:_session_callback:line 567:Zookeeper session closed, state: CLOSED
04:06:23 PM:INFO:stepper_motor_device:stepper_motor_device.py:__init__:line 68:Connected to COM4, device id: 1130
04:06:23 PM:INFO:stepper_motor_device:stepper_motor_device.py:load_registers:line 149:Getting available registers on device
04:06:23 PM:INFO:stage_model:stage_model.py:configure_device:line 81:Configuring registers with default values (can be modified in config file)
04:06:23 PM:INFO:move_worker:move_worker.py:goto_origin:line 194:(move to origin): Moving stage to origin
04:06:23 PM:INFO:move_worker:move_worker.py:move_relative:line 336:(move relative): Moved motors by steps specified in [0, -27200, -27200, 0]
04:06:23 PM:INFO:move_worker:move_worker.py:move_relative:line 336:(move relative): Moved motors by steps specified in [-27200, 0, 0, 0]
04:06:23 PM:INFO:move_worker:move_worker.py:move_relative:line 336:(move relative): Moved motors by steps specified in [0, 0, 0, -27200]
04:06:23 PM:INFO:stage_model:stage_model.py:configure_device:line 87:Zeroed all motor positions
04:06:23 PM:INFO:stage_model:stage_model.py:configure_device:line 88:Finished configuring stepper motor device
#############################################################
04:06:23 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3428:Checking that photometry is not running
04:06:23 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3438:Photometry excitation stopped
04:06:23 PM:INFO:Foraging:Foraging.py:_load_most_recent_rig_json:line 1534:Found existing rig.json: rig_446-8-D_2024-11-26_11_16_28.json
04:06:23 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 971:attempting to close bonsai connection
04:06:26 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 979:bonsai connection closed
04:06:26 PM:INFO:Foraging:Foraging.py:_ReconnectBonsai:line 981:attempting to restart bonsai
04:06:26 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1371:Trying to connect to already running Bonsai
04:06:26 PM:INFO:Foraging:Foraging.py:_ConnectOSC:line 1418:connecting to GUI and Bonsai through OSC
04:06:26 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1378:Connected to already running Bonsai
04:06:26 PM:INFO:Foraging:Foraging.py:_InitializeBonsai:line 1379:Bonsai started successfully
04:06:26 PM:INFO:Foraging:Foraging.py:__init__:line 219:Start up complete
04:06:27 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) = 5730
04:06:27 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) = 4265
04:06:28 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/
04:06:28 PM:INFO:curriculum_manager:curriculum_manager.py:download_curriculums:line 162:Found 26 curriculums in C:\Users\svc_aind_behavior/capsule/scratch/saved_curriculums/
04:06:28 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/
04:06:28 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/
04:06:28 PM:INFO:Dialogs:Dialogs.py:update_auto_train_fields:line 2273:No entry found in df_training_manager for subject_id: 0
04:06:28 PM:INFO:Dialogs:Dialogs.py:_override_curriculum_clicked:line 2621:Override stage clicked: state=2
04:06:28 PM:INFO:Dialogs:Dialogs.py:_update_stage_to_apply:line 2647:Current stage to apply: unknown training stage @unknown curriculum
04:12:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 12343023.090976, '127.0.0.1', 4033]
04:12:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 12343023.094496, '127.0.0.1', 4033]
04:12:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualLeftWaterStartTime', 12343028.780992, '127.0.0.1', 4033]
04:12:08 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 12343028.782496, '127.0.0.1', 4033]
04:12:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 12343029.576992, '127.0.0.1', 4033]
04:12:09 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 12343029.579488, '127.0.0.1', 4033]
04:12:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/ManualRightWaterStartTime', 12343034.638976, '127.0.0.1', 4033]
04:12:14 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightRewardDeliveryTimeHarp', 12343034.64048, '127.0.0.1', 4033]
04:29:58 PM:INFO:Foraging:Foraging.py:_StopCurrentSession:line 3581:Stopping current trials
04:30:18 PM:INFO:Foraging:Foraging.py:_Open:line 2948:Quick load success: C:\behavior_data\446-8-D\756567\behavior_756567_2024-11-26_16-38-38\behavior\756567_2024-11-26_16-38-38.json
04:30:18 PM:INFO:Foraging:Foraging.py:_NewSession:line 3491:New Session pressed
04:30:18 PM:INFO:Foraging:Foraging.py:_NewSession:line 3523:Resetting session run flag
04:30:18 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3428:Checking that photometry is not running
04:30:18 PM:INFO:Foraging:Foraging.py:_StopPhotometry:line 3438:Photometry excitation stopped
04:30:18 PM:INFO:Foraging:Foraging.py:_NewSession:line 3561:New Session complete
04:30:18 PM: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 38728 column 13 (char 583263)
@alexpiet alexpiet added the low priority - auto-generated autogenerated issues that have only occurred once label Dec 2, 2024
@alexpiet
Copy link
Collaborator Author

alexpiet commented Dec 3, 2024

Hey @micahwoodard this appears to be happening every few weeks. (https://github.com/AllenNeuralDynamics/dynamic-foraging-task/issues?q=is%3Aissue+FATAL%3Ajson.decoder.JSONDecodeError)
Do you have any idea what is happening? Maybe the saving process is getting interrupted?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
low priority - auto-generated autogenerated issues that have only occurred once
Projects
None yet
Development

No branches or pull requests

2 participants