Timing issues without any missed frames

Hardware
1

Hello,
In a simple experiment I turn the monitor on (whole screen white) for one frame (refresh rate:60Hz) and then off for one frame (whole screen black) and repeat this over and over. Simultaneously I measure the luminance of the top left corner of the screen with a photodiode and record its analog signal. When I look at the results the changes in the luminance and the photodiode signal are synchronized at the beginning, but they don’t match at the end of the experiment so it seems that there are some timing issues. However, when I check the vbl times the length of the frames seem to be right and no missed frame is reported. I need to have precise timings and I am wondering why this happens.

My setup: My graphics card is an AMD Radeon RX 5700 XT. I run Psychtoolbox-3 on MATLAB2020b and my OS is Ubuntu 20.04.1. I am also using a Bits# to generate a trigger and synchronize stimulus presentation with data acquisition system. So my stimulus presentation happens through the Bits#.

I have tried different monitors, different refresh rates, and also without using the Bits, but the problem persists in all these conditions.

Here is the code I am using for the experiment:

clc
clear all
close all

%% PREPARE AND COLLECT INFO
KbName('UnifyKeyNames')
Screen('Preference', 'SkipSyncTests', 0);
oldPriority = Priority(1);
input('hit enter to begin...  ');

%% Set parameters:
bitsPort = '/dev/ttyACM0';

%% Keyboard set up:
[keyboardIndices, productNames, ~] = GetKeyboardIndices;

deviceString =  'Dell Dell USB Entry Keyboard';
deviceNumber = 0;

for i=1:length(productNames)    %for each possible device
    if strcmp(productNames{i},deviceString)     %compare the name to the name you want
        
        deviceNumber = keyboardIndices(i);        %grab the correct id, and exit loop
        break;
        
    end
end
%}

triggerKey = KbName('=+');

%%
AssertOpenGL;
HideCursor;

%% setting up the bits#:
clrplusMode = 2;

PsychImaging('PrepareConfiguration');
% 32bit:
PsychImaging('AddTask', 'General','FloatPoint32BitIfPossible');
% Use color++ mode with overlay:
PsychImaging('AddTask', 'General', 'EnableBits++Color++Output',clrplusMode);

% Open a connection to Bits#/Display++.
BitsPlusPlus('OpenBits#',bitsPort);
BitsPlusPlus('SwitchToColor++');

%% Screen:
w.whichScreen = max(Screen('Screens'));

% setting the resolution
w.screenRes = [0 0 1024 768];
w.screenFrameRate = 60;
oldRes = SetResolution(w.whichScreen,w.screenRes(3), w.screenRes(4),w.screenFrameRate);

w.frameRate = Screen('FrameRate',w.whichScreen);

%% timing:
t.ifi = 1/w.frameRate;
t.nRep = 2^12;
t.nFrame  = 1;

%% stimulus features:
stim.grey = [.5 .5 .5];
stim.black = [0 0 0];
stim.white = [1 1 1];

%% WINDOW SETUP
[window, rect] = PsychImaging('OpenWindow', w.whichScreen, stim.grey,w.screenRes);

w.screenRect = rect;

cntrX = round(w.screenRect(3)/2);
cntrY = round(w.screenRect(4)/2);

%% setting up the Bits# trigger:
repetitions = 1;
mask = bin2dec('1111111111111111');

trigPackOn = 10; % time to be high in the beginning of the frame (in 100 us steps = 0.1 ms steps)
dataPack = [repmat(bin2dec('1000000000000000'),trigPackOn,1);repmat(bin2dec('0000000000000000'),248-trigPackOn,1)]';

command = 0;
xpBits = 1;
ypBits = 2;

%% Initial set up:
btext = 'Hit =/+ Key to Begin...';
bbox = Screen('TextBounds', window, btext);
newRect = CenterRectOnPoint(bbox, cntrX, cntrY);
tx = newRect(1); ty = newRect(2);

Screen('DrawText', window, btext, tx, ty + 40, stim.white,stim.grey);
Screen('Flip', window);
KbTriggerWait(triggerKey, deviceNumber);

%% presenting the stimulus
BitsPlusPlus('DIOCommand', window, 1, mask, dataPack, command,xpBits,ypBits);
vbl = Screen('Flip', window);

vblAll = [];
stimOnTAll = [];
flipTAll = [];
missedAll = [];
beamPosAll = [];

for nii=1:t.nRep/2
    
    %%%%%%%% ON:
    Screen('FillRect',window,stim.white);
    [vbl stimOnT flipT missed beamPos]  = Screen('Flip', window, vbl + (t.nFrame - 0.5)*t.ifi,0);
    
    vblAll = [vblAll vbl];
    stimOnTAll = [stimOnTAll,stimOnT];
    flipTAll = [flipTAll,flipT];
    missedAll = [missedAll,missed];
    beamPosAll = [beamPosAll,beamPos];
    
    
    %%%%%%%%%% OFF:
    Screen('FillRect',window,stim.black);
    [vbl stimOnT flipT missed beamPos]  = Screen('Flip', window, vbl + (t.nFrame - 0.5)*t.ifi,0);
    
    vblAll = [vblAll vbl];
    stimOnTAll = [stimOnTAll,stimOnT];
    flipTAll = [flipTAll,flipT];
    missedAll = [missedAll,missed];
    beamPosAll = [beamPosAll,beamPos];
    
end

%% Reseting Bits#:
BitsPlusPlus('DIOCommandReset', window);
% Load identity (linear) CLUT into Bits++/Bits#/Display++ to restore proper display:
BitsPlusPlus('LoadIdentityClut', window);
Screen('Flip', window);

BitsPlusPlus('Close');

%% Close everything down
ShowCursor;
Screen('CloseAll');

In this code I set the times relative to the timing of the last frame, but I have also tested setting the flipping times with absolute values by calculating the timings before the stimulus presentations. Still, I have the same issue.

Following are the results:
no missed frames, and duration of the frames:

framdur_relT
framdur_relT924×570 30.7 KB

two events match at the beginning:

relT_pulses_start
relT_pulses_start1221×591 59.6 KB

but the synchronicity is not as good at the end:

relT_pulses_end
relT_pulses_end1221×591 60.2 KB

My authentication code for priority support:
CZS6KX2Y-202145122119:509c8b2e476ca976cfd253b3f725126098767e9a548cb4f30fa1ea282922433f

2

How long is a run? How do you record the photodiode signal? Looks to me (first suspicion is) like clock drift of one device relative to another.
What is the interpeak interval in the photodiode signal? Is it stable but slightly different than the inter frame interval?

3

Have you tried pre-allocating (not setting as empty…) all those arrays before you run the loop?

4

Not clear what the screen luminance signal is

5

Preallocating all the arrays seems very likely to be the solution to your problem. We had similar issues when someone in my lab wrote code that had made Matlab do memory allocation every frame, causing things to get slower and slower, something noticeable only during long runs. Matlab encourages bad programming hygiene. It is good practice to allocate all frequently referenced arrays to a size bigger than the maximum you will ever need, and then to truncate them at the end before you do anything to save them. This practice uses much less memory than frequent reallocations, which happen when you set an array to its previous size plus one new element.

6

Your hw + os setup (Ubuntu 20.04-LTS + AMD gpu + PTB) should be perfect for timestamping, assuming PTB does not give any errors or warnings wrt. stimulation timing or timestamping. I don’t think we had a silent failure of timestamping in over a decade, so i have very high confidence in those timestamps reported by Screen('Flip'). If you don’t see any dropped frames and always a 16.6 msecs delta between flips, as your plot shows, then you are not dropping frames. It is true that you should preallocate those timestamp arrays for speed, as Matlab’s editor certainly recommended, but that won’t be the problem here as you don’t have missed flips.

The task PsychImaging('AddTask', 'General', 'EnableBits++Color++Output',clrplusMode); will enforce a validation of correctly working hardware identity pixel passthrough, so from the fact that your script runs at all, we can conclude that the T-Lock trigger code gets correctly sent out and received by the Bits#. No problems caused by PTB / graphics driver / gpu bugs or bad cabling or signal reception.

One thing that puzzles me in your code: You use BitsPlusPlus('DIOCommand', window, 1, mask, dataPack, command,xpBits,ypBits); before entering the for-loop, only once, and with a repetitions count of 1? Unless this is a typo and was actually -1 in the real script, this should only cause emission of one single DIO trigger, not repeated emission of one trigger for each flip?

One further catch: You do not record the first vbl timestamp from the vbl = Screen('Flip', window); right before you enter your `for nii…`` loop. A skipped flip deadline between that flip and the first flip to white in your loop would go unnoticed in your plot. And that would already misalign the Bits# DIO trigger signal with the visual stimulus pattern and what the photodiode reports.

The trigger design of the Bits# T-Lock DIO trigger is unfortunately stunningly flawed. The Bits# does not send the DIO trigger when it receives the stimulus image with the T-Lock trigger code, ie. in the video frame for which you request a trigger, as a sane design would do. Instead it sends it with a 1 video refresh cycle delay ie. 16.6 msecs later. So if your first flip to white in your for-loop would skip one or multiple frames, then the DIO trigger would go out in the video refresh cycle when the white image was supposed to be first shown, whereas the actual white image - registered by the photo-diode - would only display one or more refresh cycles later.

When i tried to use the DIO mechanism for timestamp checking, i found it to be mostly unusable due to that design flaw, as this delayed-by-one behaviour creates a lot of confusion if one tries to reason about timing errors, especially if one sends out triggers on every flip and flips on each refresh cycle.

I would trust the results from the photo-diode much more than what the Bits# triggers give you.

How did you check this without the Bits# ? What was the 2nd source of a signal then?

What types of monitors did you use? A classic CRT monitor with analog VGA input? Otherwise, one thing to remember is that many digital monitors do only provide reasonable timing if they are used at their native (==maximum) resolution and refresh rate. Other resolutions and refresh rates may trigger resampling in space and time, which can add all kinds of timing artifacts. You’d see that in the traces of the photo-diode, but not in the trigger signal of the Bits# or the PTB timestamps, as PTB measures when the signal leaves the video output, and Bits# measures what happens before the monitor gets to post-process it.

Another problem could be if a LCD monitor is not able to switch its pixels fast enough from black → white → black again, or if the monitor uses a pulsing backlight or backlight which controls its brightness via pulse-width modulation. That could cause some drift in the luminance response vs. video signal, which may cause the photo-diode signal to drift a bit. I’d make sure no pulsing/strobing backlight is used, and test with display brightness set to maximum.

I would also try a different test cycle: Something like white for one video refresh cycle, then black for multiple refresh cycles, ie. using t.nFrame other than 1 for that. And pull the DIOCommand into the the for loop and place it so the DIO trigger only fires at the refresh cycle where the white frame is supposed to show up. This would give an LCD monitor more time to settle its pixels back to black after a white flash, and make it easier to follow the recorded traces.
I can’t remember atm. how the Bits# actually treats DIO changes faster than one every ~25 msecs? Docs say you must specify 248 element vector, which defines a time-series of DIO settings where each element encodes 0.1 msecs of time, so a full playback of such a T-Lock DIO command would last 24.8 msecs. I hope the device doesn’t get confused by a new T-Lock DIO code more often than once every 24.8 msecs. Only one trigger per white-frame would avoid possible trouble there.

I’ll intersperse some comments on improving the code, although i think it isn’t really wrong…

It’s not that clear what the timing on the x-axis is in these plots? How long is a sample duration? Or why you call the red trace “screen luminance”? Isn’t that just the trigger signal?

Time spent on this request 80 minutes >> 40 minutes left on your license, so priority support is used up from this point.

-mario

7

Each run is 68.27sec (2048 cycles of 1frame On and 1frame Off, with a 60Hz refresh rate). I am using the 1401 DAQ from CED to record the signal with a 600Hz sampling rate, and this is the photodiode I’m using:

From the figure below, you can see that the interpeak intervals are very stable and equal to 33.33ms (2frames) as it’s expected. But there are a few instances when the interval is shorter than what it should be and this is probably why the two signals get out of sync.
(first subplot is a zoomed in version of the recorded photodiode signal with the timings of the peaks overlaid on it. The second plot is the temporal distance between each two peaks plotted against the timing of the most recent peak. Each sample is 1/600 sec ~1.68 msec).

photoDIpI
photoDIpI1019×801 50.2 KB

8

Thanks for the comments and suggestions.

Regarding the trigger, I send it only once because I am using the 1401 CED DAQ system and I can set my recording window time. So I will set it to record for the duration of the experiment (here around 69sec) after it receives one trigger and this means that I won’t need to send repeated triggers.
I have also recorded the Bits# trigger with our DAQ system and now I am sure that it comes at the end of a frame it has been set on. So, in order not to miss the start of the stimulus I only need to set it one flip command before the stimulus presentation. I can see that a delayed trigger can be problematic, but in this case the trigger doesn’t have any delays. I didn’t include it in the plot but I have checked the timing of the first vbl timestamp and it’s correct.

I think the legend I chose for my plots might have been somehow misleading. The red signal is not taken from Bits#. It’s a synthetic signal I made using my knowledge of when the monitor was supposed to be on and off. So, I really didn’t need the Bits# to generate it. The bits# helped with the starting time of the recording by sending the trigger. For testing without it, I started recording before the start of the experiment and later on found the start of the photodiode response manually then overlapped the synthetic luminance changes on it. I can again see that the two cycles match at the beginning but get out of sync as time passes.

I had tried digital monitors, but upon your suggestion I tested a CRT as well and unfortunately didn’t see any improvements.

9

And that plot explains it all, i think. So in a 68 seconds recording, you have about 5 white-frames where the photo-diode peaks ~ 1.666 msecs shorter than the expected 33.333 msecs, iow. the peak comes exactly 1 sample too early in your 600 sampes/sec recording. This is exactly what one would expect if the graphics card would not refresh at exactly 60 Hz, but a tiny bit faster, or if the recording device would not sample at 600 Hz, but a tiny bit slower, or both. If you sample a 30 Hz black-white transition on a 60 Hz display at 600 Hz, then you’d expect the photo-diode peak every 20 samples, but with a small discrepancy, the error will accumulate over a couple of seconds, until it reaches a full 1.66 msecs sample duration and the peak of the signal falls into a different sample bin, and then you get a single case where the peak is only 19 samples apart. That “resets” the error and you are back to 20 samples delta until the process repeats after a dozen seconds or so.

Essentially clock drift between the graphics cards clock and the CED DAQ clock. Small clock drift can happen due to manufacturing tolerances, voltage fluctuations in your labs power grid, temperature change of the equipment, or that the monitor can’t actually run at exactly 60 Hz for a given resolution but a tad faster or slower. You will even see this in PTB’s reported measured framerate from VBL sync vs. operating system reported nominal framerate. Rarely are both exactly 60.0 Hz.

-mario

10

Yes, as a start recording signal, it would work. If the first real stimulus flip would be delayed a frame, it would just have started recording a refresh duration too early and you can realign by searching the first photodiode peak in the recording.

Your synthetic signal is the problem, as the real world isn’t that nice. As soon as you have more than 1 clock driving or measuring things, you will observe some clock drift of the more or less systematic or horrendous type. 50 ppm variation per clock are not unusual, so two clocks like in your case with graphics card clock + DAQ clock could already get you 100 ppm variation. Or more, depending on temperature changes, voltage or ac grid fluctuations etc. E.g., the computers main clock which drives GetSecs and other PTB timing functions also is also slowly adjusted by NTP adjustments, which depending on the quality of your NTP servers and network connection can be a good or bad thing for timing. And there also exist solutions like precision time protocol (PTP) to at least sync the computer clock with special PTP enabled equipment if one needs to sync across a range of machines and equipment. Or things like the VPixx products which can sync their data acquisition to the video refresh timing, and thereby to the graphics cards clock.

If your - perfectly expected - results are good enough in the end, depends on what the final purpose of all this data acquisition is and how precise you need it?

Anyway, your priority support for this license is used up.

Best
-mario

11

One more comment: If people need very fine-grained control over visual timing, framerates etc. and have a modern AMD graphics card + FreeSync/“DP-adaptive sync”/“G-Sync compatible” monitor connected via DisplayPort on Linux, PTB’s fine-grained timing support may have something to offer, cfe. VRRTest and help VRRSupport. The current implementation as a pure userspace implementation is not perfect, but should be already useful for many paradigms. A kernel level implementation should improve a lot upon that, and may or may not show up anytime within the next 1-2 years, depending on how successful my experiments with that will be and if community funding will be available. But feedback wrt. needs or usefulness of this special Linux feature is welcome to steer future development.

-mario