macOS Display Timing

There has been at least one report of macOS 10.13 / 10.14 adding an extra one frame delay to graphics update times, causing experiment software graphics update times to be off by one retrace.

We used the MilliKey DeLux light sensor to look into this further by testings the display change timing of a macmini running either macOS 10.9.5 or 10.13.6 connected to an LCD display. Sure enough, it looks like sometime between macOS 10.9.5 and macOS 10.13.6 an extra one frame delay has been added to the operating systems graphics pipeline.

Procedure

The computer monitor and test script were the same as was used in the Windows 10 Display Timing post. Unless otherwise stated, this test used the same procedure as that post.

In this test we used was an Apple macmini (late 2011 model) connected to a SyncMaster P2770 LCD monitor. The stated response time of the SyncMaster P2770 is 1 msec, which probably means it is closer to 2 msec peak to peak.

The same test script was run on the same hardware while booted into either macOS 10.9.5 or macOS 10.13.6. The time difference between receiving the DeLux USB serial trigger event and the time reported from the win.flip() for each dark-light transition was calculated, subtracting the 7 msec offset the DeLux was configured to use.

Results

USB serial events sent by the MilliKey DeLux will add an average of 0.5 msec to these display change delay results. This has not been corrected for in the following plots.

macOS 10.9.5

While using macOS 10.9.5 we observed an expected / reasonable display update delay for the LCD monitor being tested. Average

macOS 10.13.6

Results show a consistent 1 frame delay in macOS 10.13.6 display updates as compared to macOS 10.9.5.

Conclusion

Using a MilliKey DeLux light sensor we have been able to show that there does seem to be an extra frame delay in display update timing on macOS 10.13.6 (or higher presumably) that does not exist in macOS 10.9.5. This adds an extra one retrace delay to any screen update times calculated by the experiment. This means visual stimulus duration should still be accurate, however onset and offset times should both be corrected for the extra delay.

If anyone is aware of a way to fix this issue on macOS 10.13+, please let us know.

Happy Hacking!

Share:

Windows 10 Display Timing

It looks like you need to be careful with your display settings in Windows 10, otherwise Windows 10 could be adding an extra frame delay to the display update times reported by your experiment software.

We have found that if the Windows 10 Display -> Scale (and layout) setting is not set to 100%, the Windows 10 operating system adds an extra frame delay to the actual monitor update time. When using a 70 Hz monitor for example, this adds an extra 14.3 msec delay, causing the reported display update time to be off by one retrace as well.

Windows 10 Monitor Scale Setting @ 100% results in expected display change timing.
Windows 10 Monitor Scale Setting @ 125% results in extra 1 frame (monitor retrace) delay.

Procedure

Using the MilliKey DeLux light sensor upgrade and PsychoPy3 we compared the display update time reported by psychopy.visual.Window.flip() to the time the experiment received a 1000 Hz USB serial event triggered by the MilliKey DeLux light sensor in response to each screen brightness change.

In this test we used was a Dell G5 15 laptop running Windows 10 with NVIDIA graphics connected to a SyncMaster P2770 LCD monitor. The stated response time of the SyncMaster P2770 is 1 msec, which probably means it is closer to 2 msec peak to peak.

A Python 3 test script used the open source PsychoPy3 experiment package to make 1000 dark -> light display changes, recording the flip() time of each dark->light change. The same script was connected to a MilliKey with the DeLux light sensor via USB Serial.

The MilliKey DeLux was configured to generate a USB Serial event after the DeLux light sensor detected the monitor brightness crossed a digital threshold level. The appropriate light sensor threshold level for the monitor being tested was set by the test script itself.

The MilliKey DeLux can be configured to send the USB Serial event a fixed number of msec after the actual light sensor trigger time, called the trigger offset. In this test we set the trigger offset to 7 msec. This allows the USB Serial event to be sent, and received, by the experiment program at a time when the program can rapidly receive and process the event.

The same test script and hardware was used in both a 100% and 125% scaling condition. The time difference between receiving the DeLux USB serial trigger event and the time reported from the win.flip() for each dark-light transition was calculated, subtracting the 7 msec offset the DeLux was configured to use.

Results

USB serial events sent by the MilliKey DeLux will add an average of 0.5 msec to these display change delay results. This has not been corrected for in the following plots.

Average Display Change Delay (Error) Bars and CI lines. Using 125% scaling causes an extra frame delay.

100% Scaling

Display change latency of SyncMaster P2770 LCD monitor @ 100% scaling setting is reasonable given LCD response time . Tested using MilliKey DeLux light sensor.

Display Update Delay Stats
Count: (1000,)
Average: 2.335 msec
Median: 2.231 msec
Min: 1.000 msec
Max: 4.556 msec
Stdev: 0.517 msec

When 100% scaling is being used, the display update time reported by win.flip() looks accurate given the LCD monitor response time.

Note that the bi-modal nature of the above delay distribution, with peaks at approximately 2 and 3 msec, is likely a result of quantization caused by the 1000 Hz MilliKey USB serial report rate.

125% Scaling


Extra frame delay can be seen when Windows 10 Display Scaling setting is @ 125%. Tested using MilliKey DeLux light sensor.

The results clearly show that the Windows 10 operating system is adding an extra frame delay when the Display Scaling setting is equal to 125%.

Code

The test script is based on one of the MilliKey DeLux Python examples that can be downloaded from our website. The test procedure logic is in the runDisplayTimingTest() function.

#!/usr/bin/env python
# -*- coding: utf-8 -*-
from __future__ import absolute_import, division, print_function
from psychopy import visual, event, core
import json
import serial
import numpy
import time

# Serial Port of MilliKey.
#mK_seria1_port = '/dev/cu.usbmodem4998701'
mK_seria1_port = 'COM112'

# Number of dark -> light display change tests to run
test_count = 1000

# Number of light frames to display after dark->light transition
light_frame_count = 10

# Number seconds to wait between each test iteration.
iti=0.4

# Number of msec MilliKey waits before sending serial trigger after 
# light threshold is crossed. 
trig_delay=7

# Maximum number of trigger events MilliKey will send on each test iteration. 
# Useful for limiting the trigger repeating every retrace on CRT monitors for
# example.
max_trig_count =  2

# True == Run simple auto threshold leveling routine before running the test.
# False == Use threshold level stored in MilliKey device.
autothresh = True

# Multiplier for calculating threshold level from dark screen max reading
# For LCD, suggest 1.5 - 2.5
# For CRT, suggest 5.0 - 10.0
thresh_scaling_factor = 2

TRIG_RISING_SERIAL = 1

def runDisplayTimingTest():
    results = numpy.zeros(test_count, dtype=numpy.float64)
    mk_sconn = init_millikey_delux()
    win, (white_stim, dark_stim, txt_stim1, txt_stim2) = initPsychoPyGraphics()

    start_key = event.waitKeys()

    if autothresh:
        lowlight_stats = getLightSensorStats(mk_sconn, win, dark_stim)
        ls_threshold = lowlight_stats.get('max')*thresh_scaling_factor
        print("Using threshold level %d for test.\n"%(ls_threshold))

    print("test_num\ttrig_rx_time\tflip_time\ttrig_delay\tdisplay_latency\ttrig_msg")

    # run test_count loops
    count=0
    while count < test_count:
        # Draw black screen and flip to it.
        dark_stim.draw()
        win.flip()
        # Wait ~iti seconds with display black, starting light sensor
        # 1/2 way through.
        time.sleep(iti/2)        
        mk_sconn.write(b"START_AIN %d\n"%(ls_threshold))
        core.wait(iti/2)
        flush_serial_rx(mk_sconn)
        # Draw white (target) stim and flip to it,
        # getting time flip occurred (stim onset)
        # time from psychopy.
        white_stim.draw()
        ftime = win.flip()

        reading = mk_sconn.readline()
        if reading:
                t, d = core.getTime(), json.loads(reading[:-2])
                tdelay = d['delay']/1000.0
                results[count]= t-ftime-tdelay
                if d['count'] > 1:
                    print("Warning: Trigger number %d received; expecting 1"%(d['count']))
                print("%d\t%.4f\t%.4f\t%.4f\t%.4f\t%s"%(count+1, t, ftime,
                                                    tdelay, results[count],str(d)))
        else:
            print("Error: MilliKey Serial Timeout.")
            win.close()
            mk_sconn.close()
            raise RuntimeError("Error: MilliKey Serial Timeout.")


        # Display white screen for n frames.
        for lf in range(light_frame_count):
            white_stim.draw()
            win.flip()

        mk_sconn.write(b"STOP_AIN\n")
        count+=1

    win.close()
    mk_sconn.close()
    return results

def sendSerial(mk_sconn, txdata, wait=0.050, is_json=True):
    rx = None
    mk_sconn.write("{}\n".format(txdata).encode('utf-8'))
    stime = core.getTime()
    rx = mk_sconn.readline()
    while len(rx) == 0 and core.getTime()-stime < wait:
        rx = mk_sconn.readline()
    if rx and is_json:
        try:
            return json.loads(rx[:-2])
        except:
            return rx[:-2]
    if rx:
        return rx[:-2]

def flush_serial_rx(mk_sconn):
    while mk_sconn.readline():
        pass
    
def getLightSensorStats(mk_sconn, win, stim):
    for i in range(4):
        stim.draw()
        win.flip()
    mk_sconn.write(b"START_AIN\n")
    for i in range(10):
        stim.draw()
        win.flip()
    mk_sconn.write(b"STOP_AIN\n")
    mk_sconn.write(b"GET AIN_STATS\n")
    stats = mk_sconn.readline()
    return json.loads(stats)

def init_millikey_delux():
    mk_sconn = serial.Serial(mK_seria1_port, baudrate=128000, timeout=0.05)
    print(sendSerial(mk_sconn, 'SET AIN_TRIG_DELAY %d'%(trig_delay),
                     is_json=False))
    print(sendSerial(mk_sconn, 'SET AIN_TRIG_MODE %d %d'%(TRIG_RISING_SERIAL,
                                                          max_trig_count),
                                                          is_json=False))

    ain_stats= sendSerial(mk_sconn, "GET AIN_STATS")
    ain_res = ain_stats.get('res')
    if ain_res > 100: # ain_res < 100 means light sensor is connected
        print("Error Light Sensor is not connected to Analog Input Jack.")
        mk_sconn.close()
        raise RuntimeError("Analog Input Error. Check connection.")
    return mk_sconn

def initPsychoPyGraphics():
    # Create a full screen window and two full screen stim.
    win = visual.Window(fullscr=True, screen=0)
    white_stim = visual.ShapeStim(win, lineColor='white', fillColor='white',
                                  vertices=((-1,-1),(1,-1),(1,1),(-1,1)))
    dark_stim = visual.ShapeStim(win, lineColor='black', fillColor='black',
                                 vertices=((-1,-1),(1,-1),(1,1),(-1,1)))
    txt_stim1 = visual.TextStim(win,
                                "Place DeLux Light Sensor in Top Left Corner.",
                                color=(0.0,1.0,0.0), height=0.05)
    txt_stim2 = visual.TextStim(win, "Press any Key to Start Test.",
                                pos=(0.0,-0.1), color=(0.0,1.0,0.0),
                                height=0.05)
    white_stim.draw()
    dark_stim.draw()
    txt_stim1.draw()
    txt_stim2.draw()
    win.flip()
    return win, (white_stim, dark_stim, txt_stim1, txt_stim2)

# Plot Results
def createHistogram(data, title="Display\ Update\ Delay", 
                    xlabel="Delay (milliseconds)",
                    ylabel="Probability density", nbins = 50):
    try:
        import matplotlib.pyplot as plt
        mu, sigma = data.mean(), data.std()
        # the histogram of the data
        n, bins, patches = plt.hist(data, nbins, density=1,
                                    facecolor='green', alpha=0.75)
        # add a 'best fit' line
        y = ((1 / (numpy.sqrt(2 * numpy.pi) * sigma)) *
             numpy.exp(-0.5 * (1 / sigma * (bins - mu))**2))
        plt.plot(bins, y, '--')
        plt.xlabel(xlabel)
        plt.ylabel(ylabel)
        if title is None:
            title = r"Histogram"
        title = r'$\mathrm{%s:}\ \mu=%.3f,\ \sigma=%.3f$'%(title,mu,sigma)
        plt.title(title)
        plt.grid(True)
        plt.tight_layout()
        plt.show()
    except:
        print("Could not create Histogram:\n\ttitle: {}\n\tlabel: {}\n\tylabel: {}".format(title, xlabel, ylabel))
    
if __name__ == '__main__':
	results = runDisplayTimingTest()
	
    # Convert times to msec.
    results = results * 1000.0
    
    print('\n\n')
    print("Display Update Delay Stats")
    print("\tCount: {}".format(results.shape))
    print("\tAverage: {:.3f} msec".format(results.mean()))
    print("\tMedian: {:.3f} msec".format(numpy.median(results)))
    print("\tMin: {:.3f} msec".format(results.min()))
    print("\tMax: {:.3f} msec".format(results.max()))
    print("\tStdev: {:.3f} msec".format(results.std()))
    
    createHistogram(results)

Conclusions

Next time you go to collect data on a Windows 10 machine, we would suggest you first make sure to check the Windows 10 Display Scaling setting and ensure it is at 100%.

It is probably worth pointing out that the extra delay seen in the 125% scaling condition does not effect stimulus duration: it adds one retrace interval to the start and end time of a stimulus.

There are likely other conditions that could cause the display timing of your experiment computer to be different than what you think or assume it to be. Therefore, the best option in our opinion is to test your own experiment setup on a regular basis. This is not as hard to do, time consuming, or expensive as you might think. Please checkout the MilliKey DeLux and consider using it the next time you need to do some timing validation of your experiment setup. Testing display change timing has never been easier and more affordable!

Happy Hacking!

Share:

PsychoPy3 PsychHID based Keyboard API

Background

In an earlier post we used a MilliKey response box to test the time stamping accuracy of three different Python accessible keyboard event APIs when receiving 1000 Hz MilliKey USB keyboard events:

  • psychopy.event.getKeys()
  • psychopy.iohub…keyboard.getPresses()
  • Psychtoolbox Python PsychHID()

and found that Psychtoolbox PsychHID Python interface provided the most accurate keyboard event time stamps across all three OS’es tested, particularly for macOS.

PsychoPy3 keyboard.Keyboard

In this post we use the MilliKey response box to test the latest development version of PsychoPy3 and the new keyboard event handling module added by Jon Pierce, psychopy.hardware.keyboard.Keyboard.

psychopy.hardware. keyboard.Keyboard uses the Psychtoolbox PsychHID Python interface to provide accurate cross platform 1000 Hz keyboard event time stamping.

Results

psychopy.hardware. keyboard.Keyboard

PsychoPy3’s psychopy.hardware. keyboard.Keyboard module takes full advantage of the PsychHID engine to provide accurate 1000 Hz MilliKey keyboard event time stamping on Windows, Linux, and macOS. Average event latency is ~1 msec across all operating systems.

Very nice.

Comparision

In comparison, lets look at the performance of other PsychoPy keyboard event APIs.

psychopy.iohub..keyboard.getPresses()

Python3 psychopy.iohub keyboard event timing is not as consistent across operating systems. On Windows, and in particular Linux, iohub comes close to matching the performance of PsychHID, but macOS causes extra delay compared to other operating systems.

psychopy.event.getKeys()

Results for psychopy.event.getKeys() are similarly poor across operating systems. Remember that in this test keyboard events were being created during calls to win.flip(). The timing results show how big of an impact this has on time stamping error when a 60Hz monitor is used.


Happy Hacking!

Share:

PsychHID Rules!

Updated March 19th, 2019 with Linux results.

I spent some time last weekend using the MilliKey response box to test the keyboard event time-stamping accuracy of the PsychToolbox3 PsychHID library written by Mario Kleiner. Given my love of Python, I had to try out the psychtoolbox Python wrapper of PsychHID and compare it to psychopy.event.getKeys() and psychopy.iohub keyboard.getPresses().

This test also makes things a bit harder for the experiment software by having the display updated on each frame of a trial and using MilliKey to generate keyboard events between 2 and 14 msec into a retrace.

Screen capture of test script running using PsychHID. Results are amazing, especially given in this case a screen cap app was also running!

Results

We’ll start with the results and then give the source code later. All results were collected using PsychoPy 3.0.6 with Python 3.7.1.

Regardless of operating system, the computer monitor was running at 60 Hz.

1000 key press events were generated by the MilliKey device for each test, with the key event occurring between 2 and 14 msec into a window flip().

Windows 10

psychopy.event.getKeys

As would be expected, the time stamp accuracy obtained from
psychopy.event.getKeys depends on when the key press event actually occurred relative to win.flip(), with an average error of 7 msec ranging from 0.5 msec to 16.9 msec.

psychopy.iohub keyboard.getPresses()

In contrast, iohub and PsychHID perform keyboard event time-stamping asynchronously to the experiment process, so average time-stamp error is much better.

With that said, iohub does not match the raw speed of PsychHID:

Python PsychHID() KbQueue*

Linux

psychopy.event.getKeys

As was seen on Windows, the time stamp accuracy of keyboard events using event.getKeys() is totally dependent on when the key press event actually occurred relative to win.flip()

psychopy.iohub keyboard.getPresses()

iohub performance on Linux seems very good, even on Python 3.

Python PsychHID() KbQueue*

PsychHID just takes top place on Linux as well, with iohub not far behind (maybe not at all statistically).

macOS 10.13.6

Results from macOS are of particular interest because of the poor 1000 Hz USB keyboard event time-stamping results that seem to exist when using standard macOS keyboard event libraries, even in best case test conditions.

psychopy.event.getKeys

psychopy.iohub keyboard.getPresses()

The iohub results for macOS further illustrate that the extra event delay seen compared to other operating systems is likely because of macOS keyboard API overhead, even when the macos accessibility API is used. To be fair, this maybe a Python + macOS interaction, I have not tried timing a C program for example.

Python PsychHID() KbQueue*

On macOS, PsychHID is the only framework I have tested that provides 1 msec average keyboard event latency. At a very high level, I think this is because PsychHID uses HID event sniffing to detect keyboard events on macOS, bypassing the standard macOS keyboard handling APIs, and their associated delays, all together.

Python Source Code

The same test script was used to test all three event frameworks. The KB_BACKEND variable specified which backend to use for the test:

  • ‘psychopy’: Use psychopy.event.getKeys(timeStamped=True).
  • ‘iohub’: Start an iohub server and use io.devices.keyboard.getPresses().
  • ‘psychhid’: Start a Psychtoolbx HID KbQueue and use KbQueueGetEvent.
# -*- coding: utf-8 -*-
from __future__ import absolute_import, division, print_function
from psychopy import core, visual
import string
import serial
import numpy

KB_BACKEND = 'psychhid' # 'iohub', or 'psychhid'
# Serial Port of MilliKey.
mK_serial_port = 'COM3'
#mK_serial_port = '/dev/cu.usbmodem2998881'
# Number of keyboard events to generate.
kgen_count = 100
# min, max msec duration for generated keypresses.
min_dur, max_dur = 175,  300
# min, max msec MilliKey will wait before issuing the requested key press event.
min_delay, max_delay = 2, 14
possible_kgen_chars = string.ascii_lowercase + string.digits

getKeys = None
getTime = core.getTime
if KB_BACKEND == 'psychhid':
    from psychtoolbox import GetSecs
    getTime = GetSecs

if KB_BACKEND == 'psychopy':
    from psychopy import event
    def getKeys():
        return event.getKeys(timeStamped=True)
elif KB_BACKEND == 'iohub':
    global io
    from psychopy.iohub import launchHubServer
    io = launchHubServer()
    def getKeys():
        keys = io.devices.keyboard.getPresses()
        return [(k.key,k.time) for k in keys]
elif KB_BACKEND == 'psychhid':
    from psychtoolbox import PsychHID
    keys = [1] * 256
    PsychHID('KbQueueCreate', [], keys)
    PsychHID('KbQueueStart')
    # Seems like on Windows this must be called before first kb event
    # or first event has a time stamp error of ~ 20 msec.
    _ = GetSecs()
    def getKeys():
        keys = []
        while PsychHID('KbQueueFlush'):
            evt = PsychHID('KbQueueGetEvent')[0]
            if evt['Pressed']:
                K = chr(int(evt['CookedKey'])).lower()
                keys.append((K, evt['Time']))
        return keys

results = numpy.zeros(kgen_count, dtype=numpy.float64)

mk_sconn = serial.Serial(mK_serial_port, baudrate=128000, timeout=0.1)

win = visual.Window([800, 400])#, fullscr=True, allowGUI=False)
txt1 = "MilliKey Generating Key Press: [%s]\nOffset: %.1f msec. Duration: %d msec.\n%d of %d events."
msg = visual.TextStim(win, text=txt1)
dotPatch = visual.DotStim(win, color=(0.0, 1.0, 0.0), dir=270,
                          nDots=223, fieldShape='sqr',
                          fieldPos=(0.0, 0.0), fieldSize=1.5,
                          dotLife=50, signalDots='same',
                          noiseDots='direction', speed=0.01,
                          coherence=0.9)
msg.draw()
dotPatch.draw()
win.flip()

count = 0
while count < kgen_count:
    kchar = possible_kgen_chars[count % (len(possible_kgen_chars))]
    press_duration = int(numpy.random.randint(min_dur, max_dur))
    delay_evt_usec = int(numpy.random.randint(min_delay, max_delay))*1000
    evt_delay_sec = delay_evt_usec/1000.0/1000.0
    msg.setText(txt1%(kchar, delay_evt_usec/1000.0, press_duration,
                            count+1, kgen_count))
    dotPatch.draw()
    msg.draw()
    win.flip()

    # Instruct MilliKey device to:
    #  - generate a key press delay_evt_usec after receiving the KGEN command
    #  - generate key release event press_duration after press event is sent.
    kgen_cmd = "KGEN {} {} {}\n".format(kchar,
                                            press_duration,
                                            delay_evt_usec).encode()
    mk_sconn.write(kgen_cmd)
    mk_sconn.flush()
    # stime is the time the KGEN command was sent to the MilliKey device.
    # plus the event offset the device is using.
    stime = getTime()+evt_delay_sec

    # If next 3 lines are not used, PsychHID getKeys() seems to loose
    # occational keypress event on Windows 10. I could be using PsychHID()
    # incorrectly, need to investigate....
    dotPatch.draw()
    msg.draw()
    win.flip()

    # Keep checking for key press events until one is received
    kb_presses = getKeys()
    while not kb_presses:
        dotPatch.draw()
        msg.draw()
        win.flip()
        kb_presses = getKeys()

    kpress, ktime = kb_presses[0]
    if not kb_presses:
        raise RuntimeError("KGEN Timeout Error: No Key Press Event Detected.")

    # Ensure we got the key we were expecting.....
    if kchar == kpress:
        results[count] = ktime-stime
        count += 1
    else:
        txt = "Keyboard Key != Key Press Issued ([{}] vs [{}]). "
        txt += "Was a keyboard key or MilliKey button pressed during the test?"
        raise RuntimeError(txt.format(kchar, kpress))

    # Wait until after MilliKey has issued associated key release event.
    ctime = getTime()
    while getTime() - ctime < (press_duration/1000.0)*2:
        dotPatch.draw()
        msg.draw()
        win.flip()
        getKeys()

# Done test, close backend if needed
if KB_BACKEND == 'psychhid':
    PsychHID('KbQueueStop')
elif KB_BACKEND == 'iohub':
    io.quit()

mk_sconn.close()
win.close()

# Print Results
# Convert times to msec.
evt_results = results[:count] * 1000.0
print("%s Timestamp Accuracy Stats"%(KB_BACKEND))
print("\tCount: {}".format(evt_results.shape))
print("\tAverage: {:.3f} msec".format(evt_results.mean()))
print("\tMedian: {:.3f} msec".format(numpy.median(evt_results)))
print("\tMin: {:.3f} msec".format(evt_results.min()))
print("\tMax: {:.3f} msec".format(evt_results.max()))
print("\tStdev: {:.3f} msec".format(evt_results.std()))

# Plot Results
def createHistogram(data, title=None, xlabel="Time stamp Error (msec)",
                    ylabel="Probability density", nbins = 50):
    try:
        import matplotlib.pyplot as plt
        mu, sigma = data.mean(), data.std()
        # the histogram of the data
        n, bins, patches = plt.hist(data, nbins, density=1,
                                    facecolor='green', alpha=0.75)
        # add a 'best fit' line
        y = ((1 / (numpy.sqrt(2 * numpy.pi) * sigma)) *
             numpy.exp(-0.5 * (1 / sigma * (bins - mu))**2))
        plt.plot(bins, y, '--')
        plt.xlabel(xlabel)
        plt.ylabel(ylabel)
        if title is None:
            title = r"Histogram"
        title = r'$\mathrm{%s:}\ \mu=%.3f,\ \sigma=%.3f$'%(title,mu,sigma)
        plt.title(title)
        plt.grid(True)
        plt.tight_layout()
        plt.show()
    except:
        print("Could not create Histogram:\n\ttitle: {}\n\tlabel: {}\n\tylabel: {}".format(title, xlabel, ylabel))

createHistogram(evt_results,"%s\ Time\ Stamp\ Accuracy"%(KB_BACKEND))

core.quit()

Conclusions

Hopefully this post provides some useful information about the time stamping accuracy you should expect to achieve when using a 1000 Hz USB keyboard with different operating systems and keyboard event APIs. I hope it also illustrates how useful the MilliKey response box can be in testing 1000 Hz USB keyboard event delay and time stamping error.

If you are using macOS and want to really get events with 1 msec delay, then you must really use PsychHID, no matter what the response box maker claims (that includes us!).

When using Windows 10, psychopy.event.getKeys() provides acceptable time stamp accuracy when your experiment script is only checking for keyboard events during the trial. If the experiment updates the display frequently during a trial, psychopy.iohub or PsychHID should be used.

Looking forward to PsychHID based keyboard event monitoring being added to PsychoPy in the future.


PsychHID is really quite amazing; nice job Mario!

Happy Hacking!

Share:

Test Visual Stimulus Onset Timing using Keyboard Events !?

In this post we look at how to use the MilliKey DeLux light sensor upgrade to test visual stimulus onset timing using PsychoPy Coder by checking for a keyboard event.

MilliKey DeLux Light Sensor Upgrade

The MilliKey DeLux is an affordable and easy to use light sensor attachment for MilliKey response boxes. The MilliKey DeLux can generate light level driven 1000 Hz USB serial or keyboard events that are read by the same experiment software controlling visual stimulus presentation.

In a previous post about Testing PsychoPy event.waitKeys() Event Timing, we demonstrated how to use the MilliKey to test the keyboard event time stamping accuracy of the experiment software. This was achieved by sending USB serial messages from the experiment software instructing the MilliKey to generate keyboard events and then comparing the key press time to the time the serial message was sent. We found that, at least on Windows and Linux, PsychoPy can accurately time stamp MilliKey 1000 Hz keyboard events with one millisecond average delay and sub-millisecond variability.

One of the unique features of the MilliKey DeLux is that it can be configured to generate a letter ‘l’ key press event when the light sensor brightness crosses a trigger threshold level. This allows you to assess visual stimulus onset timing of an experiment by using the standard keyboard event handling functionality of the software being used.

PsychoPy Coder Test Script

Lets start by creating a simple PsychoPy Coder demo that repeatedly:

  • clears the screen to black
  • draws a white screen
  • waits for a keyboard press event
  • prints time difference between reported keyboard event and stimulus onset (white screen) times.
#!/usr/bin/env python
# -*- coding: utf-8 -*-
from __future__ import absolute_import, division, print_function
from psychopy import visual, event, core

# Number of dark -> light display change tests to run
test_count = 10

# Create a full screen window and two full screen stim.
win = visual.Window(fullscr=True, screen=0)
white_stim = visual.ShapeStim(win, lineColor='white', fillColor='white',
                              vertices=((-1,-1),(1,-1),(1,1),(-1,1)))
dark_stim = visual.ShapeStim(win, lineColor='black', fillColor='black',
                             vertices=((-1,-1),(1,-1),(1,1),(-1,1)))

# draw / setup both stim
white_stim.draw()
dark_stim.draw()
win.flip()

# Manually press any key to start test
event.waitKeys(timeStamped=True)

print("trial\tRT\tkey_time\tflip_time\tkey")
# run test_count loops
count=0
while count < test_count:
    # Draw black screen and display it for about 0.5 seconds.
    dark_stim.draw()
    win.flip()
    core.wait(0.5)
	# Throw away any possible junk keys
	# prior to changing display 
    event.getKeys()
	
    # Draw white (target) stim and flip to it,
    # getting time flip occurred (stim onset)
    # time from psychopy.
    white_stim.draw()
    ftime = win.flip()

	# Key keyboard event and print time difference between
	# flip() time and keypress time.
    k, ktime = event.waitKeys(timeStamped=True)[0]
    kdelay = ktime - ftime    
    print("%d\t%.6f\t%.6f\t%.6f\t%s"%(count, kdelay, ftime, ktime, k))

    core.wait(0.25)
    count+=1

We have basically created the most simple of manual reaction time tests. Run the above script from PsychoPy Coder and press a key as quickly as you can each time the screen turns white.

For example, running the example and manually pressing the space key, I get output like:

trial	RT	key_time	flip_time	key
0	0.368140	1.687949	2.056089	space
1	0.171302	2.570518	2.741820	space
2	0.197275	3.256913	3.454187	space
3	0.198487	3.967356	4.165843	space
4	0.196070	4.679771	4.875841	space
5	0.215323	5.390571	5.605894	space
6	0.197549	6.118132	6.315682	space
7	0.193179	6.828715	7.021894	space
8	0.166193	7.535785	7.701978	space
9	0.193039	8.214774	8.407813	space

So far this has all been kind of boring right?

What if we could use this exact script to test the visual onset timing of the white screen? Lets do it using the MilliKey DeLux.

MilliKey DeLux Setup

For this test to work we first need to make sure the MilliKey DeLux is configured to:

  1. use a sensible threshold level for the monitor being Generate Keyboard Events.
  2. auto generate light sensor triggered keyboard events.

Lets do this using the LabHackers’ Device Manager application.

LabHackers' Device Manager DeLux Setting Tab

MilliKey DeLux light sensor settings are found on the DeLux tab of the LabHackers’ Device Manager application.

For this example use the following settings:
Trigger Type: ‘Keyboard Event’
Trigger Delay: 5 msec
Enable Background Processing: Checked / True

The Trigger Threshold setting can be set using the auto threshold feature of the Light Sensor Dialog. The following video is a screen capture from a Windows 10 computer running the Labhackers’ Device Manager application. It illustrates using the auto threshold feature to set the light sensor threshold to an appropriate level for the monitor being tested. The MilliKey DeLux hardware, which can not be seen in the video, was placed over the white rectangle of the test dialog on the LCD monitor.

Using LabHackers’ Device Manager to Configure a MilliKey DeLux light sensor.

After you have configured the MilliKey DeLux to generate ‘offline’ keyboard events, and have exited the LabHackers’ Device Manager, the MilliKey will generate a ‘l’ key press event 5 milliseconds (Trigger Delay) after screen brightness crosses the threshold level set. Each key press lasts 123 msec, at which time a key release event is sent by the MilliKey.

Note: Once the MilliKey DeLux is armed and ready to create keyboard events, if the light level hitting the is not controlled you may get a bunch of letter ‘l’s being typed on your computer. If you want to abort this test and get the MilliKey to stop generating keyboard events, unplug the MilliKey USB cable from the computer and reconnect it. This turns off the Enable Background Processing setting, which is disabled by default when you first connect the MilliKey to a computer.

Results

For this test we used a Windows 7 computer connected to a CRT monitor running at 60Hz. We used a CRT monitor because there is effectively no delay between when a video card starts a screen retrace and when the top left corner of the CRT monitor starts displaying update. In contrast LCD / TFT monitors all have a response time, which can range between 1 and 10+ msec depending on the monitor model.

trial   RT      key_time        flip_time       key
0       0.004892        4.412357        4.417248        l
1       0.005464        5.188762        5.194226        l
2       0.005237        5.976979        5.982216        l
3       0.005049        6.765145        6.770194        l
4       0.004792        7.553340        7.558132        l
5       0.005583        8.341535        8.347118        l
6       0.005390        9.129753        9.135143        l
7       0.005198        9.917925        9.923123        l
8       0.005766        10.694352       10.700118       l
9       0.005555        11.482574       11.488128       l

Since a CRT monitor was used, the time difference between win.flip() and when the CRT actually starts being updated should be 0.0 msec. Remember that we set the MilliKey DeLux to generate the key press event 5 msec after the stimulus onset was detected by the device hardware, so if win.flip() is accurate, the delay calculated by the test should be 0.0 after we subtract the 5 msec event delay specified in the device settings.

As the following table shows, they are:

00.0049-0.0001
10.00550.0005
20.00520.0002
30.00500.0000
40.0048-0.0002
50.00560.0006
60.00540.0004
70.00520.0002
80.00580.0008
90.00560.0006

It is important to note that using keyboard events as light sensor triggers is only suggested on systems that provide accurate keyboard event timing. Therefore we can not suggest this method for PsychoPy testing on macOS at this time. macOS users should use the Serial event mode, which we will demonstrate in a future post.

Next

The MilliKey DeLux keyboard event mode is very useful for testing stimulus onset timing in experiment software that you know provides accurate keyboard event timing and when you can not, or do not, want to add custom code to your experiment.

If the keyboard event time stamping accuracy of the software being used is poor, or you would rather not get light sensor triggers as keyboard events, then you can use USB Serial events instead. In the next MilliKey DeLux post, we will look at using the Serial trigger type to test stimulus onset timing in a PsychoPy Coder experiment.

Happy Hacking!

Share:

Testing PsychoPy event.waitKeys() Event Timing

As discussed in my last post, the LabHackers’ MilliKey button box includes the ability to generate 1000 Hz USB keyboard events after receiving a KGEN serial command. (BTW, the USB2TTL8 also supports the KGEN command.)

One of the main uses of the KGEN command is to test keyboard event timing from within your experiment software without the need to use extra external hardware. In this post we look at how to test the time stamping accuracy of the PsychoPy event.waitKeys() function using KGEN.

Why test?

You might be wondering why, given the MilliKey is a 1000 Hz response box that generates keyboard events with 1 msec average latency, it is important to be able to test keyboard event timing from within your experiment software? Why can’t we just subtract one msec from key press time stamps and assume everything is OK? Two reasons:

  1. 1000 Hz USB HID Keyboard latency can be influenced by the operating system and other USB hardware connected to the computer.
  2. Keyboard events are time stamped by the experiment software being used, not the response box hardware itself.

Therefore it is not safe to rely solely on the device specifications; timing really should be tested and verified within the experiment software being used.

Python Example

#!/usr/bin/env python
# -*- coding: utf-8 -*-
"""
IMPORTANT: Set the mK_serial_port variable below to the correct
           serial port string for the MilliKey to be tested.

Example of testing the latency of MilliKey keyboard events and event time 
stamping accuracy when using core.waitKeys() within a PsychoPy script.

While the demo runs, keyboard events are generated by the
MilliKey device based on serial commands sent from the script.

**DO NOT PRESS ANY KEYS OR MILLIKEY BUTTONS DURING THE TEST.**
"""
from __future__ import absolute_import, division, print_function

from psychopy import visual, event, core
import serial
import string
import numpy

# Serial Port of MilliKey.
mK_serial_port = 'COM138'

# Number of keyboard events to generate.
kgen_count = 100

# min, max msec duration for generated keypresses.
min_dur, max_dur = 175,  300

# Usec MilliKey will wait before issuing the requested key press event.
delay_evt_usec = 5000

possible_kgen_chars = string.ascii_lowercase + string.digits
results = numpy.zeros(kgen_count, dtype=numpy.float64)
mk_sconn = serial.Serial(mK_serial_port, baudrate=128000, timeout=0.1)

win = visual.Window([600, 400])
msg = visual.TextStim(win, text='Creating Key Press: [] (duration of {} msec)')
msg.draw()
win.flip()

evt_delay_sec = delay_evt_usec/1000.0/1000.0
kb_presses = ['']
count = 0
run = True
txt1 = "Generating Key Press: [{}] (duration of {} msec)\n{} of {} events."
while run is True and count < kgen_count:
    kchar = possible_kgen_chars[count % (len(possible_kgen_chars))]
    press_duration = int(numpy.random.randint(min_dur, max_dur))
    msg.setText(txt1.format(kchar, press_duration, count+1, kgen_count))
    msg.draw()
    win.flip()
    kgen_cmd = "KGEN {} {} {}\n".format(kchar,
                                            press_duration,
                                            delay_evt_usec).encode()
    mk_sconn.write(kgen_cmd)
    stime = core.getTime()+evt_delay_sec
    kb_presses = event.waitKeys(maxWait=1.0)
    ktime = core.getTime()
    if not kb_presses:
        raise RuntimeError("KGEN Timeout Error: No Key Press Event Detected.")
    for kbp in kb_presses:
        if kbp in ['escape', 'esc']:
            run = False
            break
    if run is False:
        continue
    kpress = kb_presses[0]
    if kchar == kpress:
        results[count] = ktime-stime
        core.wait((press_duration/1000.0)*1.2)
        count += 1
    else:
        txt = "Keyboard Key != Key Press Issued ({} vs {}). "
        txt += "Was a keyboard key or MilliKey button pressed during the test?"
        raise RuntimeError(txt.format(kchar, kpress))

mk_sconn.close()
win.close()

# Convert times to msec.
results = results[:count] * 1000.0

print("MilliKey Keyboard Press Event Delay (Timestamp Accuracy) Stats")
print("\tCount: {}".format(results.shape))
print("\tAverage: {:.3f} msec".format(results.mean()))
print("\tMedian: {:.3f} msec".format(numpy.median(results)))
print("\tMin: {:.3f} msec".format(results.min()))
print("\tMax: {:.3f} msec".format(results.max()))
print("\tStdev: {:.3f} msec".format(results.std()))

core.quit()

Test Results

Windows 10

Running PsychoPy 3.0.5.

MilliKey Keyboard Press Event Delay (Timestamp Accuracy) Stats
    Count: (100,)
    Average: 1.012 msec
    Median: 0.982 msec
    Min: 0.509 msec
    Max: 1.633 msec
    Stdev: 0.303 msec

Linux (Mint 18.3)

 MilliKey Keyboard Press Event Delay (Timestamp Accuracy) Stats
	Count: (100,)
	Average: 0.899 msec
	Median: 0.898 msec
	Min: 0.350 msec
	Max: 1.499 msec
	Stdev: 0.309 msec

When a PsychoPy experiment script, running on Windows or Linux, can simply wait for MilliKey keyboard events, there is an average difference of ~ 1.0 msec between when the KGEN command is sent by the script and when the keyboard event is received by PsychoPy. If we subtract the time it takes to send a KGEN command, which is 0.3 msec on average, then the average MilliKey key press latency in this test would be about 1.0 – 0.3 = 0.7 msec.

macOS 10.13.6

Running PsychoPy 3.0.5.

MilliKey Keyboard Press Event Delay (Timestamp Accuracy) Stats
Count: (100,)
Average: 4.755 msec
Median: 4.608 msec
Min: 3.679 msec
Max: 18.594 msec
Stdev: 1.445 msec

The average keyboard delay from the same script running on macOS is longer and also more variable than other operating systems tested. It seems, for example, that the first keyboard event received after the python interpreter starts is delayed by an extra 10 or more milliseconds. Results with first event removed:

 MilliKey Keyboard Press Event Delay (Timestamp Accuracy) Stats
    Count: (99,)
    Average: 4.615 msec
    Median: 4.597 msec
    Min: 3.679 msec
    Max: 5.939 msec
    Stdev: 0.394 msec

Remember that the USB serial latency on macOS is under 1 msec, as would be expected, so the additional delay in receiving keyboard events seems to be specific to processing done by the macOS operating system or the underlying keyboard event handling libraries used.

This pattern of results does not seem to be specific to PsychoPy event.waitKeys(). I have also tested using pygame, glfw, pyqt4 and pyqt5 and all show a similar pattern of results across operating systems.

If you have a LabHackers device, please let us know if you your results are consistent with this or not. For that matter, if you have done actual keyboard event delay testing using any method on macOS, it would be great to see the results.

Notes

It is important to recognize that using KGEN to test keyboard event timing has the following caveats:

  1. Timing results can only be generalized to other 1000 Hz USB HID Keyboard hardware that has a 0 millisecond debounce time.
  2. Given the sub millisecond jitter that will occur when sending each serial KGEN command, test results should be considered accurate to within 0.5 msec, even though the resolution of the timing is much greater.

Even with these in mind, we think KGEN is pretty useful and hope you do too.

Happy Hacking!

Share: