Long saving times

Lindsey's Avatar

Lindsey

19 Nov, 2019 02:48 PM

This comment was split from the discussion: Long saving time

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.

  1. Support Staff 1 Posted by Christopher Sta... on 19 Nov, 2019 02:55 PM

    Christopher Stawarz's Avatar

    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

  2. 2 Posted by Lindsey Glickfe... on 19 Nov, 2019 05:01 PM

    Lindsey Glickfeld's Avatar

    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.

  3. Support Staff 3 Posted by Christopher Sta... on 19 Nov, 2019 07:01 PM

    Christopher Stawarz's Avatar

    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

  4. 4 Posted by Lindsey Glickfe... on 19 Nov, 2019 08:05 PM

    Lindsey Glickfeld's Avatar

    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.

  5. Support Staff 5 Posted by Christopher Sta... on 20 Nov, 2019 03:15 PM

    Christopher Stawarz's Avatar

    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

  6. 6 Posted by Lindsey Glickfe... on 20 Nov, 2019 06:28 PM

    Lindsey Glickfeld's Avatar

    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.

  7. Support Staff 7 Posted by Christopher Sta... on 20 Nov, 2019 08:17 PM

    Christopher Stawarz's Avatar

    Great! Thanks for letting me know.

    Chris

  8. Christopher Stawarz closed this discussion on 22 Nov, 2019 04:00 PM.

Comments are currently closed for this discussion. You can start a new one.

Keyboard shortcuts

Generic

? Show this help
ESC Blurs the current field

Comment Form

r Focus the comment reply box
^ + ↩ Submit the comment

You can use Command ⌘ instead of Control ^ on Mac