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

trial stalled 5 minutes, user continued trials #761

Open
alexpiet opened this issue Oct 7, 2024 · 3 comments
Open

trial stalled 5 minutes, user continued trials #761

alexpiet opened this issue Oct 7, 2024 · 3 comments
Labels
high priority - auto-generated autogenerated issues that have occurred > 3 times in a month

Comments

@alexpiet
Copy link
Collaborator

alexpiet commented Oct 7, 2024

This issue was automatically generated from GUI logs.

file: Foraging.py
function: _StartTrialLoop
line 4263
logfile: W10DT714671/W10DT714671-A_gui_log_2024-10-04_08-59-25.txt
boxes: 1C, 2C, 6A, 6B, 7C, 7D, ephys1
count: 7
text: trial stalled 5 minutes, user continued trials


Log context

10:34:49 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11488817.066176, '127.0.0.1', 4003]
10:34:49 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11488817.094848, '127.0.0.1', 4003]
10:34:49 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11488817.28208, '127.0.0.1', 4003]
10:34:49 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11488817.488224, '127.0.0.1', 4003]
10:35:06 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11488833.674528, '127.0.0.1', 4003]
10:35:06 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11488833.93664, '127.0.0.1', 4003]
10:36:52 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11488939.718784, '127.0.0.1', 4003]
10:36:52 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11488939.912288, '127.0.0.1', 4003]
10:37:14 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11488962.198944, '127.0.0.1', 4003]
10:38:12 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489020.053376, '127.0.0.1', 4003]
10:38:12 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11489020.24608, '127.0.0.1', 4003]
10:38:12 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11489020.462816, '127.0.0.1', 4003]
10:40:20 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489147.858592, '127.0.0.1', 4003]
10:40:20 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489148.055264, '127.0.0.1', 4003]
10:40:20 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489148.251488, '127.0.0.1', 4003]
10:40:23 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489150.713408, '127.0.0.1', 4003]
10:40:45 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489172.93056, '127.0.0.1', 4003]
10:40:45 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489173.148, '127.0.0.1', 4003]
10:40:45 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489173.359168, '127.0.0.1', 4003]
10:41:12 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 11489200.24736, '127.0.0.1', 4003]
10:41:12 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489200.48048, '127.0.0.1', 4003]
10:41:13 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489200.705664, '127.0.0.1', 4003]
10:41:13 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489200.712992, '127.0.0.1', 4003]
10:41:19 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489206.966592, '127.0.0.1', 4003]
10:41:19 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489207.342976, '127.0.0.1', 4003]
10:41:19 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489207.364352, '127.0.0.1', 4003]
10:43:09 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489317.435744, '127.0.0.1', 4003]
10:43:09 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489317.622944, '127.0.0.1', 4003]
10:43:12 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 11489320.454464, '127.0.0.1', 4003]
10:45:11 AM:ERROR:Foraging:Foraging.py:_StartTrialLoop:line 4263:trial stalled 5 minutes, user continued trials
@alexpiet
Copy link
Collaborator Author

This issue reoccurred:

file: Foraging.py
function: _StartTrialLoop
line 4282
logfile: W10DT714683/W10DT714683-C_gui_log_2024-10-10_08-56-15.txt
boxes: 7C, 7D
count: 2
text: trial stalled 5 minutes, user continued trials


Log context


09:59:59 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/DelayStartTime', 8694460.362976, '127.0.0.1', 4022]
09:59:59 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 8694460.366496, '127.0.0.1', 4022]
10:00:00 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 8694461.345984, '127.0.0.1', 4022]
10:00:00 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 8694461.346208, 4, '127.0.0.1']
10:00:00 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 8694461.350496, '127.0.0.1', 4022]
10:00:01 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694461.46912, '127.0.0.1', 4023]
10:00:01 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 8694461.468992, '127.0.0.1', 4022]
10:00:01 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'ErrorLeft', '127.0.0.1', 4022]
10:00:01 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694461.59344, '127.0.0.1', 4023]
10:00:01 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694461.750528, '127.0.0.1', 4023]
10:00:01 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694461.915648, '127.0.0.1', 4023]
10:00:04 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 8694464.48, '127.0.0.1', 4022]
10:00:04 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 8694464.482496, '127.0.0.1', 4022]
10:00:06 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694466.758976, '127.0.0.1', 4023]
10:00:06 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694466.897632, '127.0.0.1', 4023]
10:00:06 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694467.047296, '127.0.0.1', 4023]
10:00:24 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694484.45328, '127.0.0.1', 4023]
10:00:24 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694484.656736, '127.0.0.1', 4023]
10:02:55 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 8694635.65152, '127.0.0.1', 4023]
10:02:55 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 8694635.8776, '127.0.0.1', 4023]
10:02:58 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694639.30512, '127.0.0.1', 4023]
10:06:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694852.407968, '127.0.0.1', 4023]
10:06:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RightLickTime', 8694852.408032, '127.0.0.1', 4023]
10:06:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694852.602368, '127.0.0.1', 4023]
10:06:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694852.787616, '127.0.0.1', 4023]
10:06:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694852.956384, '127.0.0.1', 4023]
10:06:39 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694860.016672, '127.0.0.1', 4023]
10:06:39 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 8694860.197984, '127.0.0.1', 4023]
10:06:43 AM:ERROR:Foraging:Foraging.py:_StartTrialLoop:line 4282:trial stalled 5 minutes, user continued trials

@alexpiet
Copy link
Collaborator Author

This issue reoccurred:

file: Foraging.py
function: _StartTrialLoop
line 4282
logfile: W10DT714683/W10DT714683-C_gui_log_2024-10-17_08-53-20.txt
boxes: 3B, 7A, 7C, ephys1
count: 4
text: trial stalled 5 minutes, user continued trials


Log context

10:27:31 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 9300911.818496, '127.0.0.1', 4022]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTime', 9300912.798976, '127.0.0.1', 4022]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/GoCueTimeSoundCard', 9300912.802304, 4, '127.0.0.1']
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 9300912.802496, '127.0.0.1', 4022]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300912.947872, '127.0.0.1', 4023]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTime', 9300912.946976, '127.0.0.1', 4023]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcomeTime', 9300912.946976, '127.0.0.1', 4022]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/EarnedLeftWaterStartTime', 9300912.946976, '127.0.0.1', 4023]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/RewardOutcome', 'RewardLeft', '127.0.0.1', 4022]
10:27:32 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftRewardDeliveryTimeHarp', 9300912.950496, '127.0.0.1', 4023]
10:27:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300913.04096, '127.0.0.1', 4023]
10:27:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300913.315712, '127.0.0.1', 4023]
10:27:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300913.436672, '127.0.0.1', 4023]
10:27:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300913.564768, '127.0.0.1', 4023]
10:27:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300913.696032, '127.0.0.1', 4023]
10:27:33 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300913.850688, '127.0.0.1', 4023]
10:27:34 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300914.119232, '127.0.0.1', 4023]
10:27:34 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300914.27728, '127.0.0.1', 4023]
10:27:34 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300914.408256, '127.0.0.1', 4023]
10:27:34 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300914.711392, '127.0.0.1', 4023]
10:27:34 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300914.868288, '127.0.0.1', 4023]
10:27:35 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300915.79472, '127.0.0.1', 4023]
10:27:35 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/TrialEndTime', 9300915.948992, '127.0.0.1', 4022]
10:27:35 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/BehaviorEvent', 9300915.951488, '127.0.0.1', 4022]
10:27:52 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300932.087552, '127.0.0.1', 4023]
10:27:52 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300932.247296, '127.0.0.1', 4023]
10:27:52 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300932.391392, '127.0.0.1', 4023]
10:27:52 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300932.56224, '127.0.0.1', 4023]
10:27:52 AM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 9300932.702336, '127.0.0.1', 4023]
10:34:16 AM:ERROR:Foraging:Foraging.py:_StartTrialLoop:line 4282:trial stalled 5 minutes, user continued trials

@alexpiet
Copy link
Collaborator Author

This issue reoccurred:

file: Foraging.py
function: _StartTrialLoop
line 4282
logfile: W10DT713669/W10DT713669-A_gui_log_2024-10-21_16-50-24.txt
boxes: ephys1
count: 2
text: trial stalled 5 minutes, user continued trials


Log context

04:59:58 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=249724 fps=501 q=19.0 size= 3063412kB time=00:08:19.44 bitrate=50246.4kbits/s speed=   1x
04:59:58 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=249980 fps=501 q=19.0 size= 3066228kB time=00:08:19.95 bitrate=50241.3kbits/s speed=   1x
04:59:58 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=249980 fps=501 q=25.0 size= 3066986kB time=00:08:19.95 bitrate=50253.7kbits/s speed=   1x
04:59:59 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=250236 fps=501 q=19.0 size= 3069044kB time=00:08:20.47 bitrate=50235.8kbits/s speed=   1x
04:59:59 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=250236 fps=501 q=25.0 size= 3070058kB time=00:08:20.47 bitrate=50252.4kbits/s speed=   1x
04:59:59 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=250493 fps=501 q=19.0 size= 3071860kB time=00:08:20.98 bitrate=50230.3kbits/s speed=   1x
04:59:59 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=250493 fps=501 q=25.0 size= 3072874kB time=00:08:20.98 bitrate=50246.9kbits/s speed=   1x
05:00:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814766.888928, '127.0.0.1', 4003]
05:00:00 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=250757 fps=501 q=26.0 size= 3076458kB time=00:08:21.51 bitrate=50252.5kbits/s speed=   1x
05:00:00 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=250757 fps=501 q=21.0 size= 3075956kB time=00:08:21.51 bitrate=50244.3kbits/s speed=   1x
05:00:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814767.03216, '127.0.0.1', 4003]
05:00:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814767.225568, '127.0.0.1', 4003]
05:00:00 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814767.388896, '127.0.0.1', 4003]
05:00:00 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251012 fps=501 q=22.0 size= 3080564kB time=00:08:22.02 bitrate=50268.5kbits/s speed=   1x
05:00:00 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251012 fps=501 q=26.0 size= 3081066kB time=00:08:22.02 bitrate=50276.7kbits/s speed=   1x
05:00:01 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251269 fps=501 q=25.0 size= 3084906kB time=00:08:22.53 bitrate=50287.8kbits/s speed=   1x
05:00:01 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251269 fps=501 q=20.0 size= 3084148kB time=00:08:22.53 bitrate=50275.5kbits/s speed=   1x
05:00:01 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251524 fps=501 q=27.0 size= 3088490kB time=00:08:23.04 bitrate=50295.2kbits/s speed=   1x
05:00:01 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251524 fps=501 q=21.0 size= 3087476kB time=00:08:23.04 bitrate=50278.7kbits/s speed=   1x
05:00:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814768.656832, '127.0.0.1', 4003]
05:00:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814768.799712, '127.0.0.1', 4003]
05:00:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814769.031616, '127.0.0.1', 4003]
05:00:02 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251784 fps=501 q=26.0 size= 3092330kB time=00:08:23.56 bitrate=50305.8kbits/s speed=   1x
05:00:02 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=251784 fps=501 q=21.0 size= 3091572kB time=00:08:23.56 bitrate=50293.4kbits/s speed=   1x
05:00:02 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814769.197088, '127.0.0.1', 4003]
05:00:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814769.556096, '127.0.0.1', 4003]
05:00:03 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=252044 fps=501 q=27.0 size= 3096170kB time=00:08:24.08 bitrate=50316.3kbits/s speed=   1x
05:00:03 PM:INFO:Foraging:Foraging.py:log_subprocess_output:line 4759:BONSAI: frame=252044 fps=501 q=21.0 size= 3095412kB time=00:08:24.08 bitrate=50303.9kbits/s speed=   1x
05:00:03 PM:INFO:rigcontrol:rigcontrol.py:msg_handler:line 56:['/LeftLickTime', 1814769.711616, '127.0.0.1', 4003]
05:00:03 PM:ERROR:Foraging:Foraging.py:_StartTrialLoop:line 4282:trial stalled 5 minutes, user continued trials

@ellahiltonvano ellahiltonvano added the high priority - auto-generated autogenerated issues that have occurred > 3 times in a month label Oct 24, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
high priority - auto-generated autogenerated issues that have occurred > 3 times in a month
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@alexpiet @ellahiltonvano