diff --git a/1077-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch b/1077-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch new file mode 100644 index 00000000..57b2d699 --- /dev/null +++ b/1077-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch @@ -0,0 +1,350 @@ +Based on 671174136525ddf208cdbe75d6d6bd159afa961f Mon Sep 17 00:00:00 2001 +From: Tom Gundersen +Date: Thu, 11 Sep 2014 18:49:04 +0200 +Subject: [PATCH] udev: timeout - warn after a third of the timeout before + killing + +--- + src/test/test-udev.c | 4 ++-- + src/udev/udev-event.c | 40 ++++++++++++++++++++++++++++++---------- + src/udev/udev-rules.c | 8 +++++--- + src/udev/udev.h | 9 ++++++--- + src/udev/udevadm-test.c | 2 +- + src/udev/udevd.c | 40 +++++++++++++++++++++++++++------------- + 6 files changed, 71 insertions(+), 32 deletions(-) + +diff --git src/test/test-udev.c src/test/test-udev.c +index 566a73a..f085262 100644 +--- src/test/test-udev.c ++++ src/test/test-udev.c +@@ -153,8 +153,8 @@ int main(int argc, char *argv[]) { + } + } + +- udev_event_execute_rules(event, USEC_PER_SEC, rules, &sigmask_orig); +- udev_event_execute_run(event, USEC_PER_SEC, NULL); ++ udev_event_execute_rules(event, 3 * USEC_PER_SEC, USEC_PER_SEC, rules, &sigmask_orig); ++ udev_event_execute_run(event, 3 * USEC_PER_SEC, USEC_PER_SEC, NULL); + out: + if (event != NULL && event->fd_signal >= 0) + close(event->fd_signal); +diff --git src/udev/udev-event.c src/udev/udev-event.c +index a883edc..e8d6676 100644 +--- src/udev/udev-event.c ++++ src/udev/udev-event.c +@@ -541,6 +541,7 @@ out: + + static int spawn_wait(struct udev_event *event, + usec_t timeout_usec, ++ usec_t timeout_warn_usec, + const char *cmd, pid_t pid) { + struct pollfd pfd[1]; + int err = 0; +@@ -550,6 +551,7 @@ static int spawn_wait(struct udev_event *event, + + while (pid > 0) { + int timeout; ++ int timeout_warn = 0; + int fdcount; + + if (timeout_usec > 0) { +@@ -558,13 +560,17 @@ static int spawn_wait(struct udev_event *event, + age_usec = now(CLOCK_MONOTONIC) - event->birth_usec; + if (age_usec >= timeout_usec) + timeout = 1000; +- else +- timeout = ((timeout_usec - age_usec) / USEC_PER_MSEC) + MSEC_PER_SEC; ++ else { ++ if (timeout_warn_usec > 0) ++ timeout_warn = ((timeout_warn_usec - age_usec) / USEC_PER_MSEC) + MSEC_PER_SEC; ++ ++ timeout = ((timeout_usec - timeout_warn_usec - age_usec) / USEC_PER_MSEC) + MSEC_PER_SEC; ++ } + } else { + timeout = -1; + } + +- fdcount = poll(pfd, 1, timeout); ++ fdcount = poll(pfd, 1, timeout_warn); + if (fdcount < 0) { + if (errno == EINTR) + continue; +@@ -573,8 +579,20 @@ static int spawn_wait(struct udev_event *event, + goto out; + } + if (fdcount == 0) { +- log_error("timeout: killing '%s' [%u]", cmd, pid); +- kill(pid, SIGKILL); ++ log_warning("slow: '%s' [%u]", cmd, pid); ++ ++ fdcount = poll(pfd, 1, timeout); ++ if (fdcount < 0) { ++ if (errno == EINTR) ++ continue; ++ err = -errno; ++ log_error("failed to poll: %m"); ++ goto out; ++ } ++ if (fdcount == 0) { ++ log_error("timeout: killing '%s' [%u]", cmd, pid); ++ kill(pid, SIGKILL); ++ } + } + + if (pfd[0].revents & POLLIN) { +@@ -654,6 +672,7 @@ out: + + int udev_event_spawn(struct udev_event *event, + usec_t timeout_usec, ++ usec_t timeout_warn_usec, + const char *cmd, char **envp, const sigset_t *sigmask, + char *result, size_t ressize) { + struct udev *udev = event->udev; +@@ -730,7 +749,7 @@ int udev_event_spawn(struct udev_event *event, + outpipe[READ_END], errpipe[READ_END], + result, ressize); + +- err = spawn_wait(event, timeout_usec, cmd, pid); ++ err = spawn_wait(event, timeout_usec, timeout_warn_usec, cmd, pid); + } + + out: +@@ -769,6 +788,7 @@ static int rename_netif(struct udev_event *event) { + + void udev_event_execute_rules(struct udev_event *event, + usec_t timeout_usec, ++ usec_t timeout_warn_usec, + struct udev_rules *rules, const sigset_t *sigmask) { + struct udev_device *dev = event->dev; + +@@ -783,7 +803,7 @@ void udev_event_execute_rules(struct udev_event *event, + if (major(udev_device_get_devnum(dev)) != 0) + udev_watch_end(event->udev, dev); + +- udev_rules_apply_to_event(rules, event, timeout_usec, sigmask); ++ udev_rules_apply_to_event(rules, event, timeout_usec, timeout_warn_usec, sigmask); + + if (major(udev_device_get_devnum(dev)) != 0) + udev_node_remove(dev); +@@ -816,7 +836,7 @@ void udev_event_execute_rules(struct udev_event *event, + } + } + +- udev_rules_apply_to_event(rules, event, timeout_usec, sigmask); ++ udev_rules_apply_to_event(rules, event, timeout_usec, timeout_warn_usec, sigmask); + + /* rename a new network interface, if needed */ + if (udev_device_get_ifindex(dev) > 0 && streq(udev_device_get_action(dev), "add") && +@@ -889,7 +909,7 @@ void udev_event_execute_rules(struct udev_event *event, + } + } + +-void udev_event_execute_run(struct udev_event *event, usec_t timeout_usec, const sigset_t *sigmask) { ++void udev_event_execute_run(struct udev_event *event, usec_t timeout_usec, usec_t timeout_warn_usec, const sigset_t *sigmask) { + struct udev_list_entry *list_entry; + + udev_list_entry_foreach(list_entry, udev_list_get_entry(&event->run_list)) { +@@ -912,7 +932,7 @@ void udev_event_execute_run(struct udev_event *event, usec_t timeout_usec, const + + udev_event_apply_format(event, cmd, program, sizeof(program)); + envp = udev_device_get_properties_envp(event->dev); +- udev_event_spawn(event, timeout_usec, program, envp, sigmask, NULL, 0); ++ udev_event_spawn(event, timeout_usec, timeout_warn_usec, program, envp, sigmask, NULL, 0); + } + } + } +diff --git src/udev/udev-rules.c src/udev/udev-rules.c +index 9514dde..db95442 100644 +--- src/udev/udev-rules.c ++++ src/udev/udev-rules.c +@@ -615,6 +615,7 @@ static int import_file_into_properties(struct udev_device *dev, const char *file + + static int import_program_into_properties(struct udev_event *event, + usec_t timeout_usec, ++ usec_t timeout_warn_usec, + const char *program, const sigset_t *sigmask) { + struct udev_device *dev = event->dev; + char **envp; +@@ -623,7 +624,7 @@ static int import_program_into_properties(struct udev_event *event, + int err; + + envp = udev_device_get_properties_envp(dev); +- err = udev_event_spawn(event, timeout_usec, program, envp, sigmask, result, sizeof(result)); ++ err = udev_event_spawn(event, timeout_usec, timeout_warn_usec, program, envp, sigmask, result, sizeof(result)); + if (err < 0) + return err; + +@@ -1862,6 +1863,7 @@ enum escape_type { + int udev_rules_apply_to_event(struct udev_rules *rules, + struct udev_event *event, + usec_t timeout_usec, ++ usec_t timeout_warn_usec, + const sigset_t *sigmask) { + struct token *cur; + struct token *rule; +@@ -2070,7 +2072,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules, + rules_str(rules, rule->rule.filename_off), + rule->rule.filename_line); + +- if (udev_event_spawn(event, timeout_usec, program, envp, sigmask, result, sizeof(result)) < 0) { ++ if (udev_event_spawn(event, timeout_usec, timeout_warn_usec, program, envp, sigmask, result, sizeof(result)) < 0) { + if (cur->key.op != OP_NOMATCH) + goto nomatch; + } else { +@@ -2106,7 +2108,7 @@ int udev_rules_apply_to_event(struct udev_rules *rules, + rules_str(rules, rule->rule.filename_off), + rule->rule.filename_line); + +- if (import_program_into_properties(event, timeout_usec, import, sigmask) != 0) ++ if (import_program_into_properties(event, timeout_usec, timeout_warn_usec, import, sigmask) != 0) + if (cur->key.op != OP_NOMATCH) + goto nomatch; + break; +diff --git src/udev/udev.h src/udev/udev.h +index ed01da3..765ba9e 100644 +--- src/udev/udev.h ++++ src/udev/udev.h +@@ -73,7 +73,8 @@ struct udev_rules; + struct udev_rules *udev_rules_new(struct udev *udev, int resolve_names); + struct udev_rules *udev_rules_unref(struct udev_rules *rules); + bool udev_rules_check_timestamp(struct udev_rules *rules); +-int udev_rules_apply_to_event(struct udev_rules *rules, struct udev_event *event, usec_t timeout_usec, const sigset_t *sigmask); ++int udev_rules_apply_to_event(struct udev_rules *rules, struct udev_event *event, usec_t timeout_usec, usec_t timeout_warn_usec, ++ const sigset_t *sigmask); + int udev_rules_apply_static_dev_perms(struct udev_rules *rules); + + /* udev-event.c */ +@@ -84,10 +85,12 @@ int udev_event_apply_subsys_kernel(struct udev_event *event, const char *string, + char *result, size_t maxsize, int read_value); + int udev_event_spawn(struct udev_event *event, + usec_t timeout_usec, ++ usec_t timeout_warn_usec, + const char *cmd, char **envp, const sigset_t *sigmask, + char *result, size_t ressize); +-void udev_event_execute_rules(struct udev_event *event, usec_t timeout_usec, struct udev_rules *rules, const sigset_t *sigset); +-void udev_event_execute_run(struct udev_event *event, usec_t timeout_usec, const sigset_t *sigset); ++void udev_event_execute_rules(struct udev_event *event, usec_t timeout_usec, usec_t timeout_warn_usec, ++ struct udev_rules *rules, const sigset_t *sigset); ++void udev_event_execute_run(struct udev_event *event, usec_t timeout_usec, usec_t timeout_warn_usec, const sigset_t *sigset); + int udev_build_argv(struct udev *udev, char *cmd, int *argc, char *argv[]); + + /* udev-watch.c */ +diff --git src/udev/udevadm-test.c src/udev/udevadm-test.c +index 809adb6..4738b61 100644 +--- src/udev/udevadm-test.c ++++ src/udev/udevadm-test.c +@@ -136,7 +136,7 @@ static int adm_test(struct udev *udev, int argc, char *argv[]) { + goto out; + } + +- udev_event_execute_rules(event, 60 * USEC_PER_SEC, rules, &sigmask_orig); ++ udev_event_execute_rules(event, 60 * USEC_PER_SEC, 20 * USEC_PER_SEC, rules, &sigmask_orig); + + udev_list_entry_foreach(entry, udev_device_get_properties_list_entry(dev)) + printf("%s=%s\n", udev_list_entry_get_name(entry), udev_list_entry_get_value(entry)); +--- src/udev/udevd.c ++++ src/udev/udevd.c 2014-09-16 09:01:14.382735997 +0000 +@@ -75,6 +75,7 @@ static int children; + static int children_max; + static int exec_delay; + static usec_t event_timeout_usec = 180 * USEC_PER_SEC; ++static usec_t event_timeout_warn_usec = 180 * USEC_PER_SEC / 3; + static sigset_t sigmask_orig; + static UDEV_LIST(event_list); + static UDEV_LIST(worker_list); +@@ -129,6 +130,7 @@ struct worker { + enum worker_state state; + struct event *event; + usec_t event_start_usec; ++ bool event_warned; + }; + + /* passed from worker to main process */ +@@ -314,9 +316,9 @@ static void worker_new(struct event *eve + } + + /* apply rules, create node, symlinks */ +- udev_event_execute_rules(udev_event, event_timeout_usec, rules, &sigmask_orig); ++ udev_event_execute_rules(udev_event, event_timeout_usec, event_timeout_warn_usec, rules, &sigmask_orig); + +- udev_event_execute_run(udev_event, event_timeout_usec, &sigmask_orig); ++ udev_event_execute_run(udev_event, event_timeout_usec, event_timeout_warn_usec, &sigmask_orig); + + /* apply/restore inotify watch */ + if (udev_event->inotify_watch) { +@@ -410,6 +412,7 @@ out: + worker->pid = pid; + worker->state = WORKER_RUNNING; + worker->event_start_usec = now(CLOCK_MONOTONIC); ++ worker->event_warned = false; + worker->event = event; + event->state = EVENT_RUNNING; + udev_list_node_append(&worker->node, &worker_list); +@@ -441,6 +444,7 @@ static void event_run(struct event *even + worker->event = event; + worker->state = WORKER_RUNNING; + worker->event_start_usec = now(CLOCK_MONOTONIC); ++ worker->event_warned = false; + event->state = EVENT_RUNNING; + return; + } +@@ -1016,6 +1020,7 @@ static void kernel_cmdline_options(struc + exec_delay = strtoul(opt + 16, NULL, 0); + } else if (startswith(opt, "udev.event-timeout=")) { + event_timeout_usec = strtoul(opt + 16, NULL, 0) * USEC_PER_SEC; ++ event_timeout_warn_usec = (event_timeout_usec / 3) ? : 1; + } + + free(s); +@@ -1078,6 +1083,7 @@ int main(int argc, char *argv[]) { + break; + case 't': + event_timeout_usec = strtoul(optarg, NULL, 0) * USEC_PER_SEC; ++ event_timeout_warn_usec = (event_timeout_usec / 3) ? : 1; + break; + case 'D': + debug = true; +@@ -1413,21 +1419,29 @@ int main(int argc, char *argv[]) { + /* check for hanging events */ + udev_list_node_foreach(loop, &worker_list) { + struct worker *worker = node_to_worker(loop); ++ usec_t ts; + + if (worker->state != WORKER_RUNNING) + continue; + +- if ((now(CLOCK_MONOTONIC) - worker->event_start_usec) > event_timeout_usec) { +- log_error("worker [%u] %s timeout; kill it", worker->pid, worker->event->devpath); +- kill(worker->pid, SIGKILL); +- worker->state = WORKER_KILLED; +- +- /* drop reference taken for state 'running' */ +- worker_unref(worker); +- log_error("seq %llu '%s' killed", udev_device_get_seqnum(worker->event->dev), worker->event->devpath); +- worker->event->exitcode = -64; +- event_queue_delete(worker->event, true); +- worker->event = NULL; ++ ts = now(CLOCK_MONOTONIC); ++ ++ if ((ts - worker->event_start_usec) > event_timeout_warn_usec) { ++ if ((ts - worker->event_start_usec) > event_timeout_usec) { ++ log_error("worker [%u] %s timeout; kill it", worker->pid, worker->event->devpath); ++ kill(worker->pid, SIGKILL); ++ worker->state = WORKER_KILLED; ++ ++ /* drop reference taken for state 'running' */ ++ worker_unref(worker); ++ log_error("seq %llu '%s' killed", udev_device_get_seqnum(worker->event->dev), worker->event->devpath); ++ worker->event->exitcode = -64; ++ event_queue_delete(worker->event, true); ++ worker->event = NULL; ++ } else if (!worker->event_warned) { ++ log_warning("worker [%u] %s is taking a long time", worker->pid, worker->event->devpath); ++ worker->event_warned = true; ++ } + } + } + +-- +1.7.9.2 + diff --git a/systemd.changes b/systemd.changes index c2b704f1..46d3a404 100644 --- a/systemd.changes +++ b/systemd.changes @@ -9,8 +9,9 @@ Tue Sep 16 09:10:52 UTC 2014 - werner@suse.de 1072-udev-netif_rename-don-t-log-to-kmsg.patch 1073-udev-drop-print_kmsg.patch 1074-udev-fix-copy-paste-error-in-log-message.patch - 1075-udev-timeout-increase-timeout.patch - 1076-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch + 1075-udev-timeout-increase-timeout.patch (bnc#889297) + 1076-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch (bnc#889297) + 1077-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch (bnc#889297) ------------------------------------------------------------------- Sat Sep 13 13:35:33 UTC 2014 - rmilasan@suse.com diff --git a/systemd.spec b/systemd.spec index 2ba6bf9d..adea623c 100644 --- a/systemd.spec +++ b/systemd.spec @@ -988,6 +988,8 @@ Patch1074: 1074-udev-fix-copy-paste-error-in-log-message.patch Patch1075: 1075-udev-timeout-increase-timeout.patch # PATCH-FIX-UPSTREAM 1076-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch Patch1076: 1076-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch +# PATCH-FIX-UPSTREAM 1077-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch +Patch1077: 1077-udev-timeout-warn-after-a-third-of-the-timeout-befor.patch %description Systemd is a system and service manager, compatible with SysV and LSB @@ -1650,7 +1652,11 @@ cp %{SOURCE7} m4/ %patch1073 -p0 %patch1074 -p0 %patch1075 -p0 +%if %{with udevsettle} %patch1076 -p0 +%else +%patch1077 -p0 +%endif # remove patch backups find -name '*.orig' -exec rm -f '{}' \+