klabhub / neurostim

Design and run visual neuroscience experiments using Matlab and the Psychophysics Toolbox.
MIT License
5 stars 4 forks source link

Timing delays: cause found. #50

Closed adammorrissirrommada closed 8 years ago

adammorrissirrommada commented 8 years ago

@bartkrekelberg I've found a cause (and possible solution) of major delays, related to how Matlab deals with handles/pointers. In many of the existing demos, it takes 2.5ms just to read the x and y properties of o.cic.eye in the fixate.m plugin. It turns out that it takes over 1ms to read any property of a plugin that was added during the myRig stage (i.e. from a cic object that was first created in myRig and then returned to the main experiment script).

I've added a short script (testingGetDelay.m) that demonstrates the problem, and a possible solution. It reports the latency of property gets under a few different scenarios. Pay close attention to the output written to the command window.

What are your thoughts?

adammorrissirrommada commented 8 years ago

This is the output of the script on my machine:

*\ Approach 1 (cic and plugin created locally): Time (ms) per get (local pointer) = 0.00090557 Time (ms) per get (cic's pointer) = 0.025658

*\ Approach 2 (cic with plugin returned by a function call, as in myRig): Time (ms) per get (cic's pointer) = 1.1404

*\ Approach 3 (return local pointer from function call): Time (ms) per get ("local" pointer) = 0.00090557 Time (ms) per get (cic's pointer) = 0.02596 Note: in approach 3, the cic's pointer is now fast, just by the presence of the "local" pointer.

adammorrissirrommada commented 8 years ago

it seems similar to this in some way:

http://au.mathworks.com/matlabcentral/newsreader/view_thread/268466

Not sure if it is perhaps related to the circular references between cic and plugin handles? i.e., c.eye.cic.eye.cic.eye.cic.... etc.

jonaskn commented 8 years ago

just a little aside.

The reason that I am not using any handles for my parameters (and did did not go full class based) in my stimulus system (casual PLDAPS) is that I had speed issues just like that. Parameters were/are stored in a struct and if any subfield in that struct had a function handle, everything got slow.

Having handles in other fields of the class was usually not problem if they were not touched too much, but I did not explore that too much. given handle class p p.parametersStruct <-not handles p.functionHandles <-a few handles

accessing p.parametersStruct was still fast for me. Don’t know if that helps.

I pretty much only use function string and str2func whenever I need to.

It’s a shame because when I switched to Matlab I thought that doing the function relationships should be way easier that in neurostim…

jonas

On Jul 9, 2016, at 12:57 AM, adammorrissirrommada notifications@github.com wrote:

it seems similar to this in some way:

http://au.mathworks.com/matlabcentral/newsreader/view_thread/268466

Not sure if it is perhaps related to the circular references between cic and plugin handles? i.e., c.eye.cic.eye.cic.eye.cic.... etc.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or mute the thread.

bartkrekelberg commented 8 years ago

On my system:

* Approach 1 (cic and plugin created locally): Time (ms) per get (local pointer) = 0.0021994 Time (ms) per get (cic's pointer) = 0.020894 * Approach 2 (cic with plugin returned by a function call, as in myRig): Time (ms) per get (cic's pointer) = 0.020161 *\ Approach 3 (return local pointer from function call): Time (ms) per get ("local" pointer) = 0.0021994 Time (ms) per get (cic's pointer) = 0.02126 Note: in approach 3, the cic's pointer is now fast, just by the presence of the "local" pointer.

Still a big difference between local and cic but they are all very small .

I am using

MATLAB Version: 9.0.0.341360 (R2016a) MATLAB License Number: 354167 Operating System: Microsoft Windows 10 Pro Version 10.0 (Build 10586)

Java Version: Java 1.7.0_60-b19 with Oracle Corporation Java HotSpot(TM) 64-Bit Server VM mixed mode

Maybe the issue with Approach 2 has been fixed in the R2016a?

adammorrissirrommada commented 8 years ago

ooh... that would be wonderful if the solution is that simple! I'll try that myself at some point and report back. How long ago did you make the switch? This probably also explains why I was having more timing issues than you on other occasions.

adammorrissirrommada commented 8 years ago

Thanks for your input also @jonaskn . Sounds like a similar issue. We also found that Matlab evaluated all functions that were nested in a structure every time any field of the structure was read... strange behaviour.

adammorrissirrommada commented 8 years ago

I just updated to 2016a and yep, problem solved! The release notes for 2015b say "New execution engine that runs MATLAB code faster". Maybe that's it...

jonaskn commented 8 years ago

That would be great. I also quickly did a test on an at least related speed issue with function handles and handle classes that I used to have on 2014b (A breakpoint anywhere before executed code would slow down access to the struct with function handles by a factor of ~2000). And that seems to be solved in 2015b too. (All on OSX)

Probably the same issue I wrote about before, never really got to the bottom of that.

On 12/07/16 20:27, adammorrissirrommada wrote:

I just updated to 2016a and yep, problem solved! The release notes for 2015b say "New execution engine that runs MATLAB code faster". Maybe that's it...

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/klabhub/neurostim-ptb/issues/50#issuecomment-232229847, or mute the thread https://github.com/notifications/unsubscribe/ADoGTK2efs68QY3Agl06oY7agd7UtanJks5qVD8BgaJpZM4JIhWC.

adammorrissirrommada commented 8 years ago

I profiled a short run of behaviorDemo and the ordered list of chain-draggers is very different now, and frame-loops overall are much faster. Hooray!

I now wonder whether structures with dynamic properties would be possible...