Inconsistent timing of stimulus event code and photosensor

PTB: 3.0.19
Matlab R2022a
Linux Ubuntu 20.04
Stim timing issue: event code sometimes precedes visual stimulus, sometimes follows it.

Hello,

I was hoping someone might have some helpful insight regarding a timing issue we’re having with an EEG (Biosemi ActiveTwo) experiment. The experiment entails simple presentation of image files (jpg). To ensure accurate timing, we have a BlackBox Toolkit (BBTK) photosensor on the display screen detect a white box that is presented simultaneously with the stimulus.

We have found that the timing of the experiment is quite variable, and sometimes in completely perplexing ways. The code is written such that the stimulus screen is flipped to present the stimulus and white box, then the next line of code sends the stimulus to our Labjack device. The Labjack sends the digital event code to the BBTK, which then sends the code to our EEG acquisition system.This is a snippet of the relevant code:

    % Draw face frame
    Screen('FrameRect',winPt, [0, 0, 0], p.frameBox, frame_width);

    % Draw question prompt
    DrawFormattedText(winPt, line1,'center', p.centerY+200, white);

    % Draw white opto box
    Screen('FillRect', winPt, white, p.left_optoBox); % draw box for opto sensor
    Screen('FillRect', winPt, white, p.right_optoBox); % draw box for opto sensor

    % Draw stimulus (trialTex is defined at the start of the trial and pulled from a structure that contains all of the stimuli that were preloaded at the start of the experiment)
    Screen('DrawTexture',winPt,trialTex,[],p.stimBox);% draw texture data to create pictures
    Screen('DrawingFinished', winPt); % indicate drawing to the buffer is complete

    % Show the picture
    [stimOn_VBLTime(trial_n), stimOn_StimulusOnsetTime(trial_n), stimOn_FlipTimestamp(trial_n), stimOn_Missed(trial_n), stimOn_Beampos(trial_n)] = Screen('Flip', winPt, stimOn_sched(trial_n));
    lj.setDIO(imageID_dio); % send labjack code.

Given our code, we would expect to record the stimulus event code (e.g., “1”) followed ~8 ms later by the photosensor code (“512”). Note: though the code is written so that the image is flipped prior to the Labjack code being sent, we expect ~1/2 a refresh cycle (16.67 ms) to elapse before the optical sensor is trigged because the sensor is physically located halfway down the screen.

The timing described above is what we see for several of our participants. However, for many others there is a longer delay (20-35 ms) between the timestamps of the Labjack event code and the optical sensor code. I thought that this was most likely due to a computer slowdown that caused the flip to be delayed by a refresh cycle or two. However, the latency is not always a multiple of the refresh rate and the delay is more or less consistent for a given participant. That is, when the latency is longer than expected, it’s generally the same longer latency for all trials for that participant. Moreover, for some participants the optical code appears simultaneously with the Labjack code, or for some other participants even several ms prior(!?). Again, these latency differences occur almost entirely across participants. Within a given participant the timing is usually pretty consistent; albeit consistently perplexing.

If anyone has any thoughts or is intrigued by the issue, I’d be happy to share additional info (e.g, timing files, our full PTB code)

Thanks very much in advance!
-Andrew

It is expected that the event code sent by Labjack is earlier than the light signal detected by the photosensor, simply because the monitor has a delay to display.

As long as the delay is kind of fixed, you can take the delay into account during your data analysis. The weird thing is that it is different from participant to participant. However, if the difference is only several ms, it should not be a concern, given the location of the photosensor can cause that kind of difference, especially if you re-attach the photosensor for each participant.

Hope this helps. -Xiangrui

HI Xiangrui,

Thanks very much for you quick reply. I agree that we should expect the event code earlier than the photosensor for the reason you noted: the photosensor won’t be activated until the refresh cycle reaches its physical location on the screen. In our case, we’d expect that latency to be approximately 8 ms because we have a 60 Hz refresh rate and have the photosensor placed in the vertical midpoint of the screen. Our concern stems from the variability of the observed latency; that for some participants we detect the photosensor up to 5 ms before the labjack event code.

I understand that the computer might get bogged down with low-level “behind the scenes” processes which could affect timing, but can’t wrap my head around how that would result in the photosensor (which is not removed between participants) being detected prior to the labjack code for some participants.

Ultimately, I think we’re okay as long as we synch our epochs to the photosensor rather than to the event codes. But not knowing the source of the jitter is a rather vexing mystery. Importantly, I’d like to understand the cause of the variability in order to eradicate–or at least minimize–it prior to future steady-state evoked potential studies for which we can’t simply adjust event times to the photosensor.

Any additional thoughts as to what could cause the variability would be much appreciated!

Sharing the full code might be useful. There are possibly optimisations that can be made.

As you are using Linux, I assume that the timing should be good. This will obviously be dependent in exactly what you are drawing and doing in the code. But you have the best chance of good timing with Linux.

You can use the low latency kernel or I think another, called “realtime” or something like that. You would need to look into it. I am not a Linux person.

What kind of screen are you using?

P

Your expectation of ~ half frame delay of the light signal is about true for CRT. For other displays, the delay is always longer. Something like 20 ms is the shortest delay I saw on a DLP projector. I also saw an LCD has delay of ~80 ms.

If the light goes prior to the trigger, it strongly indicates coding issue. The light patch and trigger should be sent only for the first frame within a trial, and resting frames within a trial should update stimulus only. Are you doing this way? My guess is that the early light might be from a different frame.

-Xiangrui

The full code is available here. Any suggested optimizations or identification of errors would be great! (though I’m hopeful there are none of the latter to be identified)

Additional hardware info:
Stimuli are presented on a BenQ LED display at 1920x1080 @ 60 Hz.
Our GPU is an NVIDIA GeForce GTX 1080 8GB.

Please let me know if there is any additional info that would be useful.

Thanks again,
Andrew

Aways remains funny to see code which has used my demos at some point.

I will have a quick scan, but likely not by the end of the week.

One note: if you are using a flatscreen panel screen you will need to be wary of timing. It will depend on the exact panel, but even panels boasting high “refresh rates” often use tricks to get to those statements. Refresh rate stated is also not latency as one might think and measure. The physics of the way those panels work mean that timing can be a headache. Obviously, I am not 100% sure this could result in your findings. Just to flag, if you are wanting good timing fidelity flatscreen panels remain problematic. Clearly depends on the type of panel etc.

Obvious caveats about NVIDIA and PTB. Not preferred, but at the same time I use NVIDIA gpu’s for my stuff.

As always, doesn’t mean the science is bad. You just have to assess your needs and if the hardware meets them.

P

I had a quick look.

(1) I would suggest you make a minimal bit of code which demonstrates the issue. It will be hard for anyone to help with such a large bit of code. Often I have found you find the error yourself when you do this.

(2) You have a complicated timing setup with indexing which is hard to follow in the code. You seem to be using the second argument from “flip”, rather than the first to do your timing. I am not sure this is the best way to do things. But you might have valid reasons.

P

Without presentation of a paid support token, I certainly won’t spend time on this, and paid support is suspended from now until sometimes after mid January. Also, as Labjack is not an integrated part of Psychtoolbox, I don’t know what timing reliability one would expect - not familiar with it.

A few comments after a very quick skim or your complex code:

a) I assume you use the Priority() command to enable realtime scheduling and didn’t get any warnings wrt. to it.

b) As opposed to some other statements, it is absolutely possible to get much shorter than 20 msecs delays between reported stimulus onset and actual light leaving the display and being detected by a photo-diode. Not just on CRT’s, but on many LCD displays if they are operated at native resolution, refresh rate and image orientation, and don’t have a PWM or blinking backlight, or brightness cranked up to maximum. E.g., on the LCD panels of my laptops or on my 4+ years old Samsung HDR monitor I measure delays for a top-left mounted photo-diode of less than 1 msec, so I doubt that is the problem.

c) NVidia gpu’s are not exactly the most recommended gpu’s on Linux, as their proprietary drivers don’t offer the more extensive diagnostics of open-source powered AMD/Intel/RaspberryPi/… gpu’s, but a properly configured NVidia gpu + proprietary graphics driver is generally still more reliable and trustworthy than anything running on MS-Windows or macOS for Intel Macs (status of ARM Macs to be evaluated/unknown at this time), as NVidia proprietary on Linux still has better diagnostics than NVidia on Windows or macOS. Iow. it is the worst of the good solutions. So if timing tests in generally work without errors, I’d assume that is not the problem.

Most likely the “trigger after photo-diode detection” could happen if execution of that lj.setDIO(imageID_dio); would be drastically delayed for some reason, ie. for many milliseconds. Screen('Flip') normally returns within fractions of a millisecond of flip completion, fractions of a msec before or behind the first pixel of the stimulus leaving the video output port of your gpu. And display panel delays of a properly configured display for some white patch are usually not in the many msecs range.

You could place a t2 = GetSecs; after the labjack command, and compute dt = t2 - stimOn_StimulusOnsetTime(trial_n) to see how long that triggering may take relative to predicted stimulus onset and if it correlates with the random timing errors.

Anyhow, my unpaid 2 cents.

We have used LabJacks for years and they are very reliable timing wise (definitely sub-millisecond variance over USB), and we haven’t noticed any issues recently (though I will now run a soak test with our photodiode for confirmation).

Peter’s advice of a minimal test case is wise, and try to determine any other factors that may explain the variance like time of day if some scheduled task is running in the background). I do install the low latency kernel on my systems but I haven’t measured a significant improvement for PTB workflows overall (neither any detriments), so YMMV.

This also seems something worth looking at in more detail…

Thanks very much for all the feedback. As recommended, I’ll try a stripped down version of the code. But it’ll be hard to test in a satisfying way because we’ve only observed it happen for a small subset of participants. So for a test to be useful we’d have to get “lucky” and observe the issue.

For what it’s worth, I really think the relevant code in the snippet below. I can’t imagine how issues elsewhere would affect the timing of these events; namely, having the optical sensor detected prior to the LabJack code.

% Show the prompt (This is a question that appears on screen at the start of each trial, prior to the actual sitmulus)
[promptVBLTime, promptOnsetTime, promptFlipTimestamp, promptMissed, promptBeampos] = Screen('Flip', winPt, promptOn_sched); % show the prompt

% Calculate the stimulus constant time by adding a constant time to the time recorded by the prompt Screen('Flip')
stimOn_sched = promptOnsetTime + p.prompt_dur; 

% Show the picture (the stimulus of interest). The flip should occur when the system time reaches the stimOn_sched, which is determined above.
[stimOn_VBLTime, stimOn_StimulusOnsetTime, stimOn_FlipTimestamp, stimOn_Missed, stimOn_Beampos] = Screen('Flip', winPt, stimOn_sched);

% The LabJack code (i.e., digital event marker) is sent immediately after the Screen('Flip')
lj.setDIO(imageID_dio);

% log the time when the LabJack code was sent.
DIOtime = GetSecs; 

Ha! Good eye.

To be honest, I cannot remember why I chose to use the second argument from Flip (StimulusOnsetTime) rather than the first (VBLTimestamp), but I think it’s moot because our log files indicate that these are always perfectly identical values.

Our event log actually includes this very thing, but embarrassingly I hadn’t even thought to look at it until you suggested it. The LabJack code is reliably executed within 1 ms of the Screen flip. This is true even on those trials in which the optical sensor is detected prior to the event code, so there does not seem to be any meaningful relationship between the timing issue and any latency between the Flip command and the LabJack command.

Really, from the perspective of PTB the timing all looks good. Which makes it all the more perplexing.

That was my understanding too.

Thanks again and a Happy New Year to all!