> 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
diff --git a/src/libsystemd/sd-device/device-private.c b/src/libsystemd/sd-device/device-private.c
index 2e60433..b5a31ec 100644
--- a/src/libsystemd/sd-device/device-private.c
+++ b/src/libsystemd/sd-device/device-private.c
@@ -1076,7 +1076,7 @@ int device_update_db(sd_device *device) {
goto fail;
}
- log_debug("created %s file '%s' for '%s'", has_info ? "db" : "empty",
+ log_debug("%s:%s:%d: created %s file '%s' for '%s'", has_info ? "db" : "empty", __FUNCTION__, __FILE__, __LINE__,
path, device->devpath);
return 0;
diff --git a/src/libudev/libudev-monitor.c b/src/libudev/libudev-monitor.c
index 282aa2b..c99887d 100644
--- a/src/libudev/libudev-monitor.c
+++ b/src/libudev/libudev-monitor.c
@@ -767,7 +767,7 @@ int udev_monitor_send_device(struct udev_monitor *udev_monitor,
count = sendmsg(udev_monitor->sock, &smsg, 0);
if (count < 0) {
if (!destination && errno == ECONNREFUSED) {
- log_debug("passed device to netlink monitor %p", udev_monitor);
+ log_debug("%s:%s:%d: passed device to netlink monitor %p", __FUNCTION__, __FILE__, __LINE__, udev_monitor);
return 0;
} else
return -errno;
diff --git a/src/udev/udev-event.c b/src/udev/udev-event.c
index 4761222..c5f1cb1 100644
--- a/src/udev/udev-event.c
+++ b/src/udev/udev-event.c
@@ -893,27 +893,37 @@ void udev_event_execute_rules(struct udev_event *event,
if (major(udev_device_get_devnum(dev)) > 0) {
bool apply;
+ log_debug("%llu:%s:%s:%d: %s for %s", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__, udev_device_get_action(dev), udev_device_get_sysname(dev));
/* remove/update possible left-over symlinks from old database entry */
if (event->dev_db != NULL)
udev_node_update_old_links(dev, event->dev_db);
if (!event->owner_set)
+ {
event->uid = udev_device_get_devnode_uid(dev);
+ log_debug("%llu:%s:%s:%d: owner set", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__);
+ }
if (!event->group_set)
+ {
event->gid = udev_device_get_devnode_gid(dev);
+ log_debug("%llu:%s:%s:%d: group set", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__);
+ }
if (!event->mode_set) {
if (udev_device_get_devnode_mode(dev) > 0) {
/* kernel supplied value */
event->mode = udev_device_get_devnode_mode(dev);
+ log_debug("%llu:%s:%s:%d: %s mode", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__, "kernel supplied");
} else if (event->gid > 0) {
/* default 0660 if a group is assigned */
event->mode = 0660;
+ log_debug("%llu:%s:%s:%d: %s mode", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__, "default group");
} else {
/* default 0600 */
event->mode = 0600;
+ log_debug("%llu:%s:%s:%d: %s mode", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__, "default");
}
}
diff --git a/src/udev/udev-node.c b/src/udev/udev-node.c
index d824172..bc48c3b 100644
--- a/src/udev/udev-node.c
+++ b/src/udev/udev-node.c
@@ -81,7 +81,7 @@ static int node_symlink(struct udev_device *dev, const char *node, const char *s
}
}
} else {
- log_debug("creating symlink '%s' to '%s'", slink, target);
+ log_debug("%llu:%s:%s:%d: creating symlink '%s' to '%s'", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__, slink, target);
do {
err = mkdir_parents_label(slink, 0755);
if (err != 0 && err != -ENOENT)
@@ -240,7 +240,7 @@ void udev_node_update_old_links(struct udev_device *dev, struct udev_device *dev
if (found)
continue;
- log_debug("update old name, '%s' no longer belonging to '%s'",
+ log_debug("%llu:%s:%s:%d: update old name, '%s' no longer belonging to '%s'", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__,
name, udev_device_get_devpath(dev));
link_update(dev, name, false);
}
@@ -278,7 +278,7 @@ static int node_permissions_apply(struct udev_device *dev, bool apply,
bool smack = false;
if ((stats.st_mode & 0777) != (mode & 0777) || stats.st_uid != uid || stats.st_gid != gid) {
- log_debug("set permissions %s, %#o, uid=%u, gid=%u", devnode, mode, uid, gid);
+ log_debug("%llu:%s:%s:%d: set permissions %s, %#o, uid=%u, gid=%u", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__, devnode, mode, uid, gid);
err = chmod(devnode, mode);
if (err < 0)
log_warning_errno(errno, "setting mode of %s to %#o failed: %m", devnode, mode);
@@ -286,7 +286,7 @@ static int node_permissions_apply(struct udev_device *dev, bool apply,
if (err < 0)
log_warning_errno(errno, "setting owner of %s to uid=%u, gid=%u failed: %m", devnode, uid, gid);
} else {
- log_debug("preserve permissions %s, %#o, uid=%u, gid=%u", devnode, mode, uid, gid);
+ log_debug("%llu:%s:%s:%d: preserve permissions %s, %#o, uid=%u, gid=%u", udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__, devnode, mode, uid, gid);
}
/* apply SECLABEL{$module}=$label */
@@ -338,7 +338,7 @@ void udev_node_add(struct udev_device *dev, bool apply,
char filename[UTIL_PATH_SIZE];
struct udev_list_entry *list_entry;
- log_debug("handling device node '%s', devnum=%s, mode=%#o, uid="UID_FMT", gid="GID_FMT,
+ log_debug("%llu:%s:%s:%d: handling device node '%s', devnum=%s, mode=%#o, uid="UID_FMT", gid="GID_FMT, udev_device_get_seqnum(dev), __FUNCTION__, __FILE__, __LINE__,
udev_device_get_devnode(dev), udev_device_get_id_filename(dev), mode, uid, gid);
if (node_permissions_apply(dev, apply, mode, uid, gid, seclabel_list) < 0)
diff --git a/src/udev/udev-rules.c b/src/udev/udev-rules.c
index d00f90a..761f1eb 100644
--- a/src/udev/udev-rules.c
+++ b/src/udev/udev-rules.c
@@ -321,6 +321,8 @@ static void dump_token(struct udev_rules *rules, struct token *token) {
enum string_glob_type glob = token->key.glob;
const char *value = str(rules, token->key.value_off);
const char *attr = &rules->buf[token->key.attr_off];
+ log_debug("%s:%s:%d: %s %s '%s'(%s)", __FUNCTION__, __FILE__, __LINE__,
+ token_str(type), operation_str(op), value, string_glob_str(glob));
switch (type) {
case TK_RULE:
@@ -2119,7 +2121,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
if (udev_builtin_run_once(cur->key.builtin_cmd)) {
/* check if we ran already */
if (event->builtin_run & (1 << cur->key.builtin_cmd)) {
- log_debug("IMPORT builtin skip '%s' %s:%u",
+ log_debug("%s:%s:%d: IMPORT builtin skip '%s' %s:%u", __FUNCTION__, __FILE__, __LINE__,
udev_builtin_name(cur->key.builtin_cmd),
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
@@ -2134,19 +2136,21 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
}
udev_event_apply_format(event, rules_str(rules, cur->key.value_off), command, sizeof(command));
- log_debug("IMPORT builtin '%s' %s:%u",
+ log_debug("%s:%s:%d: IMPORT builtin '%s' %s:%u", __FUNCTION__, __FILE__, __LINE__,
udev_builtin_name(cur->key.builtin_cmd),
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
if (udev_builtin_run(event->dev, cur->key.builtin_cmd, command, false) != 0) {
/* remember failure */
- log_debug("IMPORT builtin '%s' returned non-zero",
+ log_debug("%s:%s:%d: IMPORT builtin '%s' returned non-zero", __FUNCTION__, __FILE__, __LINE__,
udev_builtin_name(cur->key.builtin_cmd));
event->builtin_ret |= (1 << cur->key.builtin_cmd);
if (cur->key.op != OP_NOMATCH)
goto nomatch;
}
+ log_debug("%s:%s:%d: %s end", __FUNCTION__, __FILE__, __LINE__,
+ "TK_M_IMPORT_BUILTIN");
break;
}
case TK_M_IMPORT_DB: {
@@ -2252,7 +2256,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
event->uid = 0;
}
- log_debug("OWNER %u %s:%u",
+ log_debug("%s:%s:%d: OWNER %u %s:%u", __FUNCTION__, __FILE__, __LINE__,
event->uid,
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
@@ -2278,7 +2282,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
event->gid = 0;
}
- log_debug("GROUP %u %s:%u",
+ log_debug("%s:%s:%d: GROUP %u %s:%u", __FUNCTION__, __FILE__, __LINE__,
event->gid,
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
@@ -2301,7 +2305,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
event->mode_final = true;
event->mode_set = true;
event->mode = mode;
- log_debug("MODE %#o %s:%u",
+ log_debug("%s:%s:%d: MODE %#o %s:%u", __FUNCTION__, __FILE__, __LINE__,
event->mode,
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
@@ -2314,7 +2318,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
event->owner_final = true;
event->owner_set = true;
event->uid = cur->key.uid;
- log_debug("OWNER %u %s:%u",
+ log_debug("%s:%s:%d: OWNER %u %s:%u", __FUNCTION__, __FILE__, __LINE__,
event->uid,
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
@@ -2326,7 +2330,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
event->group_final = true;
event->group_set = true;
event->gid = cur->key.gid;
- log_debug("GROUP %u %s:%u",
+ log_debug("%s:%s:%d: GROUP %u %s:%u", __FUNCTION__, __FILE__, __LINE__,
event->gid,
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
@@ -2338,7 +2342,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules,
event->mode_final = true;
event->mode_set = true;
event->mode = cur->key.mode;
- log_debug("MODE %#o %s:%u",
+ log_debug("%s:%s:%d: MODE %#o %s:%u", __FUNCTION__, __FILE__, __LINE__,
event->mode,
rules_str(rules, rule->rule.filename_off),
rule->rule.filename_line);
_______________________________________________
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel
