Abnormal frame duration 2.0

Coding
1

Hi community,
I am running the code below on a dell XPS Laptop 15’ with a Nvidia GTX 1080 on Windows 10 (Psychopy v 3.2.4):

win = visual.Window(fullscr=True, 
    monitor='mathieu', color=[145,145,145], colorSpace='rgb255', units='cm')
    
police = 'Consolas' 
win.setMouseVisible(False) 

# initialize keyboard
resp = keyboard.Keyboard()

some_text = visual.TextStim(win=win, 
    text ="Hello world", 
    font=police,
    pos=[0, 0],
    height=0.5,
    color=[0,0,0],
    colorSpace='rgb255')      


frame = 0
temp = np.zeros(10)
while True:  
    theseKeys = resp.getKeys(keyList=['space'], waitRelease=False)
    if len(theseKeys):
        break
    some_text.draw() 
    t = win.flip()
    if frame < 10:
        temp[frame] = t
    frame = frame + 1
temp = np.array(temp)
for i in range (1, 10):
    print (temp[i]-temp[i-1])
core.quit()

which systematically returns abnormal duration of the first frames, e.g.:
1st run:

0.00700440000036906
0.007453700000041863
0.015575299999909475
0.01700669999991078
0.01664569999957166
0.016724900000554044
0.01652760000069975
0.01690509999934875
0.015928200000416837

2nd run:

0.004152199999225559
0.01446850000138511
0.016495099998792284
0.016586699999606935
0.016613600000709994
0.01685130000078061
0.01628999999957159
0.016707099999621278
0.017078500000934582

I have been noticing this strange behavior across many versions of psychopy and computers/LCD monitors, and I don’t understand it. I have raised this issue before, but didn’t get a clear answer. Note that there is a similar issue with the timebyframe demo:

Figure_1-1
Figure_1-11200×796 37.6 KB

Could you please help me understand/solve this issue? I don’t see how Psychopy’s timing of visual stimuli can be accurate given these few abnormal frame durations.
Thanks!

2

@jon Any insight on this?

3

I think what’s happening is that the first frame (or 2) are filling up some frame buffers (possibly you have more than a front and back buffer?). The call to flip returns immediately because it found a spare frame buffer, filled it and carried on. After that, there was no buffer “spare”.

What are the buffer settings in your graphics card driver? Have you got anything like screen scaling turned on in your system display settings?

4

@jon My Laptop (as many recent 15’ laptops) has a 125% scaling, but using 100% scaling does not solve the issue. I then ran the above code using both Intel integrated graphics and the nvidia GTX 1080, and observed the frame duration issue on both. In the nivida settings, triple buffering is disabled, and multi-frame sampled AA (MFAA) is disabled as well. Vertical sync is enabled. I don’t see other parameters that may cause the issue.

The strange thing is that I have systematically observed this problem on many different systems (all natively running Windows 10) with different GPUs (intel, nvidia, AMD) and LCD screens (60 and 144 hz), which suggests that the problem is not due to particular GPUs settings. I am sorry to be a little obsessive with timing (one frame or two is not a big deal for most applications), but I think it is important to understand and solve this issue. What do you think?

5

I would be more concerned if the issue were occurring randomly during a run, but the fact that it happens just once at the very first frame suggests it’s something to do with the setup code, or window initialisation etc. and not something that’s affecting your running frames (which appear to be running at roughly 16.5+/-0.7ms).

For the scaling, I would expect that is adding an additional lag that you aren’t seeing in these numbers because windows does use triple-buffering when scaling and that’s only visible when you test with a photodiode. But if the absolute timing error (i.e. lag) isn’t an issue then no problem.

6

@jon I did some additional testing, adding core.wait(2.) between two runs of frame duration measurements:

win = visual.Window(fullscr=True, 
    monitor='mathieu', color=[145,145,145], colorSpace='rgb255', units='cm')
    
police = 'Consolas' 
win.setMouseVisible(False) 

# initialize keyboard
resp = keyboard.Keyboard()

some_text = visual.TextStim(win=win, 
    text ="Hello world", 
    font=police,
    pos=[0, 0],
    height=0.5,
    color=[0,0,0],
    colorSpace='rgb255')      

for i in range (5):
    print ("")
    print ("run " + str(i+1))
    frame = 0
    temp = np.zeros(10)
    for j in range (10):  
        theseKeys = resp.getKeys(keyList=['space'], waitRelease=False)
        if len(theseKeys):
            break
        some_text.draw() 
        t = win.flip()
        if frame < 10:
            temp[frame] = t
        frame = frame + 1
        temp = np.array(temp)
    for k in range (1, 10):
        print (temp[k]-temp[k-1])
    core.wait(2.)
core.quit()

Given that core.wait() is often used during the inter-trial interval (I remember Michael advising to do that to let windows do some housekeeping), my concern was that peharps the frame issue would affect the first frame of every trial. The results (nvidia GTX, scaling = 125%) are reported below:

run 1
0.0038377000000764383
0.017725199999858887
0.01662590000023556
0.016735499999867898
0.016121900000143796
0.017122399999607296
0.016439700000319135
0.016595499999766616
0.016886300000351184

run 2
0.019283099999938713
0.01702900000009322
0.016205899999931717
0.016458699999930104
0.016871000000264758
0.016649499999857653
0.016459500000109983
0.016855800000030285
0.01604959999986022

run 3
0.021114699999998265
0.016281800000342628
0.016767600000093807
0.01594829999976355
0.0169927000001735
0.01672129999997196
0.0166122999999061
0.01706160000003365
0.016228099999807455

run 4
0.01976829999966867
0.01647480000019641
0.01692060000004858
0.016869900000074267
0.016014699999686854
0.016629400000056194
0.016668400000071415
0.01649619999989227
0.016913899999963178

run 5
0.021375499999976455
0.016993100000036065
0.01628709999977218
0.016814800000247487
0.016489999999976135
0.01654869999993025
0.016948800000136544
0.01608699999997043
0.01693799999975454

As you can see, the duration of the first frame of each run is abnormal, though it is slightly > 16.7ms for runs 2-5. I can’t make sense of these numbers. Changing the scaling did not modulate these numbers. I ran the very same code on another computer (nvidia quadro, BenQ monitor) and got similar numbers. It looks like it is a windows 10 issue, though I haven’t tested this yet on Linux systems.

7

That’s only true if you don’t care about the exact duration of that inter-trial interval. By using core.wait(), you’re no longer keeping up with the frame refresh cycle, and so its possible that the ITI will end up being longer than intended, by some proportion of a frame duration.

What is needed during a script is to give some time to the operating system for other tasks, so that you don’t suddenly get a glitch in timing as the OS bursts in on psychoPy and demands time for other processes. A cycle of win.flip() drawing is usually sufficient for that, as if you are not dropping frames, then your code will be paused for a least a few milliseconds per frame while it waits for the next screen refresh. core.wait() also provides that pause, but can be much longer, depending on what you provide for the hogCPU argument, but at the cost of potentially slipping out of sync with the screen refresh cycle.

What we advise against is a tight loop that doesn’t involve a win.flip(), as that can entirely consume the CPU, leaving no breathing room for other processes, eventually leading to them breaking in to demand time.

e.g.

# Bad (doesn't pause during the loop, so entirely consumes the CPU):
while True:
    keys = event.getKeys()
        if keys:
            break

# OK (does pause during the loop, once per screen refresh, 
# being a good citizen to other processes):
while True:
    keys = event.getKeys()
        if keys:
            break
    win.flip(clearBuffer = False) # Ahh, pausing here for a few milliseconds

So I guess the lesson here is that there is some start up issue with getting in sync with the screen refresh cycle, so you might want to keep up and active drawing cycle throughout the experiment, so you don’t get these abnormal timings. If the first stimulus shown is just a “welcome” screen, for example, then there won’t be an issue. After that, just keep up active drawing on every screen refresh (as Builder scripts do), and don’t use core.wait() at all, to avoid falling off the refresh cycle.

Having said all that, understanding what is causing the initial issue would be very useful.

8

@Michael @jon Thanks Michael, you are absolutely right, and I should have specified that it is only true when you don’t care about the inter-trial interval. I would appreciate some help in trying to solve the refresh cycle initialization issue -I suspect that I am not the only one to experience this issue. Unfortunately, I only have windows-based operating systems at the moment in my lab, so I can’t determine if the issue is windows-specific or not. Maybe you guys could try to replicate this issue, and see if it also occurs on linux-based systems ?