Another post about latency

My previous work on that subject

I already worked on measuring how much latency the sixaxis emulator is adding compared to a real sixaxis. I did that using a microphone, measuring the overall response time for a gunshot.

Assuming we have:
R=C+G
R=overall response time
C=controller latency
G=game latency

For the real sixaxis:
R1=C1+G
For the sixaxis emulator:
R2=C2+G

Assuming G is constant:
R2-R1=C2-C1

To estimate the controller latency difference, which is C2-C1, I just had to subtract the overall response time.
The result was about 15ms, which is not that bad compared to the overall response time (>100ms) and the human response time (>100ms).

A way to estimate the latency of the sixaxis emulator

The basic idea is to measure the time between a usb packet coming from the mouse (or any other usb controller) and a packet sent to the usb bt dongle.

For ex, the time between the usb packet for a left clic and the usb packet that sends the R1 button press (via the bluetooth dongle).

A great tool provided with the Linux kernel is usbmon, which allows to sniff the usb traffic. It’s possible to use it with wireshark (with root user rights), but it’s better to play in a terminal to automate extraction of valuable information.

The usbmon documentation is available there: link.

First of all, what the lsusb output says:

matlo@matlo-hcpc:~/hack/test$ lsusb
Bus 004 Device 002: ID 050d:0200 Belkin Components
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 009: ID 054c:0268 Sony Corp. Batoh Device
Bus 003 Device 008: ID 0a12:0001 Cambridge Silicon Radio, Ltd Bluetooth Dongle (HCI mode)
Bus 003 Device 006: ID 054c:0268 Sony Corp. Batoh Device
Bus 003 Device 005: ID 046d:c041 Logitech, Inc. G5 Laser Mouse
Bus 003 Device 003: ID 046d:c517 Logitech, Inc. LX710 Cordless Desktop Laser
Bus 003 Device 002: ID 058f:9254 Alcor Micro Corp. Hub
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 002 Device 003: ID 046d:0809 Logitech, Inc. Webcam Pro 9000
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

What is useful there is the bus and device ids. The G5 mouse is device 5 on usb bus 3, and the bt dongle is device 8 on usb bus 3.

To start the capture:

matlo@matlo-hcpc:~/hack/test$ sudo cat /sys/kernel/debug/usb/usbmon/0u > test

Generate left clics into the sixaxis emulator, and stop the capture (ctrl+c).

Then, to display the mouse packets:

matlo@matlo-hcpc:~/hack/test$ cat test.txt | grep “3:005”

And for the bt dongle packets:

matlo@matlo-hcpc:~/hack/test$ cat test.txt | grep “3:008”

Both these commands may give a huge amount of data.

To only display packets that correspond to left clicks:

matlo@matlo-hcpc:~/hack/test$ cat test.txt | grep “3:005:1 0:1 10 = 01000000 00000000 0000”
f6747a40 967102843 C Ii:3:005:1 0:1 10 = 01000000 00000000 0000
f6747a40 968852805 C Ii:3:005:1 0:1 10 = 01000000 00000000 0000
f6747a40 970341772 C Ii:3:005:1 0:1 10 = 01000000 00000000 0000
f6747a40 971609742 C Ii:3:005:1 0:1 10 = 01000000 00000000 0000
f6747a40 972760716 C Ii:3:005:1 0:1 10 = 01000000 00000000 0000

To only display packets that correspond to R1 button presses:

matlo@matlo-hcpc:~/hack/test$ cat test.txt | grep “3:008:2 -115 58 = 2b203600 32004300 a1010000 08000080 80808000 00000000 00000000 0000ff00”
f32e2640 967105205 S Bo:3:008:2 -115 58 = 2b203600 32004300 a1010000 08000080 80808000 00000000 00000000 0000ff00
f32e2640 968861926 S Bo:3:008:2 -115 58 = 2b203600 32004300 a1010000 08000080 80808000 00000000 00000000 0000ff00
f32e2640 970345964 S Bo:3:008:2 -115 58 = 2b203600 32004300 a1010000 08000080 80808000 00000000 00000000 0000ff00
f3a904c0 971618231 S Bo:3:008:2 -115 58 = 2b203600 32004300 a1010000 08000080 80808000 00000000 00000000 0000ff00
f3a90ac0 972769407 S Bo:3:008:2 -115 58 = 2b203600 32004300 a1010000 08000080 80808000 00000000 00000000 0000ff00

What is to be extracted from this is the timestamp in microseconds, which is the second column.

matlo@matlo-hcpc:~/hack/test$ cat test.txt | grep “3:005:1 0:1 10 = 01000000 00000000 0000” | awk ‘{ print $2 }’
967102843
968852805
970341772
971609742
972760716

matlo@matlo-hcpc:~/hack/test$ cat test.txt | grep “3:008:2 -115 58 = 2b203600 32004300 a1010000 08000080 80808000 00000000 00000000 0000ff00” | awk ‘{ print $2}’
967105205
968861926
970345964
971618231
972769407

Then, it’s easy to copy-paste this data into a spreadsheet, compute the difference, compute the average, and the standard deviation.

For this example (with 5 more samples), it gives a 7.6ms average difference, with a 2.9ms standard deviation. The max difference is about 12ms.

It has to be reminded that the event polling period is 10ms (equal to the sixaxis report period), so that the maximum latency added by the event polling is 10ms, and the average is 5ms. Thus, the processing time is in average 7.6-5=2.6ms. It has to be noticed that I’m using a Linux kernel with realtime/low latency capabilities.

It’s also possible that there is some more latency added by the usb stack and the bt dongle, but it’s probably less than the 7.6ms processing time.

Conclusion:

– it’s probably not possible to have a lower response time with a sixaxis emulation (bt or usb)
– to lower the controller latency, the only potential way is to use a usb device to usb device controller (a custom usb link between the PC and the PS3), with a report period lower than 10ms

Thanks to that work I found a latency issue (about 50ms) that only impacts left and right mouse clics. The work-around -I’m not joking!- is to press the middle button after the mouse is plugged to the PC (see next post).

2 Replies to “Another post about latency”

Leave a Reply

Your email address will not be published. Required fields are marked *