Inquisit timing accuracy.


Author
Message
seandr
seandr
Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)
Group: Administrators
Posts: 1.3K, Visits: 5.6K

Wonderful feature, too bad this isn't mentioned anywhere in the docs...;-)


That's because it's still a little rough around the edges and somewhat incomplete. Besides, secret features add a sense of mystery to a product. [H]


-Sean



seandr
seandr
Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)
Group: Administrators
Posts: 1.3K, Visits: 5.6K

Yes, since that old build, I added some optimizations in the way that Inquisit synchronizes with the refresh cycle to erase stimuli, as I recall. The previous behavior could insert some time in between trials.


-Sean


Dave
Dave
Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)
Group: Administrators
Posts: 12K, Visits: 97K

Yes, since that old build, I added some optimizations in the way that Inquisit synchronizes with the refresh cycle to erase stimuli, as I recall. The previous behavior could insert some time in between trials.


Interesting info, thanks. However, things go seriously kerfuffle on my system if I set the posttrialpause to be zero. Seems like Inquisit needs at least two frames for cleanup at the end of any given trial. So there might be room for further improvement. What happens on your systems when you run the test script with posttrialpause = 0?


That's because it's still a little rough around the edges and somewhat
incomplete. Besides, secret features add a sense of mystery to a
product.


LOL.


~Dave


Dave
Dave
Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)
Group: Administrators
Posts: 12K, Visits: 97K

Oh, btw, while coming up with the time auditing bits for the test script I also briefly experimented with the stimulusonset property (e.g. '/ ontrialend = values.myonset = shape.green_circle.stimulusonset.1'). However, the returned value always appeared to be empty. Any hint?


Thanks,


~Dave


seandr
seandr
Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)
Group: Administrators
Posts: 1.3K, Visits: 5.6K

A little more info on the timing optimization - there were circumstances in which Inquisit would resynchronize with the vertical retrace rate more than one time while erasing stimuli - i.e., it would wait for the paint cycle to start, erase a stimulus, then wait for the next paint cycle to start, erase the next stimulus, etc. The fix ensure that it would only wait for 1 paint cycle before erasing all stimuli (which means there still may be a delay between trials, but it will usually smaller than before).


A posttrialpause gives Inquisit a fixed time buffer after the trial to erase stimuli and do some other minor cleanup. With a posttrialpause defined, you shouldn't see any delay from erasing stimuli. Without the posttrialpause, I would expect to see some small delays.


As for pretrialpause, that should not affect the overall length of a trial who's trialduration is set to a fixed value. However, it could push stimulus presentation back if preparing the stimuli requires some time. In most cases, we're talking a few milliseconds to prepare a stimulus, but it could become significant on a slow machine with lots of stimuli.


Hope this clarifies things.


-Sean


Dave
Dave
Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)
Group: Administrators
Posts: 12K, Visits: 97K

A posttrialpause gives Inquisit a fixed time buffer after the trial to erase stimuli and do some other minor cleanup. With a posttrialpause defined, you shouldn't see any delay from erasing stimuli. Without the posttrialpause, I would expect to see some small delays.


Sorry to keep dragging this on, but I'd like to point out that all stims in the testscript are set to '/erase=false', i.e. Inquisit shouldn't have to erase anything ever. The only thing remaining is the "other minor cleanup" (resetting trial properties and such, I assume). And yet -- with posttrialpause=0 -- approx. 2 additional frames are added to each trial. Granted, I'd also expect some (very) small delays for the minor cleanup, but I don't see why this should take 2 frames (~34 ms) because there is no screen / display erasing involved whatsoever. Considering the sheer number of processor and memory operations modern PCs can perform within microseconds, I'd expect the minor cleanup to be virtually undetectable. I definitely don't understand why it adds 2 frames (even one frame would be too much, IMO). Any input is greatly appreciated!


~Dave


P.S.: As mentioned previously, I think there may be a bug involving the 'stimulusonset' property: 'shape.myshape.stimulusonset.1' always returns an empty value on my system (Inquisit 3.0.5.0), despite the stimulus having been displayed and thus having an onset to report.


seandr
seandr
Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)
Group: Administrators
Posts: 1.3K, Visits: 5.6K

I've tested the script with /postrialpause=0 and am seeing intermittent delays between 30-34 ms.


Any resemblance these numbers have to the refresh rate is purely coincidental given that there is no stimulus erasure happening with your test script. At the end of the trial, Inquisit does a few things, including:


1) Captures the screen and saves it to disk (if applicable)
2) Erase stimuli and show feedback stimuli (if applicable)
3) Update stats for the expt, block, and trial
4) Evaluates any /ontrialend expressions
5) Writes trial data to the file
6) Erases any feedback stimuli (if applicable)
7) Releases any video memory used by shapes or pictures (if applicable)
8) Clear any pending input messages from the relevant response buffer


The only item in this list that could possibly require 30ms is 5 - writing the data to disk. Sure enough, when I removed the /audit command from the <data> element and replaced it with /separatefiles=true (which causes Inquisit to save the data in memory and then write it all at once to disk at the end of the experiment), the 30ms delay goes away. I'd love to know if you see the same thing.


Anyway, I think we have our culprit - disk access.


-Sean


Dave
Dave
Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)
Group: Administrators
Posts: 12K, Visits: 97K

Hi Sean,


many thanks for giving this another look and your detailed response. Here are my observations as requested:


(1) / audit = true had nothing to do with my initial observation. In fact I never even ran the script with auditing turned on.


(2) / separatefiles = true doesn't resolve the issue for me. In fact it makes the delay even worse (~45ms mean).


Thanks again,


~Dave


P.S.: Can you replicate the empty stimulusonset property issue?


Dave
Dave
Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)Supreme Being (1M reputation)
Group: Administrators
Posts: 12K, Visits: 97K

A couple of more observations from tests conducted today:


- Even setting recorddata=false to prevent disc access does not resolve the issue for me. While the delay is somewhat reduced, there are still approx. 33ms added to each trial.


- Unrelated to the timing issue: recorddata doesn't seem to work when set at the <expt> level.


~Dave


seandr
seandr
Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)Supreme Being (140K reputation)
Group: Administrators
Posts: 1.3K, Visits: 5.6K

Weird. I've run the test several more times with both data recording and auditing turned on, and I'm seeing trial durations all in the range of 1000-1001 ms. I've run the test on a fast and slow machine with the same results. I can't even reproduce the delays I initially saw, and I'm actually thinking those resulted from me running the tests using a debug build with the debugger attached.


Just to make sure we are looking at the same numbers, I'm looking at the "Difference" value as a measure of the trial duration - is that what you are looking at?


-Sean




GO

Merge Selected

Merge into selected topic...



Merge into merge target...



Merge into a specific topic ID...




Reading This Topic

Explore
Messages
Mentions
Search