Long saving times

Hi Chris,
We have been having issues with long saving times as well. This is worse when trials are longer (e.g. if the mouse doesn’t respond for an extended period), is particularly bad for experiments where we are collecting inputs with high temporal resolution (as from an encoder using quadrature- although there don’t have to be changes in input for it to be a problem- just a long duration of monitoring), and seems to have gotten worse with more recent builds off MWorks. Do you have suggestions for what we can do to troubleshoot this issue? Please let me know what other information would be helpful.
Thanks,
Lindsey.

Hi Lindsey,

To start, can you describe the problem in more detail? What are the symptoms that led you to conclude that event files are taking a long time to save?

seems to have gotten worse with more recent builds off MWorks

Can you be more specific here? In what version(s) of MWorks have you noticed this issue?

Also, on one of the machines running MWServer that exhibits this problem, can you please run the following command in Terminal and send me the output?

system_profiler SPSoftwareDataType SPHardwareDataType SPDisplaysDataType SPStorageDataType

Thanks,
Chris

Hi Chris,

The Matlab window has information about the number of events that need to
be processed. Typically this fluctuates between 0 and 1 as events occur
and are saved. However, when events are taking extra time to save (often on
long trials) the number of events climbs sometimes up to 50 or 100 trials.
If I quit out of Mworks before these events have been processed, they are
not in my saved mat file.

This issue seems to happen most often on Version 0.8.dev-20171117,
sometimes with Version 0.9.dev (2019.04.24), and less often with Version
0.6 (c1863e7). This is tricky because we have different versions on
different rigs with different mice (that are more or less likely to have
long reaction times), and different experiments that collect different
amounts of data. For instance, it is particularly bad on our two-photon rig
where we’re collecting both the behavioral output (with all of the
quadrature data) as well as the counter output to sync with the microscope
frame rate (at 30 Hz). We recently updated this rig to 0.8 (from 0.6) and
this is when I first noticed the issue with events piling up.

The log below is from an experiment running on 0.8 that has the quadrature
output but not the microscope frame rate. It was ~13 events behind when we
queried the terminal.

Thanks,
Lindsey.

Hi Lindsey,

Thanks for all the additional info.

The Matlab window has information about the number of events that need to be processed. Typically this fluctuates between 0 and 1 as events occur and are saved. However, when events are taking extra time to save (often on long trials) the number of events climbs sometimes up to 50 or 100 trials.

Just to be clear up front, the issue you’re describing is completely unrelated to Beshoy’s problem. The situation there involves an unexplained backup in writing to the MWorks event file. It has nothing to do with MWClient’s MATLAB window.

The problem you’re having sounds similar to one that Andrew McKinney dealt with several years ago. In that case, the root issue was that the MWorks experiment was generating so many events that the MATLAB script simply couldn’t keep up, leading to steady growth in the number of events waiting to be processed. I suspect this is also the cause of your current problem.

If this issue is more acute on some of your setups, my guess is that those setups have CPU’s that are underpowered relative to their peers. (A MATLAB script will start falling behind when it’s utilizing 100% of a CPU core, so a core with fewer cycles to spare is going to max out sooner.) However, if the hardware on all of your setups is identical, then this probably isn’t the case.

If I quit out of Mworks before these events have been processed, they are not in my saved mat file.

Right, because your MATLAB script simply hasn’t gotten to them yet.

If you’d like, you can send me your experiment file, and I’ll see if I can find any event-generating “hot spots” similar to the one that caused problems in Andrew’s protocol.

Cheers,
Chris

Hi Chris,
It is possible that the problem is all within the Matlab processing.
However, I was wondering if Matlab could be stalling because the MWorks
event file is behind as well? Is there a way to diagnose this?
Hardware is pretty similar across rigs- I don’t think this can explain
anything.
But, if there is a way to clean up my experiment, that would be great.
I’ve attached the experiment that is the most problematic.
Lindsey.

Hi Lindsey,

However, I was wondering if Matlab could be stalling because the MWorks event file is behind as well? Is there a way to diagnose this?

I guess that’s possible, though I think it’s unlikely. The observable symptoms of writes to the MWorks event file falling behind depend on the MWorks version:

  • Pre-0.9: The event file will be missing events from the end of the experiment.
  • 0.9: The event file will take a long time to close. This comment explains how to detect this scenario.

I’ve attached the experiment that is the most problematic.

Looking at your experiment, I believe you’re seeing exactly the same issue that Andrew had.

The problem is in state “Reaction”. At the end of its transition list, it has a direct transition back to itself (line 1679 in the XML):

<transition type="direct" target="Reaction"></transition>

Because of this direct transition, the state executes repeatedly, without pause, burning as many CPU cycles as the OS will give it, until one of the other transitions succeeds. In turn, this means that any variable assignments made in the action section of the state are also made repeatedly. If any of these variables are sent to your MATLAB script, then the script will be inundated with events for as long as the experiment is in state “Reaction”.

Luckily, the solution is simple: “Reaction” needs to pause before transitioning back to itself. It can be a very short pause (500 microseconds would be my suggestion). Here’s how you can implement this:

  1. At the end of the state’s actions (i.e. right before the transition_marker element), start a timer:

     <action type="start_timer" timer="idleTimer" timebase="" duration="500" duration_units="us"/>
    
  2. Replace the direct transition back to Reaction with a timer_expired transition:

     <transition type="timer_expired" timer="idleTimer" target="Reaction"></transition>
    

I’ve attached a modified version of your experiment that contains these changes.

If my diagnosis is correct, this should eliminate the backup in MATLAB event processing. If it doesn’t, please let me know, and we’ll investigate further.

Cheers,
Chris

Chris,
This fixed it- I increased the delay timer to 10ms to get rid of all
backup, but now it seems to work smoothly. Thanks!
Lindsey.

Great! Thanks for letting me know.

Chris