SDL: Bisected slowness in 2.30.0 when initializing gamepads

This is on Linux.

When calling SDL_Init(SDL_INIT_GAMECONTROLLER), 2.30 is noticeably slower for me than 2.28: 3 seconds vs 0.5 seconds.

I’ve bisected it to commit 3b1e0e16.

From what I can tell, the slowness is due to SDL_UDEV_GetProductInfo(). Prior to the bisected commit, this function was only called when a JSIOCGNAME ioctl was successful, i.e. if a Joystick name could be obtained; so at most it’s called as many times as there are connected joysticks. Now it’s called unconditionally, presumably at least as many times as there are input devices attached, and on my system, it takes around 100ms to run. I have 21 /dev/input/event* files, so that’s 2100ms.

About this issue

  • Original URL
  • State: closed
  • Created 4 months ago
  • Comments: 127 (35 by maintainers)

Commits related to this issue

Most upvoted comments

Okay. That sounds good. see from the flamegraph all the CPU sleeping is no window/graphics related now too.

I’ll open a new pull request for the speed branch and the merits of it can be discussed there as this one was really closed quite awhile back when the O(n^2) behavior was fixed.

Thanks for all the testing a reporting!

I figure there’s not much for me to add at this point, but I’d like to say that this does matter to me because these startup times add up especially during development. I was wondering if I can mitigate this locally by initializing the gamepad subsystem separately, in a secondary thread? It’s hard to find info on thread safety besides video functions

Sophisticated test setup 😃

image

offcputime profile

Sorry that wasn’t clear. No need to setup nix. You can just directly extract the tarball and run it.

It should still be okay to extract it even if you have setup nix though. The packages just won’t be registered in the system database.

My -fno-omit-frame-pointer build finally finished and I got a full stack trace from my home machine that has two joysticks attached.

Here is a self contained version of the executable and all it’s dependencies. If you unpack it to your root filesystem you should be able to run it.

ls /nix/store/*sdl2-test-*/libexec/installed-tests/SDL2/

It all lives under /nix so easy to cleanup with an rm command. Ignore the version number. It is my walking branch. I just forgot to update the packaging name.

I commented out the while (!done) { loop(NULL); } lines and added a 30s pause at the start of main and another 30s pause before SDL_QuitSubSystem at the of main in testgamecontroller. This lets you start it, count 10s, and then run

offcputime -f -p (ps -A | awk -e '$4 == "testgamecontrol" { print($1) }') 40 | flamegraph.pl --countname us > offcputime.svg

as root to capture the off-cpu profile.

It is critical that this command starts before the initial 30s sleep ends and ends after the final 30s sleep starts but before it ends. If this doesn’t happen, the start and end times of all sleeps between the sleeps won’t be caught to calculate all time deltas and the libraries required for looking up symbols upon completion may not be still present.

After, you can run it again, count 10s, and do

profile -f -p  $(ps -A | awk -e '$4 == "testgamecontrol" { print($1) }') -F 1000 40 | flamegraph.pl --countname ms > profile.svg

to capture an on-cpu profile too.

Holy crap this is kernel. I had used this kernel before as it’s a 6.1 with Valve’s patches included. Just tried it and it completely solves the issue

https://github.com/rog-ally-gaming/linux-chimeraos/releases/tag/6.1.81.nrflx3-2

[parker@rogally sdl2-git]$ time ./src/SDL/test/testgamecontroller 
INFO: There are 0 game controller(s) attached (0 joystick(s))

real    0m0.703s
user    0m0.062s
sys     0m0.070s

Samply https://share.firefox.dev/49dPNqc

Right. I reversed those when I cut and pasted into the comment. I changed it to SDL_TRUE. There was a routine that conditionally ets it to SDL_FALSE, so that may be triggering for you and not me.

Removing all my USB peripherals takes me to an initialization time of ~1.15s.

That is a neat tool.

It looks like you’re not running the latest code with @twhitehead’s changes. Inside SDL_UDEV_GetProductInfo() there is a call to udev_device_new_from_devnum() instead of udev_enumerate_scan_devices().

Can you try updating to the latest code from git and trying again?

It seems odd that an open() call would take a long time. Did you add a print immediately afterwards to get the timing on that?

Start in LINUX_JoystickDetect() and sprinkle them throughout the functions being called there.

Are you able to reproduce this with the SDL2 testgamecontroller program? There’s a bunch of work that wine is doing in there that seems unrelated.

@twhitehead I am not well versed enough in how to use gprof to test with that at the moment. What exactly do I compile with -pg? I tried adding it to the CFLAGS when building SDL2 (perhaps incorrectly) but did not get a gmon.out file when running my test program, and adding it to the program instead seems to get me empty profiling info.

Either way, I noticed there’s a difference when running with or without my DualShock 4 controller. Re-tested with and without the controller connected, after restarting the computer (previous slow times were due to a rogue background process):

2.28.5: disconnected: 820ms connected: 1.22s

2.30.1: disconnected: 4.14s connected: 5.26s

walking: disconnected: 1.65s connected: 2.08s

@twhitehead, I merged your patch, thanks!

Can you create a PR against SDL main?

This same bug affects WINE. Every fresh prefix start (Not already running) takes 4-8 seconds to load due to SDL init hanging the process.

DEBUG: Failed loading udev_device_get_action: /usr/lib/libSDL2-2.0.so.0: undefined symbol: _udev_device_get_action

Thanks for the very thorough report. I am having a look at this.