X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ianmdlvl/git?p=elogind.git;a=blobdiff_plain;f=src%2Flibelogind%2Fsd-event%2Fsd-event.c;h=383de48d55fb712aaf6bb00e05619cda66bdc7e6;hp=5380d2178b126027965aa5c5f9233dc3d0f870fd;hb=971e2488dda5dbdfddc29adabc9a10590b084ba5;hpb=6053df4ee3a205f25b67f43ece1ff4d1202b7edb diff --git a/src/libelogind/sd-event/sd-event.c b/src/libelogind/sd-event/sd-event.c index 5380d2178..383de48d5 100644 --- a/src/libelogind/sd-event/sd-event.c +++ b/src/libelogind/sd-event/sd-event.c @@ -1,5 +1,3 @@ -/*-*- Mode: C; c-basic-offset: 8; indent-tabs-mode: nil -*-*/ - /*** This file is part of systemd. @@ -37,6 +35,7 @@ #include "process-util.h" #include "set.h" #include "signal-util.h" +#include "string-table.h" #include "string-util.h" #include "time-util.h" #include "util.h" @@ -60,6 +59,23 @@ typedef enum EventSourceType { _SOURCE_EVENT_SOURCE_TYPE_INVALID = -1 } EventSourceType; +static const char* const event_source_type_table[_SOURCE_EVENT_SOURCE_TYPE_MAX] = { + [SOURCE_IO] = "io", + [SOURCE_TIME_REALTIME] = "realtime", + [SOURCE_TIME_BOOTTIME] = "bootime", + [SOURCE_TIME_MONOTONIC] = "monotonic", + [SOURCE_TIME_REALTIME_ALARM] = "realtime-alarm", + [SOURCE_TIME_BOOTTIME_ALARM] = "boottime-alarm", + [SOURCE_SIGNAL] = "signal", + [SOURCE_CHILD] = "child", + [SOURCE_DEFER] = "defer", + [SOURCE_POST] = "post", + [SOURCE_EXIT] = "exit", + [SOURCE_WATCHDOG] = "watchdog", +}; + +DEFINE_PRIVATE_STRING_TABLE_LOOKUP_TO_STRING(event_source_type, int); + /* All objects we use in epoll events start with this value, so that * we know how to dispatch it */ typedef enum WakeupType { @@ -93,8 +109,8 @@ struct sd_event_source { int64_t priority; unsigned pending_index; unsigned prepare_index; - unsigned pending_iteration; - unsigned prepare_iteration; + uint64_t pending_iteration; + uint64_t prepare_iteration; LIST_FIELDS(sd_event_source, sources); @@ -199,14 +215,14 @@ struct sd_event { pid_t original_pid; - unsigned iteration; - dual_timestamp timestamp; - usec_t timestamp_boottime; + uint64_t iteration; + triple_timestamp timestamp; int state; bool exit_requested:1; bool need_process_child:1; bool watchdog:1; + bool profile_delays:1; int exit_code; @@ -218,6 +234,9 @@ struct sd_event { unsigned n_sources; LIST_HEAD(sd_event_source, sources); + + usec_t last_run, last_log; + unsigned delays[sizeof(usec_t) * 8]; }; static void source_disconnect(sd_event_source *s); @@ -305,6 +324,10 @@ static int earliest_time_prioq_compare(const void *a, const void *b) { return 0; } +static usec_t time_event_source_latest(const sd_event_source *s) { + return usec_add(s->time.next, s->time.accuracy); +} + static int latest_time_prioq_compare(const void *a, const void *b) { const sd_event_source *x = a, *y = b; @@ -324,9 +347,9 @@ static int latest_time_prioq_compare(const void *a, const void *b) { return 1; /* Order by time */ - if (x->time.next + x->time.accuracy < y->time.next + y->time.accuracy) + if (time_event_source_latest(x) < time_event_source_latest(y)) return -1; - if (x->time.next + x->time.accuracy > y->time.next + y->time.accuracy) + if (time_event_source_latest(x) > time_event_source_latest(y)) return 1; return 0; @@ -416,11 +439,9 @@ _public_ int sd_event_new(sd_event** ret) { e->original_pid = getpid(); e->perturb = USEC_INFINITY; - e->pending = prioq_new(pending_prioq_compare); - if (!e->pending) { - r = -ENOMEM; + r = prioq_ensure_allocated(&e->pending, pending_prioq_compare); + if (r < 0) goto fail; - } e->epoll_fd = epoll_create1(EPOLL_CLOEXEC); if (e->epoll_fd < 0) { @@ -428,6 +449,11 @@ _public_ int sd_event_new(sd_event** ret) { goto fail; } + if (secure_getenv("SD_EVENT_PROFILE_DELAYS")) { + log_debug("Event loop profiling enabled. Logarithmic histogram of event loop iterations in the range 2^0 ... 2^63 us will be logged every 5s."); + e->profile_delays = true; + } + *ret = e; return 0; @@ -437,7 +463,9 @@ fail: } _public_ sd_event* sd_event_ref(sd_event *e) { - assert_return(e, NULL); + + if (!e) + return NULL; assert(e->n_ref >= 1); e->n_ref++; @@ -482,7 +510,8 @@ static void source_io_unregister(sd_event_source *s) { r = epoll_ctl(s->event->epoll_fd, EPOLL_CTL_DEL, s->io.fd, NULL); if (r < 0) - log_debug_errno(errno, "Failed to remove source %s from epoll: %m", strna(s->description)); + log_debug_errno(errno, "Failed to remove source %s (type %s) from epoll: %m", + strna(s->description), event_source_type_to_string(s->type)); s->io.registered = false; } @@ -619,7 +648,7 @@ static int event_make_signal_data( if (sigismember(&d->sigset, sig) > 0) { if (ret) *ret = d; - return 0; + return 0; } } else { r = hashmap_ensure_allocated(&e->signal_data, &uint64_hash_ops); @@ -635,8 +664,10 @@ static int event_make_signal_data( d->priority = priority; r = hashmap_put(e->signal_data, &d->priority, d); - if (r < 0) + if (r < 0) { + free(d); return r; + } added = true; } @@ -664,7 +695,7 @@ static int event_make_signal_data( ev.data.ptr = d; r = epoll_ctl(e->epoll_fd, EPOLL_CTL_ADD, d->fd, &ev); - if (r < 0) { + if (r < 0) { r = -errno; goto fail; } @@ -921,7 +952,7 @@ static sd_event_source *source_new(sd_event *e, bool floating, EventSourceType t sd_event_ref(e); LIST_PREPEND(sources, e->sources, s); - e->n_sources ++; + e->n_sources++; return s; } @@ -1038,31 +1069,30 @@ _public_ int sd_event_add_time( int r; assert_return(e, -EINVAL); - assert_return(usec != (uint64_t) -1, -EINVAL); assert_return(accuracy != (uint64_t) -1, -EINVAL); assert_return(e->state != SD_EVENT_FINISHED, -ESTALE); assert_return(!event_pid_changed(e), -ECHILD); + if (!clock_supported(clock)) /* Checks whether the kernel supports the clock */ + return -EOPNOTSUPP; + + type = clock_to_event_source_type(clock); /* checks whether sd-event supports this clock */ + if (type < 0) + return -EOPNOTSUPP; + if (!callback) callback = time_exit_callback; - type = clock_to_event_source_type(clock); - assert_return(type >= 0, -EOPNOTSUPP); - d = event_get_clock_data(e, type); assert(d); - if (!d->earliest) { - d->earliest = prioq_new(earliest_time_prioq_compare); - if (!d->earliest) - return -ENOMEM; - } + r = prioq_ensure_allocated(&d->earliest, earliest_time_prioq_compare); + if (r < 0) + return r; - if (!d->latest) { - d->latest = prioq_new(latest_time_prioq_compare); - if (!d->latest) - return -ENOMEM; - } + r = prioq_ensure_allocated(&d->latest, latest_time_prioq_compare); + if (r < 0) + return r; if (d->fd < 0) { r = event_setup_timer_fd(e, d, clock); @@ -1120,8 +1150,7 @@ _public_ int sd_event_add_signal( int r; assert_return(e, -EINVAL); - assert_return(sig > 0, -EINVAL); - assert_return(sig < _NSIG, -EINVAL); + assert_return(SIGNAL_VALID(sig), -EINVAL); assert_return(e->state != SD_EVENT_FINISHED, -ESTALE); assert_return(!event_pid_changed(e), -ECHILD); @@ -1154,10 +1183,10 @@ _public_ int sd_event_add_signal( e->signal_sources[sig] = s; r = event_make_signal_data(e, sig, &d); - if (r < 0) { - source_free(s); - return r; - } + if (r < 0) { + source_free(s); + return r; + } /* Use the signal name as description for the event source by default */ (void) sd_event_source_set_description(s, signal_to_string(sig)); @@ -1211,14 +1240,14 @@ _public_ int sd_event_add_child( return r; } - e->n_enabled_child_sources ++; + e->n_enabled_child_sources++; r = event_make_signal_data(e, SIGCHLD, NULL); - if (r < 0) { + if (r < 0) { e->n_enabled_child_sources--; - source_free(s); - return r; - } + source_free(s); + return r; + } e->need_process_child = true; @@ -1315,11 +1344,9 @@ _public_ int sd_event_add_exit( assert_return(e->state != SD_EVENT_FINISHED, -ESTALE); assert_return(!event_pid_changed(e), -ECHILD); - if (!e->exit) { - e->exit = prioq_new(exit_prioq_compare); - if (!e->exit) - return -ENOMEM; - } + r = prioq_ensure_allocated(&e->exit, exit_prioq_compare); + if (r < 0) + return r; s = source_new(e, !ret, SOURCE_EXIT); if (!s) @@ -1344,7 +1371,9 @@ _public_ int sd_event_add_exit( #if 0 /// UNNEEDED by elogind _public_ sd_event_source* sd_event_source_ref(sd_event_source *s) { - assert_return(s, NULL); + + if (!s) + return NULL; assert(s->n_ref >= 1); s->n_ref++; @@ -1523,7 +1552,8 @@ _public_ int sd_event_source_get_priority(sd_event_source *s, int64_t *priority) assert_return(s, -EINVAL); assert_return(!event_pid_changed(s->event), -ECHILD); - return s->priority; + *priority = s->priority; + return 0; } #endif // 0 @@ -1555,7 +1585,7 @@ _public_ int sd_event_source_set_priority(sd_event_source *s, int64_t priority) event_unmask_signal_data(s->event, old, s->signal.sig); } else - s->priority = priority; + s->priority = priority; if (s->pending) prioq_reshuffle(s->event->pending, s, &s->pending_index); @@ -1683,11 +1713,11 @@ _public_ int sd_event_source_set_enabled(sd_event_source *s, int m) { s->enabled = m; r = event_make_signal_data(s->event, s->signal.sig, NULL); - if (r < 0) { - s->enabled = SD_EVENT_OFF; + if (r < 0) { + s->enabled = SD_EVENT_OFF; event_gc_signal_data(s->event, &s->priority, s->signal.sig); - return r; - } + return r; + } break; @@ -1699,12 +1729,12 @@ _public_ int sd_event_source_set_enabled(sd_event_source *s, int m) { s->enabled = m; r = event_make_signal_data(s->event, SIGCHLD, NULL); - if (r < 0) { - s->enabled = SD_EVENT_OFF; + if (r < 0) { + s->enabled = SD_EVENT_OFF; s->event->n_enabled_child_sources--; event_gc_signal_data(s->event, &s->priority, SIGCHLD); - return r; - } + return r; + } break; @@ -1746,7 +1776,6 @@ _public_ int sd_event_source_set_time(sd_event_source *s, uint64_t usec) { struct clock_data *d; assert_return(s, -EINVAL); - assert_return(usec != (uint64_t) -1, -EINVAL); assert_return(EVENT_SOURCE_IS_TIME(s->type), -EDOM); assert_return(s->event->state != SD_EVENT_FINISHED, -ESTALE); assert_return(!event_pid_changed(s->event), -ECHILD); @@ -1880,6 +1909,8 @@ static usec_t sleep_between(sd_event *e, usec_t a, usec_t b) { if (a <= 0) return 0; + if (a >= USEC_INFINITY) + return USEC_INFINITY; if (b <= a + 1) return a; @@ -1969,7 +2000,7 @@ static int event_arm_timer( d->needs_rearm = false; a = prioq_peek(d->earliest); - if (!a || a->enabled == SD_EVENT_OFF) { + if (!a || a->enabled == SD_EVENT_OFF || a->time.next == USEC_INFINITY) { if (d->fd < 0) return 0; @@ -1989,7 +2020,7 @@ static int event_arm_timer( b = prioq_peek(d->latest); assert_se(b && b->enabled != SD_EVENT_OFF); - t = sleep_between(e, a->time.next, b->time.next + b->time.accuracy); + t = sleep_between(e, a->time.next, time_event_source_latest(b)); if (d->next == t) return 0; @@ -2192,7 +2223,7 @@ static int process_signal(sd_event *e, struct signal_data *d, uint32_t events) { if (_unlikely_(n != sizeof(si))) return -EIO; - assert(si.ssi_signo < _NSIG); + assert(SIGNAL_VALID(si.ssi_signo)); read_one = true; @@ -2305,12 +2336,9 @@ static int source_dispatch(sd_event_source *s) { s->dispatching = false; - if (r < 0) { - if (s->description) - log_debug_errno(r, "Event source '%s' returned error, disabling: %m", s->description); - else - log_debug_errno(r, "Event source %p returned error, disabling: %m", s); - } + if (r < 0) + log_debug_errno(r, "Event source %s (type %s) returned error, disabling: %m", + strna(s->description), event_source_type_to_string(s->type)); if (s->n_ref == 0) source_free(s); @@ -2343,12 +2371,9 @@ static int event_prepare(sd_event *e) { r = s->prepare(s, s->userdata); s->dispatching = false; - if (r < 0) { - if (s->description) - log_debug_errno(r, "Prepare callback of event source '%s' returned error, disabling: %m", s->description); - else - log_debug_errno(r, "Prepare callback of event source %p returned error, disabling: %m", s); - } + if (r < 0) + log_debug_errno(r, "Prepare callback of event source %s (type %s) returned error, disabling: %m", + strna(s->description), event_source_type_to_string(s->type)); if (s->n_ref == 0) source_free(s); @@ -2453,7 +2478,9 @@ _public_ int sd_event_prepare(sd_event *e) { e->iteration++; + e->state = SD_EVENT_PREPARING; r = event_prepare(e); + e->state = SD_EVENT_INITIAL; if (r < 0) return r; @@ -2523,8 +2550,7 @@ _public_ int sd_event_wait(sd_event *e, uint64_t timeout) { goto finish; } - dual_timestamp_get(&e->timestamp); - e->timestamp_boottime = now(CLOCK_BOOTTIME); + triple_timestamp_get(&e->timestamp); for (i = 0; i < m; i++) { @@ -2536,7 +2562,7 @@ _public_ int sd_event_wait(sd_event *e, uint64_t timeout) { switch (*t) { case WAKEUP_EVENT_SOURCE: - r = process_io(e, ev_queue[i].data.ptr, ev_queue[i].events); + r = process_io(e, ev_queue[i].data.ptr, ev_queue[i].events); break; case WAKEUP_CLOCK_DATA: { @@ -2565,7 +2591,7 @@ _public_ int sd_event_wait(sd_event *e, uint64_t timeout) { if (r < 0) goto finish; - r = process_timer(e, e->timestamp_boottime, &e->boottime); + r = process_timer(e, e->timestamp.boottime, &e->boottime); if (r < 0) goto finish; @@ -2577,7 +2603,7 @@ _public_ int sd_event_wait(sd_event *e, uint64_t timeout) { if (r < 0) goto finish; - r = process_timer(e, e->timestamp_boottime, &e->boottime_alarm); + r = process_timer(e, e->timestamp.boottime, &e->boottime_alarm); if (r < 0) goto finish; @@ -2631,6 +2657,18 @@ _public_ int sd_event_dispatch(sd_event *e) { return 1; } +static void event_log_delays(sd_event *e) { + char b[ELEMENTSOF(e->delays) * DECIMAL_STR_MAX(unsigned) + 1]; + unsigned i; + int o; + + for (i = o = 0; i < ELEMENTSOF(e->delays); i++) { + o += snprintf(&b[o], sizeof(b) - o, "%u ", e->delays[i]); + e->delays[i] = 0; + } + log_debug("Event loop iterations: %.*s", o, b); +} + _public_ int sd_event_run(sd_event *e, uint64_t timeout) { int r; @@ -2639,11 +2677,30 @@ _public_ int sd_event_run(sd_event *e, uint64_t timeout) { assert_return(e->state != SD_EVENT_FINISHED, -ESTALE); assert_return(e->state == SD_EVENT_INITIAL, -EBUSY); + if (e->profile_delays && e->last_run) { + usec_t this_run; + unsigned l; + + this_run = now(CLOCK_MONOTONIC); + + l = u64log2(this_run - e->last_run); + assert(l < sizeof(e->delays)); + e->delays[l]++; + + if (this_run - e->last_log >= 5*USEC_PER_SEC) { + event_log_delays(e); + e->last_log = this_run; + } + } + r = sd_event_prepare(e); if (r == 0) /* There was nothing? Then wait... */ r = sd_event_wait(e, timeout); + if (e->profile_delays) + e->last_run = now(CLOCK_MONOTONIC); + if (r > 0) { /* There's something now, then let's dispatch it */ r = sd_event_dispatch(e); @@ -2726,30 +2783,23 @@ _public_ int sd_event_now(sd_event *e, clockid_t clock, uint64_t *usec) { assert_return(usec, -EINVAL); assert_return(!event_pid_changed(e), -ECHILD); - if (!dual_timestamp_is_set(&e->timestamp)) { + if (!TRIPLE_TIMESTAMP_HAS_CLOCK(clock)) + return -EOPNOTSUPP; + + /* Generate a clean error in case CLOCK_BOOTTIME is not available. Note that don't use clock_supported() here, + * for a reason: there are systems where CLOCK_BOOTTIME is supported, but CLOCK_BOOTTIME_ALARM is not, but for + * the purpose of getting the time this doesn't matter. */ + if (IN_SET(clock, CLOCK_BOOTTIME, CLOCK_BOOTTIME_ALARM) && !clock_boottime_supported()) + return -EOPNOTSUPP; + + if (!triple_timestamp_is_set(&e->timestamp)) { /* Implicitly fall back to now() if we never ran * before and thus have no cached time. */ *usec = now(clock); return 1; } - switch (clock) { - - case CLOCK_REALTIME: - case CLOCK_REALTIME_ALARM: - *usec = e->timestamp.realtime; - break; - - case CLOCK_MONOTONIC: - *usec = e->timestamp.monotonic; - break; - - case CLOCK_BOOTTIME: - case CLOCK_BOOTTIME_ALARM: - *usec = e->timestamp_boottime; - break; - } - + *usec = triple_timestamp_by_clock(&e->timestamp, clock); return 0; } #endif // 0 @@ -2855,3 +2905,11 @@ _public_ int sd_event_get_watchdog(sd_event *e) { return e->watchdog; } #endif // 0 + +_public_ int sd_event_get_iteration(sd_event *e, uint64_t *ret) { + assert_return(e, -EINVAL); + assert_return(!event_pid_changed(e), -ECHILD); + + *ret = e->iteration; + return 0; +}