Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

daemon crash on subsequent joystick reconnections #43

Closed
maxb-odessa opened this issue May 22, 2022 · 6 comments
Closed

daemon crash on subsequent joystick reconnections #43

maxb-odessa opened this issue May 22, 2022 · 6 comments
Labels
bug

Comments

@maxb-odessa
Copy link

x52d daemon coredumps on subsequent physical joystick reconnections
Diagnostics below:

journalctl -xu x52d

May 22 17:07:31 flatbox.home x52d[1703]: INFO: x52d_device.c:73 Initializing libx52
May 22 17:07:31 flatbox.home x52d[1703]: INFO: x52d_device.c:35 Starting X52 device manager thread
May 22 17:07:31 flatbox.home x52d[1703]: INFO: x52d_clock.c:170 Starting X52 clock manager thread
May 22 17:31:46 flatbox.home x52d[1703]: libusb: error [udev_hotplug_event] ignoring udev action change
May 22 17:31:51 flatbox.home x52d[1703]: INFO: x52d_device.c:51 Device connected, writing configuration
May 22 21:59:45 flatbox.home x52d[1703]: libusb: error [udev_hotplug_event] ignoring udev action change
May 22 21:59:51 flatbox.home x52d[1703]: INFO: x52d_device.c:51 Device connected, writing configuration
May 22 21:59:51 flatbox.home x52d[1703]: libusb: error [do_close] Device handle closed while transfer was still being processed, but the device is still connected as far as we know
May 22 21:59:51 flatbox.home x52d[1703]: libusb: error [do_close] A cancellation hasn't even been scheduled on the transfer for which the device is closing
May 22 21:59:51 flatbox.home systemd[1]: x52d.service: Main process exited, code=dumped, status=11/SEGV

coredumpctl debug

       PID: 1703 (x52d)
       UID: 0 (root)
       GID: 0 (root)
    Signal: 11 (SEGV)
 Timestamp: Sun 2022-05-22 21:59:51 EEST (1h 53min ago)

Command Line: /usr/local/bin/x52d -f -v
Executable: /usr/local/bin/x52d
Control Group: /system.slice/x52d.service
Unit: x52d.service
Slice: system.slice
Boot ID: 5b95a2343be14ea8bc1da55cd88710b7
Machine ID: e33d9124cc344be3a8d2422f1d6be8ba
Hostname: flatbox.home
Storage: /var/lib/systemd/coredump/core.x52d.0.5b95a2343be14ea8bc1da55cd88710b7.1703.1653245991000000.zst (present)
Disk Size: 67.6K
Message: Process 1703 (x52d) of user 0 dumped core.

            Found module linux-vdso.so.1 with build-id: 250ccfeac05063b6aec6b9e764aab14fe7a350ad
            Found module libgcc_s.so.1 with build-id: b6870691657424bce223a2e63e40a74a86865cd4
            Found module ld-linux-x86-64.so.2 with build-id: 1c439781d708688791a444ca9fb2d427e77e0711
            Found module libudev.so.1 with build-id: 349aae4b9b0f8015c69d8c61f20191b6400e6903
            Found module libc.so.6 with build-id: cd3fe5b329409691a824712f6b1335893c5ca7e7
            Found module libusb-1.0.so.0 with build-id: 87775348a4f4614d71a366d83c79d9f9498e72a2
            Found module libx52.so.2 with build-id: 20444272d1da9d5a3c47f64739587c4d6b83d70e
            Found module x52d with build-id: d7abb6073b8c460ac41f0b44bf5a2ccef284f9bd
            Stack trace of thread 1736:
            #0  0x00007f98b6820015 libusb_control_transfer.cold (libusb-1.0.so.0 + 0x5015)
            #1  0x00007f98b683c2f0 libx52_vendor_command (libx52.so.2 + 0x22f0)
            #2  0x00007f98b683c64c libx52_update (libx52.so.2 + 0x264c)
            #3  0x000000000040879d x52d_dev_update (x52d + 0x879d)
            #4  0x0000000000408978 x52_dev_thr (x52d + 0x8978)
            #5  0x00007f98b66b28ca start_thread (libc.so.6 + 0xa08ca)
            #6  0x00007f98b6652500 __clone3 (libc.so.6 + 0x40500)
            
            Stack trace of thread 1703:
            #0  0x00007f98b675596f __poll (libc.so.6 + 0x14396f)
            #1  0x0000000000409d6d poll_clients (x52d + 0x9d6d)
            #2  0x00000000004029b0 main (x52d + 0x29b0)
            #3  0x00007f98b6652f60 __libc_start_call_main (libc.so.6 + 0x40f60)
            #4  0x00007f98b6653010 __libc_start_main@@GLIBC_2.34 (libc.so.6 + 0x41010)
            #5  0x00000000004031d5 _start (x52d + 0x31d5)
            
            Stack trace of thread 1737:
            #0  0x00007f98b6726ce5 clock_nanosleep@GLIBC_2.2.5 (libc.so.6 + 0x114ce5)
            #1  0x00007f98b672b887 __nanosleep (libc.so.6 + 0x119887)
            #2  0x00007f98b672b7be sleep (libc.so.6 + 0x1197be)
            #3  0x0000000000408aea x52_clock_thr (x52d + 0x8aea)
            #4  0x00007f98b66b28ca start_thread (libc.so.6 + 0xa08ca)
            #5  0x00007f98b6652500 __clone3 (libc.so.6 + 0x40500)
            
            Stack trace of thread 1717:
            #0  0x00007f98b675596f __poll (libc.so.6 + 0x14396f)
            #1  0x00007f98b68278d2 linux_udev_event_thread_main (libusb-1.0.so.0 + 0xc8d2)
            #2  0x00007f98b66b28ca start_thread (libc.so.6 + 0xa08ca)
            #3  0x00007f98b6652500 __clone3 (libc.so.6 + 0x40500)

GNU gdb (GDB) Fedora 11.2-2.fc35
Copyright (C) 2022 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
https://www.gnu.org/software/gdb/bugs/.
Find the GDB manual and other documentation resources online at:
http://www.gnu.org/software/gdb/documentation/.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/local/bin/x52d...
[New LWP 1736]
[New LWP 1703]
[New LWP 1737]
[New LWP 1717]

warning: Section `.reg-xstate/1736' in core file too small.

This GDB supports auto-downloading debuginfo from the following URLs:
https://debuginfod.fedoraproject.org/
Enable debuginfod for this session? (y or [n]) y
Debuginfod has been enabled.
To make this setting permanent, add 'set debuginfod enabled on' to .gdbinit.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/local/bin/x52d -f -v'.
Program terminated with signal SIGSEGV, Segmentation fault.

warning: Section `.reg-xstate/1736' in core file too small.
#0 usbi_handling_events (ctx=) at /usr/src/debug/libusb1-1.0.25-8.fc35.x86_64/libusb/libusbi.h:484
484 return usbi_tls_key_get(ctx->event_handling_key) != NULL;
[Current thread is 1 (Thread 0x7f98a8897640 (LWP 1736))]
@nirenjan
Copy link
Owner

I'd have to check why this is happening, and I don't have access to my joystick right now, so I can't reproduce this at home. Can you enable trace logging and capture the logs? You should be able to do this by running the daemon with the -vvvv flag.

@maxb-odessa
Copy link
Author

Sure, here is the log (I'm made 2-3 joystick plugin/plugouts):
DEBUG: x52d_main.c:343 Foreground = true
DEBUG: x52d_main.c:344 Quiet = false
DEBUG: x52d_main.c:345 Verbosity = 4
DEBUG: x52d_main.c:346 Log file = (null)
DEBUG: x52d_main.c:347 Config file = (null)
DEBUG: x52d_main.c:348 PID file = (null)
DEBUG: x52d_main.c:349 Command socket = (null)
TRACE: x52d_config_parser.c:188 Setting configuration defaults
TRACE: x52d_config_parser.c:159 Setting 'Clock.Enabled'='true'
TRACE: x52d_config_parser.c:159 Setting 'Clock.PrimaryIsLocal'='true'
TRACE: x52d_config_parser.c:159 Setting 'Clock.Secondary'='UTC'
TRACE: x52d_config_parser.c:159 Setting 'Clock.Tertiary'='UTC'
TRACE: x52d_config_parser.c:159 Setting 'Clock.FormatPrimary'='12hr'
TRACE: x52d_config_parser.c:159 Setting 'Clock.FormatSecondary'='12hr'
TRACE: x52d_config_parser.c:159 Setting 'Clock.FormatTertiary'='12hr'
TRACE: x52d_config_parser.c:159 Setting 'Clock.DateFormat'='ddmmyy'
TRACE: x52d_config_parser.c:159 Setting 'LED.Fire'='on'
TRACE: x52d_config_parser.c:159 Setting 'LED.Throttle'='on'
TRACE: x52d_config_parser.c:159 Setting 'LED.A'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.B'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.D'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.E'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.T1'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.T2'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.T3'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.POV'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.Clutch'='green'
TRACE: x52d_config_parser.c:159 Setting 'Brightness.MFD'='128'
TRACE: x52d_config_parser.c:159 Setting 'Brightness.LED'='128'
TRACE: x52d_config_parser.c:159 Setting 'Mouse.Enabled'='true'
TRACE: x52d_config_parser.c:159 Setting 'Mouse.Speed'='0'
TRACE: x52d_config_parser.c:159 Setting 'Profiles.Directory'='/etc/x52d/profiles.d'
TRACE: x52d_config_parser.c:159 Setting 'Profiles.ClutchEnabled'='false'
TRACE: x52d_config_parser.c:159 Setting 'Profiles.ClutchLatched'='false'
TRACE: x52d_config_parser.c:206 Loading configuration from file /usr/local/etc/x52d/x52d.conf
TRACE: x52d_config_parser.c:159 Setting 'Clock.Enabled'='yes'
TRACE: x52d_config_parser.c:159 Setting 'Clock.PrimaryIsLocal'='yes'
TRACE: x52d_config_parser.c:159 Setting 'Clock.Secondary'='UTC'
TRACE: x52d_config_parser.c:159 Setting 'Clock.Tertiary'='UTC'
TRACE: x52d_config_parser.c:159 Setting 'Clock.FormatPrimary'='24hr'
TRACE: x52d_config_parser.c:159 Setting 'Clock.FormatSecondary'='24hr'
TRACE: x52d_config_parser.c:159 Setting 'Clock.FormatTertiary'='24hr'
TRACE: x52d_config_parser.c:159 Setting 'Clock.DateFormat'='ddmmyy'
TRACE: x52d_config_parser.c:159 Setting 'LED.Fire'='on'
TRACE: x52d_config_parser.c:159 Setting 'LED.Throttle'='on'
TRACE: x52d_config_parser.c:159 Setting 'LED.A'='red'
TRACE: x52d_config_parser.c:159 Setting 'LED.B'='red'
TRACE: x52d_config_parser.c:159 Setting 'LED.D'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.E'='red'
TRACE: x52d_config_parser.c:159 Setting 'LED.T1'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.T2'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.T3'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.POV'='green'
TRACE: x52d_config_parser.c:159 Setting 'LED.Clutch'='red'
TRACE: x52d_config_parser.c:159 Setting 'Brightness.MFD'='32'
TRACE: x52d_config_parser.c:159 Setting 'Brightness.LED'='32'
TRACE: x52d_config_parser.c:159 Setting 'Mouse.Enabled'='yes'
TRACE: x52d_config_parser.c:159 Setting 'Mouse.Speed'='0'
TRACE: x52d_config_parser.c:159 Setting 'Profiles.Directory'='/etc/x52d/profiles.d'
TRACE: x52d_config_parser.c:159 Setting 'Profiles.ClutchEnabled'='no'
TRACE: x52d_config_parser.c:159 Setting 'Profiles.ClutchLatched'='no'
INFO: x52d_device.c:73 Initializing libx52
TRACE: x52d_clock.c:199 Initializing clock manager
INFO: x52d_device.c:35 Starting X52 device manager thread
INFO: x52d_clock.c:170 Starting X52 clock manager thread
TRACE: x52d_config.def:19 Calling configuration callback for Clock.Enabled
DEBUG: x52d_clock.c:28 Setting clock enable to on
TRACE: x52d_config.def:23 Calling configuration callback for Clock.PrimaryIsLocal
DEBUG: x52d_clock.c:35 Setting primary clock timezone to local
TRACE: x52d_config.def:27 Calling configuration callback for Clock.Secondary
DEBUG: x52d_clock.c:116 Setting secondary clock timezone to UTC
TRACE: x52d_clock.c:109 Offset for timezone 'UTC' is 0
TRACE: x52d_config.def:31 Calling configuration callback for Clock.Tertiary
DEBUG: x52d_clock.c:116 Setting tertiary clock timezone to UTC
TRACE: x52d_clock.c:109 Offset for timezone 'UTC' is 0
TRACE: x52d_config.def:34 Calling configuration callback for Clock.FormatPrimary
DEBUG: x52d_clock.c:135 Setting primary clock format to 24 hour
TRACE: x52d_config.def:37 Calling configuration callback for Clock.FormatSecondary
DEBUG: x52d_clock.c:135 Setting secondary clock format to 24 hour
TRACE: x52d_config.def:40 Calling configuration callback for Clock.FormatTertiary
DEBUG: x52d_clock.c:135 Setting tertiary clock format to 24 hour
TRACE: x52d_config.def:43 Calling configuration callback for Clock.DateFormat
DEBUG: x52d_clock.c:159 Setting date format to DD-MM-YY
TRACE: x52d_config.def:49 Calling configuration callback for LED.Fire
TRACE: x52d_led.c:30 Setting LED Fire state to on (1)
TRACE: x52d_config.def:50 Calling configuration callback for LED.Throttle
TRACE: x52d_led.c:35 Setting LED Throttle state to on (1)
TRACE: x52d_config.def:51 Calling configuration callback for LED.A
TRACE: x52d_led.c:40 Setting LED A state to red (2)
TRACE: x52d_config.def:52 Calling configuration callback for LED.B
TRACE: x52d_led.c:45 Setting LED B state to red (2)
TRACE: x52d_config.def:53 Calling configuration callback for LED.D
TRACE: x52d_led.c:50 Setting LED D state to green (4)
TRACE: x52d_config.def:54 Calling configuration callback for LED.E
TRACE: x52d_led.c:55 Setting LED E state to red (2)
TRACE: x52d_config.def:55 Calling configuration callback for LED.T1
TRACE: x52d_led.c:60 Setting LED T1 state to green (4)
TRACE: x52d_config.def:56 Calling configuration callback for LED.T2
TRACE: x52d_led.c:65 Setting LED T2 state to green (4)
TRACE: x52d_config.def:57 Calling configuration callback for LED.T3
TRACE: x52d_led.c:70 Setting LED T3 state to green (4)
TRACE: x52d_config.def:58 Calling configuration callback for LED.POV
TRACE: x52d_led.c:75 Setting LED POV state to green (4)
TRACE: x52d_config.def:59 Calling configuration callback for LED.Clutch
TRACE: x52d_led.c:80 Setting LED Clutch state to red (2)
TRACE: x52d_config.def:65 Calling configuration callback for Brightness.MFD
TRACE: x52d_led.c:89 Setting MFD brightness to 32
TRACE: x52d_config.def:66 Calling configuration callback for Brightness.LED
TRACE: x52d_led.c:94 Setting LED brightness to 32
TRACE: x52d_config.def:72 Calling configuration callback for Mouse.Enabled
DEBUG: x52d_mouse.c:30 Setting mouse enable to on
TRACE: x52d_config.def:76 Calling configuration callback for Mouse.Speed
DEBUG: x52d_mouse.c:58 Setting mouse speed to 0 (delay 70 ms, multiplier 1.000000)
TRACE: x52d_config.def:82 Calling configuration callback for Profiles.Directory
TRACE: x52d_config.def:85 Calling configuration callback for Profiles.ClutchEnabled
TRACE: x52d_config.def:90 Calling configuration callback for Profiles.ClutchLatched
TRACE: x52d_command.c:113 Polling 1 file descriptors
TRACE: x52d_clock.c:188 Setting X52 clock to 1653497856
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
TRACE: x52d_clock.c:188 Setting X52 clock to 1653497880
TRACE: x52d_device.c:173 Disconnecting detached device
TRACE: x52d_device.c:38 Attempting to connect to X52 device
INFO: x52d_device.c:51 Device connected, writing configuration
TRACE: x52d_config.def:19 Calling configuration callback for Clock.Enabled
DEBUG: x52d_clock.c:28 Setting clock enable to on
TRACE: x52d_config.def:23 Calling configuration callback for Clock.PrimaryIsLocal
DEBUG: x52d_clock.c:35 Setting primary clock timezone to local
TRACE: x52d_config.def:27 Calling configuration callback for Clock.Secondary
DEBUG: x52d_clock.c:116 Setting secondary clock timezone to UTC
TRACE: x52d_clock.c:109 Offset for timezone 'UTC' is 0
TRACE: x52d_config.def:31 Calling configuration callback for Clock.Tertiary
DEBUG: x52d_clock.c:116 Setting tertiary clock timezone to UTC
TRACE: x52d_clock.c:109 Offset for timezone 'UTC' is 0
TRACE: x52d_config.def:34 Calling configuration callback for Clock.FormatPrimary
DEBUG: x52d_clock.c:135 Setting primary clock format to 24 hour
TRACE: x52d_config.def:37 Calling configuration callback for Clock.FormatSecondary
DEBUG: x52d_clock.c:135 Setting secondary clock format to 24 hour
TRACE: x52d_config.def:40 Calling configuration callback for Clock.FormatTertiary
DEBUG: x52d_clock.c:135 Setting tertiary clock format to 24 hour
TRACE: x52d_config.def:43 Calling configuration callback for Clock.DateFormat
DEBUG: x52d_clock.c:159 Setting date format to DD-MM-YY
TRACE: x52d_config.def:49 Calling configuration callback for LED.Fire
TRACE: x52d_led.c:30 Setting LED Fire state to on (1)
TRACE: x52d_config.def:50 Calling configuration callback for LED.Throttle
TRACE: x52d_led.c:35 Setting LED Throttle state to on (1)
TRACE: x52d_config.def:51 Calling configuration callback for LED.A
TRACE: x52d_led.c:40 Setting LED A state to red (2)
TRACE: x52d_config.def:52 Calling configuration callback for LED.B
TRACE: x52d_led.c:45 Setting LED B state to red (2)
TRACE: x52d_config.def:53 Calling configuration callback for LED.D
TRACE: x52d_led.c:50 Setting LED D state to green (4)
TRACE: x52d_config.def:54 Calling configuration callback for LED.E
TRACE: x52d_led.c:55 Setting LED E state to red (2)
TRACE: x52d_config.def:55 Calling configuration callback for LED.T1
TRACE: x52d_led.c:60 Setting LED T1 state to green (4)
TRACE: x52d_config.def:56 Calling configuration callback for LED.T2
TRACE: x52d_led.c:65 Setting LED T2 state to green (4)
TRACE: x52d_config.def:57 Calling configuration callback for LED.T3
TRACE: x52d_led.c:70 Setting LED T3 state to green (4)
TRACE: x52d_config.def:58 Calling configuration callback for LED.POV
TRACE: x52d_led.c:75 Setting LED POV state to green (4)
TRACE: x52d_config.def:59 Calling configuration callback for LED.Clutch
TRACE: x52d_led.c:80 Setting LED Clutch state to red (2)
TRACE: x52d_config.def:65 Calling configuration callback for Brightness.MFD
TRACE: x52d_led.c:89 Setting MFD brightness to 32
TRACE: x52d_config.def:66 Calling configuration callback for Brightness.LED
TRACE: x52d_led.c:94 Setting LED brightness to 32
TRACE: x52d_config.def:72 Calling configuration callback for Mouse.Enabled
DEBUG: x52d_mouse.c:30 Setting mouse enable to on
TRACE: x52d_config.def:76 Calling configuration callback for Mouse.Speed
DEBUG: x52d_mouse.c:58 Setting mouse speed to 0 (delay 70 ms, multiplier 1.000000)
TRACE: x52d_config.def:82 Calling configuration callback for Profiles.Directory
TRACE: x52d_config.def:85 Calling configuration callback for Profiles.ClutchEnabled
TRACE: x52d_config.def:90 Calling configuration callback for Profiles.ClutchLatched
libusb: error [do_close] Device handle closed while transfer was still being processed, but the device is still connected as far as we know
libusb: error [do_close] A cancellation hasn't even been scheduled on the transfer for which the device is closing

@nirenjan
Copy link
Owner

It seems like the hotplug API in libusb is not working as I expected - the idea is that the hotplug mechanism should initiate a callback to close the connection if the device has been disconnected. Based on the logs, it seems like the hotplug mechanism doesn't quite do that, or I've borked up the hotplug callback implementation in libx52.

nirenjan added a commit that referenced this issue Aug 6, 2022
@nirenjan
Handle libusb events when checking if device is connected
1a02ad2 
libusb requires the application to call one of the
`libusb_handle_events` functions in order for hotplug events to actually
get dispatched. We don't need to wait for any timeout, so we use a
default timeout of 0, which should process any pending events, and then
return immediately.

A test of repeatedly disconnecting and reconnecting a virtual device
using USBIP was done, and no crashes of the daemon were observed.

Github-Issue: #43
@nirenjan
Copy link
Owner

nirenjan commented Aug 6, 2022 •
edited
Loading

I've pushed a change that should fix this issue - can you please build the fix-hotplug branch and let me know if you still see the problems?

@maxb-odessa
Copy link
Author

maxb-odessa commented Aug 7, 2022 via email

@nirenjan
Copy link
Owner

nirenjan commented Aug 7, 2022

Thank you for testing this, I will merge it to master and close this issue.

@nirenjan nirenjan closed this as completed Aug 7, 2022
@nirenjan nirenjan mentioned this issue Dec 26, 2022
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@nirenjan @maxb-odessa