[systemd-devel] Clarification around a segmentation fault from an udevd worker

SF Markus Elfring elfring at users.sourceforge.net
Wed Jul 29 01:06:06 PDT 2015


> This should usually generate a coredump.

I have regenerated the current software on my test system.
last commit: 6ad6d61f9ddd58983b075e4fbece30bae46fac37


Sonne:/home/elfring/Projekte/Bau/systemd # systemctl stop systemd-udevd.service systemd-udevd-kernel.socket systemd-udevd-control.socket && gdb ./systemd-udevd
GNU gdb (GDB; openSUSE Factory) 7.9
…
(gdb) set follow-fork-mode child
(gdb) set detach-on-fork off
(gdb) run --debug
Starting program: /home/elfring/Projekte/Bau/systemd/systemd-udevd --debug
…
restoring old watch on '/dev/dm-12'
adding watch on '/dev/dm-12'
seq 2638 queued, 'add' 'usb'
…
(gdb) set print inferior-events on
(gdb) info inferiors              
  Num  Description       Executable        
* 3    <null>            /usr/lib/udev/mtp-probe 
  2    process 5759      /home/elfring/Projekte/Bau/systemd/systemd-udevd 
  1    process 5751      /home/elfring/Projekte/Bau/systemd/systemd-udevd 
(gdb) inferior 2
(gdb) continue
Continuing.
'/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:02.0/usb3/3-2 3 3'(out) '0'
Process '/usr/lib/udev/mtp-probe /sys/devices/pci0000:00/0000:00:02.0/usb3/3-2 3 3' succeeded.
2638:udev_event_execute_rules:/home/elfring/Projekte/systemd/lokal/src/udev/udev-event.c:896: add for 3-2
2638:udev_event_execute_rules:/home/elfring/Projekte/systemd/lokal/src/udev/udev-event.c:905: owner set
2638:udev_node_add:/home/elfring/Projekte/systemd/lokal/src/udev/udev-node.c:342: handling device node '/dev/bus/usb/003/003', devnum=c189:258, mode=0664, uid=0, gid=7
2638:node_permissions_apply:/home/elfring/Projekte/systemd/lokal/src/udev/udev-node.c:281: set permissions /dev/bus/usb/003/003, 020664, uid=0, gid=7
2638:node_symlink:/home/elfring/Projekte/systemd/lokal/src/udev/udev-node.c:84: creating symlink '/dev/char/189:258' to '../bus/usb/003/003'

Program received signal SIGSEGV, Segmentation fault.
0x00007ffff6fefc78 in vfprintf () from /lib64/libc.so.6
(gdb) bt full
#0  0x00007ffff6fefc78 in vfprintf () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007ffff7016f39 in vsnprintf () from /lib64/libc.so.6
No symbol table info available.
#2  0x000055555559ac64 in log_internalv (level=7, error=0, file=0x5555556118a0 "/home/elfring/Projekte/systemd/lokal/src/libsystemd/sd-device/device-private.c", 
    line=1080, func=0x5555556124c0 <__func__.9471> "device_update_db", format=0x555555611f40 "%s:%s:%d: created %s file '%s' for '%s'", ap=0x7fffffffd760)
    at /home/elfring/Projekte/systemd/lokal/src/basic/log.c:662
        _saved_errno_ = 0
        buffer = "db:device_update_db:1432426656: created ", '\000' <repeats 81 times>, "\221\367\275K2\375\244\300\317\377\377\377\177\000\000\241\252YUUU\000\000\000\000\000\000\000\000\000\000êYUUU\000\000\300\341_UUU\000\000\000\000\000\000\000\000\000\000\300\341_UUU\000\000\000\000\000\000\211\003\000\000 \332_UUU\000\000\000\000\000\000"...
#3  0x000055555559ad9b in log_internal (level=7, error=0, file=0x5555556118a0 "/home/elfring/Projekte/systemd/lokal/src/libsystemd/sd-device/device-private.c", line=1080, 
    func=0x5555556124c0 <__func__.9471> "device_update_db", format=0x555555611f40 "%s:%s:%d: created %s file '%s' for '%s'")
    at /home/elfring/Projekte/systemd/lokal/src/basic/log.c:679
        ap = {{gp_offset = 48, fp_offset = 48, overflow_arg_area = 0x7fffffffd860, reg_save_area = 0x7fffffffd780}}
        r = 21845
#4  0x00005555555f522c in device_update_db (device=0x55555567bb20) at /home/elfring/Projekte/systemd/lokal/src/libsystemd/sd-device/device-private.c:1079
        _level = 7
        _e = 0
        id = 0x55555567a740 "c189:258"
        path = 0x7fffffffd870 "/run/udev/data/c189:258"
        f = 0x5555556526a0
        path_tmp = 0x55555566e770 "/run/udev/data/.#c189:258gYzL5N"
        has_info = true
        r = 0
        __PRETTY_FUNCTION__ = "device_update_db"
        __func__ = "device_update_db"
        __FUNCTION__ = "device_update_db"
#5  0x00005555555cb3cf in udev_device_update_db (udev_device=0x555555638560) at /home/elfring/Projekte/systemd/lokal/src/libudev/libudev-device-private.c:48
        r = 21845
        __PRETTY_FUNCTION__ = "udev_device_update_db"
#6  0x000055555556c924 in udev_event_execute_rules (event=0x555555638df0, timeout_usec=180000000, timeout_warn_usec=60000000, properties_list=0x5555556380c0, 
    rules=0x555555638500) at /home/elfring/Projekte/systemd/lokal/src/udev/udev-event.c:939
        dev = 0x555555638560
        __func__ = "udev_event_execute_rules"
        __FUNCTION__ = "udev_event_execute_rules"
#7  0x0000555555563264 in worker_spawn (manager=0x555555638080, event=0x55555566ea30) at /home/elfring/Projekte/systemd/lokal/src/udev/udevd.c:450
        udev_event = 0x555555638df0
        fd_lock = -1
        dev = 0x555555638560
        rtnl = 0x0
        fd_signal = 4
        ep_monitor = {events = 1, data = {ptr = 0xb, fd = 11, u32 = 11, u64 = 11}}
        mask = {__val = {18446744067267100671, 18446744073709551615 <repeats 15 times>}}
        fd_monitor = 11
        fd_ep = 5
        ep_signal = {events = 1, data = {ptr = 0x4, fd = 4, u32 = 4, u64 = 4}}
        udev = 0x555555638060
        worker_monitor = 0x55555566f8d0
        pid = 0
        r = 0
        __func__ = "worker_spawn"
        __PRETTY_FUNCTION__ = "worker_spawn"
#8  0x0000555555563b19 in event_run (manager=0x555555638080, event=0x55555566ea30) at /home/elfring/Projekte/systemd/lokal/src/udev/udevd.c:578
        worker = 0x0
        i = {idx = 4294967295, next_key = 0x0}
        __PRETTY_FUNCTION__ = "event_run"
        __func__ = "event_run"
#9  0x00005555555646df in event_queue_start (manager=0x555555638080) at /home/elfring/Projekte/systemd/lokal/src/udev/udevd.c:822
        event = 0x55555566ea30
        loop = 0x55555566ea30
        usec = 2384851219
        r = 0
        __PRETTY_FUNCTION__ = "event_queue_start"
#10 0x0000555555564cf0 in on_uevent (s=0x555555638fd0, fd=5, revents=1, userdata=0x555555638080) at /home/elfring/Projekte/systemd/lokal/src/udev/udevd.c:926
        manager = 0x555555638080
        dev = 0x555555638560
        r = 0
        __PRETTY_FUNCTION__ = "on_uevent"
#11 0x00005555555e5e4e in source_dispatch (s=0x555555638fd0) at /home/elfring/Projekte/systemd/lokal/src/libsystemd/sd-event/sd-event.c:2116
        r = 0
        __PRETTY_FUNCTION__ = "source_dispatch"
        __func__ = "source_dispatch"
#12 0x00005555555e7328 in sd_event_dispatch (e=0x55555567b920) at /home/elfring/Projekte/systemd/lokal/src/libsystemd/sd-event/sd-event.c:2472
        p = 0x555555638fd0
        r = 32767
        __PRETTY_FUNCTION__ = "sd_event_dispatch"
#13 0x00005555555e74e3 in sd_event_run (e=0x55555567b920, timeout=18446744073709551615) at /home/elfring/Projekte/systemd/lokal/src/libsystemd/sd-event/sd-event.c:2500
        r = 1
        __PRETTY_FUNCTION__ = "sd_event_run"
#14 0x00005555555e7610 in sd_event_loop (e=0x55555567b920) at /home/elfring/Projekte/systemd/lokal/src/libsystemd/sd-event/sd-event.c:2520
        r = 0
        __PRETTY_FUNCTION__ = "sd_event_loop"
#15 0x00005555555684a3 in run (fd_ctrl=4, fd_uevent=5, cgroup=0x0) at /home/elfring/Projekte/systemd/lokal/src/udev/udevd.c:1633
        manager = 0x555555638080
        r = 0
        __func__ = "run"
#16 0x0000555555568ddd in main (argc=2, argv=0x7fffffffe268) at /home/elfring/Projekte/systemd/lokal/src/udev/udevd.c:1757
        cgroup = 0x0
        r = 0
        fd_ctrl = 4
        fd_uevent = 5
        __func__ = "main"
(gdb) info inferiors
  Num  Description       Executable        
* 2    process 5759      /home/elfring/Projekte/Bau/systemd/systemd-udevd 
  1    process 5751      /home/elfring/Projekte/Bau/systemd/systemd-udevd 
(gdb) inferior 1
…
(gdb) continue
Continuing.
seq 2638 forked new worker [5759]
seq 2639 queued, 'add' 'usb'
Check if link configuration needs reloading.
seq 2638 '/devices/pci0000:00/0000:00:02.0/usb3/3-2' is taking a long time
seq 2638 '/devices/pci0000:00/0000:00:02.0/usb3/3-2' killed
worker [5759] terminated by signal 9 (Killed)
worker [5759] failed while handling '/devices/pci0000:00/0000:00:02.0/usb3/3-2'
udev_monitor_send_device:/home/elfring/Projekte/systemd/lokal/src/libudev/libudev-monitor.c:770: passed device to netlink monitor 0x555555671520
../../gdb/linux-nat.c:3021: internal-error: linux_nat_filter_event: Assertion `lp->resumed' failed.
A problem internal to GDB has been detected,
further debugging may prove unreliable.
Quit this debugging session? (y or n) y
…


I wonder about such software development surprises.
How much does the attached source file extension influence the shown situation
for a bit of extra debug output?

Regards,
Markus
-------------- next part --------------
A non-text attachment was scrubbed...
Name: more_debug_log1.diff
Type: text/x-patch
Size: 13353 bytes
Desc: not available
URL: <http://lists.freedesktop.org/archives/systemd-devel/attachments/20150729/e1e30568/attachment-0001.bin>


More information about the systemd-devel mailing list