diff options
| author | Lennart Poettering <lennart@poettering.net> | 2015-05-11 20:38:21 +0200 |
|---|---|---|
| committer | Lennart Poettering <lennart@poettering.net> | 2015-05-11 22:24:45 +0200 |
| commit | f2341e0a87cab1558c84c933956e9181d5fb6c52 (patch) | |
| tree | 536878a0b833b532321b34613b20684d8fcf0624 | |
| parent | 6f856a0992aee3fb06cb13a761b902657ff228ea (diff) | |
core,network: major per-object logging rework
This changes log_unit_info() (and friends) to take a real Unit* object
insted of just a unit name as parameter. The call will now prefix all
logged messages with the unit name, thus allowing the unit name to be
dropped from the various passed romat strings, simplifying invocations
drastically, and unifying log output across messages. Also, UNIT= vs.
USER_UNIT= is now derived from the Manager object attached to the Unit
object, instead of getpid(). This has the benefit of correcting the
field for --test runs.
Also contains a couple of other logging improvements:
- Drops a couple of strerror() invocations in favour of using %m.
- Not only .mount units now warn if a symlinks exist for the mount
point already, .automount units do that too, now.
- A few invocations of log_struct() that didn't actually pass any
additional structured data have been replaced by simpler invocations
of log_unit_info() and friends.
- For structured data a new LOG_UNIT_MESSAGE() macro has been added,
that works like LOG_MESSAGE() but prefixes the message with the unit
name. Similar, there's now LOG_LINK_MESSAGE() and
LOG_NETDEV_MESSAGE().
- For structured data new LOG_UNIT_ID(), LOG_LINK_INTERFACE(),
LOG_NETDEV_INTERFACE() macros have been added that generate the
necessary per object fields. The old log_unit_struct() call has been
removed in favour of these new macros used in raw log_struct()
invocations. In addition to removing one more function call this
allows generated structured log messages that contain two object
fields, as necessary for example for network interfaces that are
joined into another network interface, and whose messages shall be
indexed by both.
- The LOG_ERRNO() macro has been removed, in favour of
log_struct_errno(). The latter has the benefit of ensuring that %m in
format strings is properly resolved to the specified error number.
- A number of logging messages have been converted to use
log_unit_info() instead of log_info()
- The client code in sysv-generator no longer #includes core code from
src/core/.
- log_unit_full_errno() has been removed, log_unit_full() instead takes
an errno now, too.
- log_unit_info(), log_link_info(), log_netdev_info() and friends, now
avoid double evaluation of their parameters
32 files changed, 814 insertions, 956 deletions
diff --git a/src/analyze/analyze-verify.c b/src/analyze/analyze-verify.c index 4145812bc7..e7df55f5a5 100644 --- a/src/analyze/analyze-verify.c +++ b/src/analyze/analyze-verify.c @@ -72,8 +72,7 @@ static int verify_socket(Unit *u) { /* This makes sure instance is created if necessary. */ r = socket_instantiate_service(SOCKET(u)); if (r < 0) { - log_unit_error(u->id, "Socket %s cannot be started, failed to create instance.", - u->id); + log_unit_error_errno(u, r, "Socket cannot be started, failed to create instance: %m"); return r; } @@ -82,11 +81,10 @@ static int verify_socket(Unit *u) { Service *service; service = SERVICE(UNIT_DEREF(SOCKET(u)->service)); - log_unit_debug(u->id, "%s uses %s", u->id, UNIT(service)->id); + log_unit_debug(u, "Using %s", UNIT(service)->id); if (UNIT(service)->load_state != UNIT_LOADED) { - log_unit_error(u->id, "Service %s not loaded, %s cannot be started.", - UNIT(service)->id, u->id); + log_unit_error(u, "Service %s not loaded, %s cannot be started.", UNIT(service)->id, u->id); return -ENOENT; } } @@ -98,11 +96,8 @@ static int verify_executable(Unit *u, ExecCommand *exec) { if (exec == NULL) return 0; - if (access(exec->path, X_OK) < 0) { - log_unit_error(u->id, "%s: command %s is not executable: %m", - u->id, exec->path); - return -errno; - } + if (access(exec->path, X_OK) < 0) + return log_unit_error_errno(u, errno, "Command %s is not executable: %m", exec->path); return 0; } @@ -143,16 +138,15 @@ static int verify_documentation(Unit *u, bool check_man) { int r = 0, k; STRV_FOREACH(p, u->documentation) { - log_unit_debug(u->id, "%s: found documentation item %s.", u->id, *p); + log_unit_debug(u, "Found documentation item: %s", *p); + if (check_man && startswith(*p, "man:")) { k = show_man_page(*p + 4, true); if (k != 0) { if (k < 0) - log_unit_error(u->id, "%s: can't show %s: %s", - u->id, *p, strerror(-r)); + log_unit_error_errno(u, r, "Can't show %s: %m", *p); else { - log_unit_error(u->id, "%s: man %s command failed with code %d", - u->id, *p + 4, k); + log_unit_error_errno(u, r, "man %s command failed with code %d", *p + 4, k); k = -ENOEXEC; } if (r == 0) @@ -176,14 +170,12 @@ static int verify_unit(Unit *u, bool check_man) { if (log_get_max_level() >= LOG_DEBUG) unit_dump(u, stdout, "\t"); - log_unit_debug(u->id, "Creating %s/start job", u->id); + log_unit_debug(u, "Creating %s/start job", u->id); r = manager_add_job(u->manager, JOB_START, u, JOB_REPLACE, false, &err, &j); if (sd_bus_error_is_set(&err)) - log_unit_error(u->id, "Error: %s: %s", - err.name, err.message); + log_unit_error(u, "Error: %s: %s", err.name, err.message); if (r < 0) - log_unit_error(u->id, "Failed to create %s/start: %s", - u->id, strerror(-r)); + log_unit_error_errno(u, r, "Failed to create %s/start: %m", u->id); k = verify_socket(u); if (k < 0 && r == 0) diff --git a/src/core/automount.c b/src/core/automount.c index 1806fa39d3..b747c6f38f 100644 --- a/src/core/automount.c +++ b/src/core/automount.c @@ -176,16 +176,16 @@ static int automount_verify(Automount *a) { return 0; if (path_equal(a->where, "/")) { - log_unit_error(UNIT(a)->id, "Cannot have an automount unit for the root directory. Refusing."); + log_unit_error(UNIT(a), "Cannot have an automount unit for the root directory. Refusing."); return -EINVAL; } r = unit_name_from_path(a->where, ".automount", &e); if (r < 0) - return log_unit_error(UNIT(a)->id, "Failed to generate unit name from path: %m"); + return log_unit_error(UNIT(a), "Failed to generate unit name from path: %m"); if (!unit_has_name(UNIT(a), e)) { - log_unit_error(UNIT(a)->id, "%s's Where setting doesn't match unit name. Refusing.", UNIT(a)->id); + log_unit_error(UNIT(a), "Where= setting doesn't match unit name. Refusing."); return -EINVAL; } @@ -249,11 +249,7 @@ static void automount_set_state(Automount *a, AutomountState state) { unmount_autofs(a); if (state != old_state) - log_unit_debug(UNIT(a)->id, - "%s changed %s -> %s", - UNIT(a)->id, - automount_state_to_string(old_state), - automount_state_to_string(state)); + log_unit_debug(UNIT(a), "Changed %s -> %s", automount_state_to_string(old_state), automount_state_to_string(state)); unit_notify(UNIT(a), state_translation_table[old_state], state_translation_table[state], true); } @@ -449,9 +445,9 @@ static int automount_send_ready(Automount *a, Set *tokens, int status) { return ioctl_fd; if (status) - log_unit_debug_errno(UNIT(a)->id, status, "Sending failure: %m"); + log_unit_debug_errno(UNIT(a), status, "Sending failure: %m"); else - log_unit_debug(UNIT(a)->id, "Sending success."); + log_unit_debug(UNIT(a), "Sending success."); r = 0; @@ -536,8 +532,15 @@ static void automount_enter_waiting(Automount *a) { assert(a->pipe_fd < 0); assert(a->where); - if (a->tokens) - set_clear(a->tokens); + set_clear(a->tokens); + + r = unit_fail_if_symlink(UNIT(a), a->where); + if (r < 0) + goto fail; + + (void) mkdir_p_label(a->where, 0555); + + unit_warn_if_dir_nonempty(UNIT(a), a->where); dev_autofs_fd = open_dev_autofs(UNIT(a)->manager); if (dev_autofs_fd < 0) { @@ -545,11 +548,6 @@ static void automount_enter_waiting(Automount *a) { goto fail; } - /* We knowingly ignore the results of this call */ - mkdir_p_label(a->where, 0555); - - warn_if_dir_nonempty(a->meta.id, a->where); - if (pipe2(p, O_NONBLOCK|O_CLOEXEC) < 0) { r = -errno; goto fail; @@ -610,8 +608,7 @@ fail: if (mounted) repeat_unmount(a->where); - log_unit_error(UNIT(a)->id, - "Failed to initialize automounter: %s", strerror(-r)); + log_unit_error_errno(UNIT(a), r, "Failed to initialize automounter: %m"); automount_enter_dead(a, AUTOMOUNT_FAILURE_RESOURCES); } @@ -654,15 +651,15 @@ static int automount_dispatch_expire(sd_event_source *source, usec_t usec, void data->dev_autofs_fd = fcntl(UNIT(a)->manager->dev_autofs_fd, F_DUPFD_CLOEXEC, 3); if (data->dev_autofs_fd < 0) - return log_unit_error_errno(UNIT(a)->id, errno, "Failed to duplicate autofs fd: %m"); + return log_unit_error_errno(UNIT(a), errno, "Failed to duplicate autofs fd: %m"); data->ioctl_fd = open_ioctl_fd(UNIT(a)->manager->dev_autofs_fd, a->where, a->dev_id); if (data->ioctl_fd < 0) - return log_unit_error_errno(UNIT(a)->id, data->ioctl_fd, "Couldn't open autofs ioctl fd: %m"); + return log_unit_error_errno(UNIT(a), data->ioctl_fd, "Couldn't open autofs ioctl fd: %m"); r = asynchronous_job(expire_thread, data); if (r < 0) - return log_unit_error_errno(UNIT(a)->id, r, "Failed to start expire job: %m"); + return log_unit_error_errno(UNIT(a), r, "Failed to start expire job: %m"); data = NULL; @@ -708,8 +705,7 @@ static void automount_enter_runnning(Automount *a) { /* We don't take mount requests anymore if we are supposed to * shut down anyway */ if (unit_stop_pending(UNIT(a))) { - log_unit_debug(UNIT(a)->id, - "Suppressing automount request on %s since unit stop is scheduled.", UNIT(a)->id); + log_unit_debug(UNIT(a), "Suppressing automount request since unit stop is scheduled."); automount_send_ready(a, a->tokens, -EHOSTDOWN); automount_send_ready(a, a->expire_tokens, -EHOSTDOWN); return; @@ -719,27 +715,24 @@ static void automount_enter_runnning(Automount *a) { /* Before we do anything, let's see if somebody is playing games with us? */ if (lstat(a->where, &st) < 0) { - log_unit_warning_errno(UNIT(a)->id, errno, "%s failed to stat automount point: %m", UNIT(a)->id); + log_unit_warning_errno(UNIT(a), errno, "Failed to stat automount point: %m"); goto fail; } if (!S_ISDIR(st.st_mode) || st.st_dev != a->dev_id) - log_unit_info(UNIT(a)->id, - "%s's automount point already active?", UNIT(a)->id); + log_unit_info(UNIT(a), "Automount point already active?"); else { r = manager_add_job(UNIT(a)->manager, JOB_START, UNIT_TRIGGER(UNIT(a)), JOB_REPLACE, true, &error, NULL); if (r < 0) { - log_unit_warning(UNIT(a)->id, - "%s failed to queue mount startup job: %s", - UNIT(a)->id, bus_error_message(&error, r)); + log_unit_warning(UNIT(a), "Failed to queue mount startup job: %s", bus_error_message(&error, r)); goto fail; } } r = automount_start_expire(a); if (r < 0) - log_unit_warning_errno(UNIT(a)->id, r, "Failed to start expiration timer, ignoring: %m"); + log_unit_warning_errno(UNIT(a), r, "Failed to start expiration timer, ignoring: %m"); automount_set_state(a, AUTOMOUNT_RUNNING); return; @@ -755,7 +748,7 @@ static int automount_start(Unit *u) { assert(a->state == AUTOMOUNT_DEAD || a->state == AUTOMOUNT_FAILED); if (path_is_mount_point(a->where, false) > 0) { - log_unit_error(u->id, "Path %s is already a mount point, refusing start for %s", a->where, u->id); + log_unit_error(u, "Path %s is already a mount point, refusing start.", a->where); return -EEXIST; } @@ -820,7 +813,7 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu state = automount_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else a->deserialized_state = state; } else if (streq(key, "result")) { @@ -828,7 +821,7 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu f = automount_result_from_string(value); if (f < 0) - log_unit_debug(u->id, "Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != AUTOMOUNT_SUCCESS) a->result = f; @@ -836,14 +829,14 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu unsigned d; if (safe_atou(value, &d) < 0) - log_unit_debug(u->id, "Failed to parse dev-id value %s", value); + log_unit_debug(u, "Failed to parse dev-id value: %s", value); else a->dev_id = (unsigned) d; } else if (streq(key, "token")) { unsigned token; if (safe_atou(value, &token) < 0) - log_unit_debug(u->id, "Failed to parse token value %s", value); + log_unit_debug(u, "Failed to parse token value: %s", value); else { r = set_ensure_allocated(&a->tokens, NULL); if (r < 0) { @@ -853,13 +846,13 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu r = set_put(a->tokens, UINT_TO_PTR(token)); if (r < 0) - log_unit_error_errno(u->id, r, "Failed to add token to set: %m"); + log_unit_error_errno(u, r, "Failed to add token to set: %m"); } } else if (streq(key, "expire-token")) { unsigned token; if (safe_atou(value, &token) < 0) - log_unit_debug(u->id, "Failed to parse token value %s", value); + log_unit_debug(u, "Failed to parse token value: %s", value); else { r = set_ensure_allocated(&a->expire_tokens, NULL); if (r < 0) { @@ -869,19 +862,19 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu r = set_put(a->expire_tokens, UINT_TO_PTR(token)); if (r < 0) - log_unit_error_errno(u->id, r, "Failed to add expire token to set: %m"); + log_unit_error_errno(u, r, "Failed to add expire token to set: %m"); } } else if (streq(key, "pipe-fd")) { int fd; if (safe_atoi(value, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse pipe-fd value %s", value); + log_unit_debug(u, "Failed to parse pipe-fd value: %s", value); else { safe_close(a->pipe_fd); a->pipe_fd = fdset_remove(fds, fd); } } else - log_unit_debug(u->id, "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -917,14 +910,13 @@ static int automount_dispatch_io(sd_event_source *s, int fd, uint32_t events, vo assert(fd == a->pipe_fd); if (events != EPOLLIN) { - log_unit_error(UNIT(a)->id, "%s: got invalid poll event %"PRIu32" on pipe (fd=%d)", - UNIT(a)->id, events, fd); + log_unit_error(UNIT(a), "Got invalid poll event %"PRIu32" on pipe (fd=%d)", events, fd); goto fail; } r = loop_read_exact(a->pipe_fd, &packet, sizeof(packet), true); if (r < 0) { - log_unit_error_errno(UNIT(a)->id, r, "Invalid read from pipe: %m"); + log_unit_error_errno(UNIT(a), r, "Invalid read from pipe: %m"); goto fail; } @@ -936,21 +928,19 @@ static int automount_dispatch_io(sd_event_source *s, int fd, uint32_t events, vo _cleanup_free_ char *p = NULL; get_process_comm(packet.v5_packet.pid, &p); - log_unit_info(UNIT(a)->id, - "Got automount request for %s, triggered by %"PRIu32" (%s)", - a->where, packet.v5_packet.pid, strna(p)); + log_unit_info(UNIT(a), "Got automount request for %s, triggered by %"PRIu32" (%s)", a->where, packet.v5_packet.pid, strna(p)); } else - log_unit_debug(UNIT(a)->id, "Got direct mount request on %s", a->where); + log_unit_debug(UNIT(a), "Got direct mount request on %s", a->where); r = set_ensure_allocated(&a->tokens, NULL); if (r < 0) { - log_unit_error(UNIT(a)->id, "Failed to allocate token set."); + log_unit_error(UNIT(a), "Failed to allocate token set."); goto fail; } r = set_put(a->tokens, UINT_TO_PTR(packet.v5_packet.wait_queue_token)); if (r < 0) { - log_unit_error_errno(UNIT(a)->id, r, "Failed to remember token: %m"); + log_unit_error_errno(UNIT(a), r, "Failed to remember token: %m"); goto fail; } @@ -958,32 +948,30 @@ static int automount_dispatch_io(sd_event_source *s, int fd, uint32_t events, vo break; case autofs_ptype_expire_direct: - log_unit_debug(UNIT(a)->id, "Got direct umount request on %s", a->where); + log_unit_debug(UNIT(a), "Got direct umount request on %s", a->where); (void) sd_event_source_set_enabled(a->expire_event_source, SD_EVENT_OFF); r = set_ensure_allocated(&a->expire_tokens, NULL); if (r < 0) { - log_unit_error(UNIT(a)->id, "Failed to allocate token set."); + log_unit_error(UNIT(a), "Failed to allocate token set."); goto fail; } r = set_put(a->expire_tokens, UINT_TO_PTR(packet.v5_packet.wait_queue_token)); if (r < 0) { - log_unit_error_errno(UNIT(a)->id, r, "Failed to remember token: %m"); + log_unit_error_errno(UNIT(a), r, "Failed to remember token: %m"); goto fail; } r = manager_add_job(UNIT(a)->manager, JOB_STOP, UNIT_TRIGGER(UNIT(a)), JOB_REPLACE, true, &error, NULL); if (r < 0) { - log_unit_warning(UNIT(a)->id, - "%s failed to queue umount startup job: %s", - UNIT(a)->id, bus_error_message(&error, r)); + log_unit_warning(UNIT(a), "Failed to queue umount startup job: %s", bus_error_message(&error, r)); goto fail; } break; default: - log_unit_error(UNIT(a)->id, "Received unknown automount request %i", packet.hdr.type); + log_unit_error(UNIT(a), "Received unknown automount request %i", packet.hdr.type); break; } diff --git a/src/core/busname.c b/src/core/busname.c index 3dc6e87e55..2010ec0985 100644 --- a/src/core/busname.c +++ b/src/core/busname.c @@ -208,13 +208,13 @@ static int busname_verify(BusName *n) { return 0; if (!service_name_is_valid(n->name)) { - log_unit_error(UNIT(n)->id, "%s's Name= setting is not a valid service name Refusing.", UNIT(n)->id); + log_unit_error(UNIT(n), "Name= setting is not a valid service name Refusing."); return -EINVAL; } e = strjoina(n->name, ".busname"); if (!unit_has_name(UNIT(n), e)) { - log_unit_error(UNIT(n)->id, "%s's Name= setting doesn't match unit name. Refusing.", UNIT(n)->id); + log_unit_error(UNIT(n), "Name= setting doesn't match unit name. Refusing."); return -EINVAL; } @@ -276,7 +276,7 @@ static void busname_unwatch_fd(BusName *n) { r = sd_event_source_set_enabled(n->starter_event_source, SD_EVENT_OFF); if (r < 0) - log_unit_debug(UNIT(n)->id, "Failed to disable event source."); + log_unit_debug_errno(UNIT(n), r, "Failed to disable event source: %m"); } static int busname_watch_fd(BusName *n) { @@ -293,7 +293,7 @@ static int busname_watch_fd(BusName *n) { r = sd_event_add_io(UNIT(n)->manager->event, &n->starter_event_source, n->starter_fd, EPOLLIN, busname_dispatch_io, n); if (r < 0) { - log_unit_warning_errno(UNIT(n)->id, r, "Failed to watch starter fd: %m"); + log_unit_warning_errno(UNIT(n), r, "Failed to watch starter fd: %m"); busname_unwatch_fd(n); return r; } @@ -315,7 +315,7 @@ static int busname_open_fd(BusName *n) { mode = UNIT(n)->manager->running_as == SYSTEMD_SYSTEM ? "system" : "user"; n->starter_fd = bus_kernel_open_bus_fd(mode, &path); if (n->starter_fd < 0) - return log_unit_warning_errno(UNIT(n)->id, n->starter_fd, "Failed to open %s: %m", path ?: "kdbus"); + return log_unit_warning_errno(UNIT(n), n->starter_fd, "Failed to open %s: %m", path ?: "kdbus"); return 0; } @@ -339,8 +339,7 @@ static void busname_set_state(BusName *n, BusNameState state) { busname_close_fd(n); if (state != old_state) - log_unit_debug(UNIT(n)->id, "%s changed %s -> %s", - UNIT(n)->id, busname_state_to_string(old_state), busname_state_to_string(state)); + log_unit_debug(UNIT(n), "Changed %s -> %s", busname_state_to_string(old_state), busname_state_to_string(state)); unit_notify(UNIT(n), state_translation_table[old_state], state_translation_table[state], true); } @@ -462,14 +461,14 @@ static void busname_enter_signal(BusName *n, BusNameState state, BusNameResult f n->control_pid, false); if (r < 0) { - log_unit_warning_errno(UNIT(n)->id, r, "%s failed to kill control process: %m", UNIT(n)->id); + log_unit_warning_errno(UNIT(n), r, "Failed to kill control process: %m"); goto fail; } if (r > 0) { r = busname_arm_timer(n); if (r < 0) { - log_unit_warning_errno(UNIT(n)->id, r, "%s failed to arm timer: %m", UNIT(n)->id); + log_unit_warning_errno(UNIT(n), r, "Failed to arm timer: %m"); goto fail; } @@ -493,7 +492,7 @@ static void busname_enter_listening(BusName *n) { if (n->activating) { r = busname_watch_fd(n); if (r < 0) { - log_unit_warning_errno(UNIT(n)->id, r, "%s failed to watch names: %m", UNIT(n)->id); + log_unit_warning_errno(UNIT(n), r, "Failed to watch names: %m"); goto fail; } @@ -524,7 +523,7 @@ static void busname_enter_making(BusName *n) { r = busname_make_starter(n, &n->control_pid); if (r < 0) { - log_unit_warning_errno(UNIT(n)->id, r, "%s failed to fork 'making' task: %m", UNIT(n)->id); + log_unit_warning_errno(UNIT(n), r, "Failed to fork 'making' task: %m"); goto fail; } @@ -535,7 +534,7 @@ static void busname_enter_making(BusName *n) { r = bus_kernel_make_starter(n->starter_fd, n->name, n->activating, n->accept_fd, NULL, n->policy_world); if (r < 0) { - log_unit_warning_errno(UNIT(n)->id, r, "%s failed to make starter: %m", UNIT(n)->id); + log_unit_warning_errno(UNIT(n), r, "Failed to make starter: %m"); goto fail; } @@ -564,7 +563,7 @@ static void busname_enter_running(BusName *n) { * shut down anyway */ if (unit_stop_pending(UNIT(n))) { - log_unit_debug(UNIT(n)->id, "Suppressing activation request on %s since unit stop is scheduled.", UNIT(n)->id); + log_unit_debug(UNIT(n), "Suppressing activation request since unit stop is scheduled."); /* Flush all queued activation reqeuest by closing and reopening the connection */ bus_kernel_drop_one(n->starter_fd); @@ -591,7 +590,7 @@ static void busname_enter_running(BusName *n) { return; fail: - log_unit_warning(UNIT(n)->id, "%s failed to queue service startup job: %s", UNIT(n)->id, bus_error_message(&error, r)); + log_unit_warning(UNIT(n), "Failed to queue service startup job: %s", bus_error_message(&error, r)); busname_enter_dead(n, BUSNAME_FAILURE_RESOURCES); } @@ -615,7 +614,7 @@ static int busname_start(Unit *u) { service = SERVICE(UNIT_DEREF(n->service)); if (UNIT(service)->load_state != UNIT_LOADED) { - log_unit_error(u->id, "Bus service %s not loaded, refusing.", UNIT(service)->id); + log_unit_error(u, "Bus service %s not loaded, refusing.", UNIT(service)->id); return -ENOENT; } } @@ -689,7 +688,7 @@ static int busname_deserialize_item(Unit *u, const char *key, const char *value, state = busname_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else n->deserialized_state = state; @@ -698,7 +697,7 @@ static int busname_deserialize_item(Unit *u, const char *key, const char *value, f = busname_result_from_string(value); if (f < 0) - log_unit_debug(u->id, "Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != BUSNAME_SUCCESS) n->result = f; @@ -706,20 +705,20 @@ static int busname_deserialize_item(Unit *u, const char *key, const char *value, pid_t pid; if (parse_pid(value, &pid) < 0) - log_unit_debug(u->id, "Failed to parse control-pid value %s", value); + log_unit_debug(u, "Failed to parse control-pid value: %s", value); else n->control_pid = pid; } else if (streq(key, "starter-fd")) { int fd; if (safe_atoi(value, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse starter fd value %s", value); + log_unit_debug(u, "Failed to parse starter fd value: %s", value); else { safe_close(n->starter_fd); n->starter_fd = fdset_remove(fds, fd); } } else - log_unit_debug(u->id, "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -769,8 +768,7 @@ static int busname_peek_message(BusName *n) { if (errno == EINTR || errno == EAGAIN) return 0; - log_unit_error(UNIT(n)->id, "%s: Failed to query activation message: %m", UNIT(n)->id); - return -errno; + return log_unit_error_errno(UNIT(n), errno, "Failed to query activation message: %m"); } /* We map as late as possible, and unmap imemdiately after @@ -786,8 +784,7 @@ static int busname_peek_message(BusName *n) { p = mmap(NULL, sz, PROT_READ, MAP_SHARED, n->starter_fd, start); if (p == MAP_FAILED) { - log_unit_error(UNIT(n)->id, "%s: Failed to map activation message: %m", UNIT(n)->id); - r = -errno; + r = log_unit_error_errno(UNIT(n), errno, "Failed to map activation message: %m"); goto finish; } @@ -806,7 +803,7 @@ static int busname_peek_message(BusName *n) { } if (pid > 0) - log_unit_debug(UNIT(n)->id, "%s: Activation triggered by process " PID_FMT " (%s)", UNIT(n)->id, pid, strna(comm)); + log_unit_debug(UNIT(n), "Activation triggered by process " PID_FMT " (%s)", pid, strna(comm)); r = 0; @@ -816,7 +813,7 @@ finish: cmd_free.offset = cmd_recv.msg.offset; if (ioctl(n->starter_fd, KDBUS_CMD_FREE, &cmd_free) < 0) - log_unit_warning(UNIT(n)->id, "Failed to free peeked message, ignoring: %m"); + log_unit_warning(UNIT(n), "Failed to free peeked message, ignoring: %m"); return r; } @@ -830,11 +827,10 @@ static int busname_dispatch_io(sd_event_source *source, int fd, uint32_t revents if (n->state != BUSNAME_LISTENING) return 0; - log_unit_debug(UNIT(n)->id, "Activation request on %s", UNIT(n)->id); + log_unit_debug(UNIT(n), "Activation request"); if (revents != EPOLLIN) { - log_unit_error(UNIT(n)->id, "%s: Got unexpected poll event (0x%x) on starter fd.", - UNIT(n)->id, revents); + log_unit_error(UNIT(n), "Got unexpected poll event (0x%x) on starter fd.", revents); goto fail; } @@ -870,10 +866,8 @@ static void busname_sigchld_event(Unit *u, pid_t pid, int code, int status) { else assert_not_reached("Unknown sigchld code"); - log_unit_full(u->id, - f == BUSNAME_SUCCESS ? LOG_DEBUG : LOG_NOTICE, - "%s control process exited, code=%s status=%i", - u->id, sigchld_code_to_string(code), status); + log_unit_full(u, f == BUSNAME_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, + "Control process exited, code=%s status=%i", sigchld_code_to_string(code), status); if (f != BUSNAME_SUCCESS) n->result = f; @@ -909,17 +903,17 @@ static int busname_dispatch_timer(sd_event_source *source, usec_t usec, void *us switch (n->state) { case BUSNAME_MAKING: - log_unit_warning(UNIT(n)->id, "%s making timed out. Terminating.", UNIT(n)->id); + log_unit_warning(UNIT(n), "Making timed out. Terminating."); busname_enter_signal(n, BUSNAME_SIGTERM, BUSNAME_FAILURE_TIMEOUT); break; case BUSNAME_SIGTERM: - log_unit_warning(UNIT(n)->id, "%s stopping timed out. Killing.", UNIT(n)->id); + log_unit_warning(UNIT(n), "Stopping timed out. Killing."); busname_enter_signal(n, BUSNAME_SIGKILL, BUSNAME_FAILURE_TIMEOUT); break; case BUSNAME_SIGKILL: - log_unit_warning(UNIT(n)->id, "%s still around after SIGKILL. Ignoring.", UNIT(n)->id); + log_unit_warning(UNIT(n), "Processes still around after SIGKILL. Ignoring."); busname_enter_dead(n, BUSNAME_FAILURE_TIMEOUT); break; diff --git a/src/core/dbus-unit.c b/src/core/dbus-unit.c index 056c7117b2..a4ece2adb5 100644 --- a/src/core/dbus-unit.c +++ b/src/core/dbus-unit.c @@ -666,7 +666,7 @@ static int property_get_current_memory( r = unit_get_memory_current(u, &sz); if (r < 0 && r != -ENODATA) - log_unit_warning_errno(u->id, r, "Failed to get memory.usage_in_bytes attribute: %m"); + log_unit_warning_errno(u, r, "Failed to get memory.usage_in_bytes attribute: %m"); return sd_bus_message_append(reply, "t", sz); } @@ -690,7 +690,7 @@ static int property_get_cpu_usage( r = unit_get_cpu_usage(u, &ns); if (r < 0 && r != -ENODATA) - log_unit_warning_errno(u->id, r, "Failed to get cpuacct.usage attribute: %m"); + log_unit_warning_errno(u, r, "Failed to get cpuacct.usage attribute: %m"); return sd_bus_message_append(reply, "t", ns); } @@ -776,7 +776,7 @@ void bus_unit_send_change_signal(Unit *u) { r = bus_foreach_bus(u->manager, NULL, u->sent_dbus_new_signal ? send_changed_signal : send_new_signal, u); if (r < 0) - log_debug_errno(r, "Failed to send unit change signal for %s: %m", u->id); + log_unit_debug_errno(u, r, "Failed to send unit change signal for %s: %m", u->id); u->sent_dbus_new_signal = true; } @@ -822,7 +822,7 @@ void bus_unit_send_removed_signal(Unit *u) { r = bus_foreach_bus(u->manager, NULL, send_removed_signal, u); if (r < 0) - log_debug_errno(r, "Failed to send unit remove signal for %s: %m", u->id); + log_unit_debug_errno(u, r, "Failed to send unit remove signal for %s: %m", u->id); } int bus_unit_queue_job( diff --git a/src/core/device.c b/src/core/device.c index c09ea6c197..a0eb0f449c 100644 --- a/src/core/device.c +++ b/src/core/device.c @@ -132,10 +132,7 @@ static void device_set_state(Device *d, DeviceState state) { d->state = state; if (state != old_state) - log_unit_debug(UNIT(d)->id, - "%s changed %s -> %s", UNIT(d)->id, - device_state_to_string(old_state), - device_state_to_string(state)); + log_unit_debug(UNIT(d), "Changed %s -> %s", device_state_to_string(old_state), device_state_to_string(state)); unit_notify(UNIT(d), state_translation_table[old_state], state_translation_table[state], true); } @@ -183,11 +180,11 @@ static int device_deserialize_item(Unit *u, const char *key, const char *value, state = device_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else d->deserialized_state = state; } else - log_unit_debug(u->id, "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -252,7 +249,7 @@ static int device_update_description(Unit *u, struct udev_device *dev, const cha r = unit_set_description(u, path); if (r < 0) - log_unit_error_errno(u->id, r, "Failed to set device description: %m"); + log_unit_error_errno(u, r, "Failed to set device description: %m"); return r; } @@ -281,14 +278,14 @@ static int device_add_udev_wants(Unit *u, struct udev_device *dev) { r = unit_name_mangle(e, UNIT_NAME_NOGLOB, &n); if (r < 0) - return log_unit_error_errno(u->id, r, "Failed to mangle unit name: %m"); + return log_unit_error_errno(u, r, "Failed to mangle unit name: %m"); r = unit_add_dependency_by_name(u, UNIT_WANTS, n, NULL, true); if (r < 0) - return log_unit_error_errno(u->id, r, "Failed to add wants dependency: %m"); + return log_unit_error_errno(u, r, "Failed to add wants dependency: %m"); } if (!isempty(state)) - log_unit_warning(u->id, "Property %s on %s has trailing garbage, ignoring.", property, strna(udev_device_get_syspath(dev))); + log_unit_warning(u, "Property %s on %s has trailing garbage, ignoring.", property, strna(udev_device_get_syspath(dev))); return 0; } @@ -317,7 +314,7 @@ static int device_setup_unit(Manager *m, struct udev_device *dev, const char *pa if (u && DEVICE(u)->sysfs && !path_equal(DEVICE(u)->sysfs, sysfs)) { - log_unit_debug(u->id, "Device %s appeared twice with different sysfs paths %s and %s", e, DEVICE(u)->sysfs, sysfs); + log_unit_debug(u, "Device %s appeared twice with different sysfs paths %s and %s", e, DEVICE(u)->sysfs, sysfs); return -EEXIST; } @@ -358,7 +355,7 @@ static int device_setup_unit(Manager *m, struct udev_device *dev, const char *pa return 0; fail: - log_unit_warning_errno(u->id, r, "Failed to set up device unit: %m"); + log_unit_warning_errno(u, r, "Failed to set up device unit: %m"); if (delete) unit_free(u); diff --git a/src/core/execute.c b/src/core/execute.c index 9eba323529..1a297ba96c 100644 --- a/src/core/execute.c +++ b/src/core/execute.c @@ -392,11 +392,12 @@ static int setup_input(const ExecContext *context, int socket_fd, bool apply_tty } } -static int setup_output(const ExecContext *context, int fileno, int socket_fd, const char *ident, const char *unit_id, bool apply_tty_stdin, uid_t uid, gid_t gid) { +static int setup_output(Unit *unit, const ExecContext *context, int fileno, int socket_fd, const char *ident, bool apply_tty_stdin, uid_t uid, gid_t gid) { ExecOutput o; ExecInput i; int r; + assert(unit); assert(context); assert(ident); @@ -459,15 +460,9 @@ static int setup_output(const ExecContext *context, int fileno, int socket_fd, c case EXEC_OUTPUT_KMSG_AND_CONSOLE: case EXEC_OUTPUT_JOURNAL: case EXEC_OUTPUT_JOURNAL_AND_CONSOLE: - r = connect_logger_as(context, o, ident, unit_id, fileno, uid, gid); + r = connect_logger_as(context, o, ident, unit->id, fileno, uid, gid); if (r < 0) { - log_unit_struct(unit_id, - LOG_ERR, - LOG_MESSAGE("Failed to connect %s of %s to the journal socket: %s", - fileno == STDOUT_FILENO ? "stdout" : "stderr", - unit_id, strerror(-r)), - LOG_ERRNO(-r), - NULL); + log_unit_error_errno(unit, r, "Failed to connect %s to the journal socket, ignoring: %m", fileno == STDOUT_FILENO ? "stdout" : "stderr"); r = open_null_as(O_WRONLY, fileno); } return r; @@ -1263,6 +1258,7 @@ static int build_environment( } static int exec_child( + Unit *unit, ExecCommand *command, const ExecContext *context, const ExecParameters *params, @@ -1282,6 +1278,7 @@ static int exec_child( gid_t gid = GID_INVALID; int i, r; + assert(unit); assert(command); assert(context); assert(params); @@ -1383,13 +1380,13 @@ static int exec_child( return r; } - r = setup_output(context, STDOUT_FILENO, socket_fd, basename(command->path), params->unit_id, params->apply_tty_stdin, uid, gid); + r = setup_output(unit, context, STDOUT_FILENO, socket_fd, basename(command->path), params->apply_tty_stdin, uid, gid); if (r < 0) { *exit_status = EXIT_STDOUT; return r; } - r = setup_output(context, STDERR_FILENO, socket_fd, basename(command->path), params->unit_id, params->apply_tty_stdin, uid, gid); + r = setup_output(unit, context, STDERR_FILENO, socket_fd, basename(command->path), params->apply_tty_stdin, uid, gid); if (r < 0) { *exit_status = EXIT_STDERR; return r; @@ -1415,7 +1412,7 @@ static int exec_child( r = write_string_file("/proc/self/oom_score_adj", t); if (r == -EPERM || r == -EACCES) { log_open(); - log_unit_debug_errno(params->unit_id, r, "Failed to adjust OOM setting, assuming containerized execution, ignoring: %m"); + log_unit_debug_errno(unit, r, "Failed to adjust OOM setting, assuming containerized execution, ignoring: %m"); log_close(); } else if (r < 0) { *exit_status = EXIT_OOM_ADJUST; @@ -1600,7 +1597,7 @@ static int exec_child( * silently proceeed. */ if (r == -EPERM || r == -EACCES) { log_open(); - log_unit_debug_errno(params->unit_id, r, "Failed to set up namespace, assuming containerized execution, ignoring: %m"); + log_unit_debug_errno(unit, r, "Failed to set up namespace, assuming containerized execution, ignoring: %m"); log_close(); } else if (r < 0) { *exit_status = EXIT_NAMESPACE; @@ -1801,11 +1798,11 @@ static int exec_child( line = exec_command_line(final_argv); if (line) { log_open(); - log_unit_struct(params->unit_id, - LOG_DEBUG, - "EXECUTABLE=%s", command->path, - LOG_MESSAGE("Executing: %s", line), - NULL); + log_struct(LOG_DEBUG, + LOG_UNIT_ID(unit), + "EXECUTABLE=%s", command->path, + LOG_UNIT_MESSAGE(unit, "Executing: %s", line), + NULL); log_close(); } } @@ -1815,7 +1812,8 @@ static int exec_child( return -errno; } -int exec_spawn(ExecCommand *command, +int exec_spawn(Unit *unit, + ExecCommand *command, const ExecContext *context, const ExecParameters *params, ExecRuntime *runtime, @@ -1828,6 +1826,7 @@ int exec_spawn(ExecCommand *command, char **argv; pid_t pid; + assert(unit); assert(command); assert(context); assert(ret); @@ -1839,7 +1838,7 @@ int exec_spawn(ExecCommand *command, context->std_error == EXEC_OUTPUT_SOCKET) { if (params->n_fds != 1) { - log_unit_error(params->unit_id, "Got more than one socket."); + log_unit_error(unit, "Got more than one socket."); return -EINVAL; } @@ -1850,28 +1849,29 @@ int exec_spawn(ExecCommand *command, n_fds = params->n_fds; } - r = exec_context_load_environment(context, params->unit_id, &files_env); + r = exec_context_load_environment(unit, context, &files_env); if (r < 0) - return log_unit_error_errno(params->unit_id, r, "Failed to load environment files: %m"); + return log_unit_error_errno(unit, r, "Failed to load environment files: %m"); argv = params->argv ?: command->argv; line = exec_command_line(argv); if (!line) return log_oom(); - log_unit_struct(params->unit_id, - LOG_DEBUG, - "EXECUTABLE=%s", command->path, - LOG_MESSAGE("About to execute: %s", line), - NULL); + log_struct(LOG_DEBUG, + LOG_UNIT_ID(unit), + LOG_UNIT_MESSAGE(unit, "About to execute: %s", line), + "EXECUTABLE=%s", command->path, + NULL); pid = fork(); if (pid < 0) - return log_unit_error_errno(params->unit_id, r, "Failed to fork: %m"); + return log_unit_error_errno(unit, r, "Failed to fork: %m"); if (pid == 0) { int exit_status; - r = exec_child(command, + r = exec_child(unit, + command, context, params, runtime, @@ -1882,21 +1882,20 @@ int exec_spawn(ExecCommand *command, &exit_status); if (r < 0) { log_open(); - log_unit_struct(params->unit_id, - LOG_ERR, - LOG_MESSAGE_ID(SD_MESSAGE_SPAWN_FAILED), - "EXECUTABLE=%s", command->path, - LOG_MESSAGE("Failed at step %s spawning %s: %s", - exit_status_to_string(exit_status, EXIT_STATUS_SYSTEMD), - command->path, strerror(-r)), - LOG_ERRNO(r), - NULL); + log_struct_errno(LOG_ERR, r, + LOG_MESSAGE_ID(SD_MESSAGE_SPAWN_FAILED), + LOG_UNIT_ID(unit), + LOG_UNIT_MESSAGE(unit, "Failed at step %s spawning %s: %m", + exit_status_to_string(exit_status, EXIT_STATUS_SYSTEMD), + command->path), + "EXECUTABLE=%s", command->path, + NULL); } _exit(exit_status); } - log_unit_debug(params->unit_id, "Forked %s as "PID_FMT, command->path, pid); + log_unit_debug(unit, "Forked %s as "PID_FMT, command->path, pid); /* We add the new process to the cgroup both in the child (so * that we can be sure that no user code is ever executed @@ -2068,17 +2067,17 @@ void exec_command_free_array(ExecCommand **c, unsigned n) { } typedef struct InvalidEnvInfo { - const char *unit_id; + Unit *unit; const char *path; } InvalidEnvInfo; static void invalid_env(const char *p, void *userdata) { InvalidEnvInfo *info = userdata; - log_unit_error(info->unit_id, "Ignoring invalid environment assignment '%s': %s", p, info->path); + log_unit_error(info->unit, "Ignoring invalid environment assignment '%s': %s", p, info->path); } -int exec_context_load_environment(const ExecContext *c, const char *unit_id, char ***l) { +int exec_context_load_environment(Unit *unit, const ExecContext *c, char ***l) { char **i, **r = NULL; assert(c); @@ -2136,7 +2135,7 @@ int exec_context_load_environment(const ExecContext *c, const char *unit_id, cha /* Log invalid environment variables with filename */ if (p) { InvalidEnvInfo info = { - .unit_id = unit_id, + .unit = unit, .path = pglob.gl_pathv[n] }; @@ -2734,17 +2733,18 @@ ExecRuntime *exec_runtime_unref(ExecRuntime *r) { assert(r->n_ref > 0); r->n_ref--; - if (r->n_ref <= 0) { - free(r->tmp_dir); - free(r->var_tmp_dir); - safe_close_pair(r->netns_storage_socket); - free(r); - } + if (r->n_ref > 0) + return NULL; + + free(r->tmp_dir); + free(r->var_tmp_dir); + safe_close_pair(r->netns_storage_socket); + free(r); return NULL; } -int exec_runtime_serialize(ExecRuntime *rt, Unit *u, FILE *f, FDSet *fds) { +int exec_runtime_serialize(Unit *u, ExecRuntime *rt, FILE *f, FDSet *fds) { assert(u); assert(f); assert(fds); @@ -2781,7 +2781,7 @@ int exec_runtime_serialize(ExecRuntime *rt, Unit *u, FILE *f, FDSet *fds) { return 0; } -int exec_runtime_deserialize_item(ExecRuntime **rt, Unit *u, const char *key, const char *value, FDSet *fds) { +int exec_runtime_deserialize_item(Unit *u, ExecRuntime **rt, const char *key, const char *value, FDSet *fds) { int r; assert(rt); @@ -2793,7 +2793,7 @@ int exec_runtime_deserialize_item(ExecRuntime **rt, Unit *u, const char *key, co r = exec_runtime_allocate(rt); if (r < 0) - return r; + return log_oom(); copy = strdup(value); if (!copy) @@ -2807,7 +2807,7 @@ int exec_runtime_deserialize_item(ExecRuntime **rt, Unit *u, const char *key, co r = exec_runtime_allocate(rt); if (r < 0) - return r; + return log_oom(); copy = strdup(value); if (!copy) @@ -2821,10 +2821,10 @@ int exec_runtime_deserialize_item(ExecRuntime **rt, Unit *u, const char *key, co r = exec_runtime_allocate(rt); if (r < 0) - return r; + return log_oom(); if (safe_atoi(value, &fd) < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse netns socket value %s", value); + log_unit_debug(u, "Failed to parse netns socket value: %s", value); else { safe_close((*rt)->netns_storage_socket[0]); (*rt)->netns_storage_socket[0] = fdset_remove(fds, fd); @@ -2834,10 +2834,10 @@ int exec_runtime_deserialize_item(ExecRuntime **rt, Unit *u, const char *key, co r = exec_runtime_allocate(rt); if (r < 0) - return r; + return log_oom(); if (safe_atoi(value, &fd) < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse netns socket value %s", value); + log_unit_debug(u, "Failed to parse netns socket value: %s", value); else { safe_close((*rt)->netns_storage_socket[1]); (*rt)->netns_storage_socket[1] = fdset_remove(fds, fd); diff --git a/src/core/execute.h b/src/core/execute.h index 1a43ac77b0..a0908e0c3d 100644 --- a/src/core/execute.h +++ b/src/core/execute.h @@ -209,14 +209,14 @@ struct ExecParameters { const char *cgroup_path; bool cgroup_delegate; const char *runtime_prefix; - const char *unit_id; usec_t watchdog_usec; int *idle_pipe; char *bus_endpoint_path; int bus_endpoint_fd; }; -int exec_spawn(ExecCommand *command, +int exec_spawn(Unit *unit, + ExecCommand *command, const ExecContext *context, const ExecParameters *exec_params, ExecRuntime *runtime, @@ -242,7 +242,7 @@ void exec_context_dump(ExecContext *c, FILE* f, const char *prefix); int exec_context_destroy_runtime_directory(ExecContext *c, const char *runtime_root); -int exec_context_load_environment(const ExecContext *c, const char *unit_id, char ***l); +int exec_context_load_environment(Unit *unit, const ExecContext *c, char ***l); bool exec_context_may_touch_console(ExecContext *c); bool exec_context_maintains_privileges(ExecContext *c); @@ -255,8 +255,8 @@ int exec_runtime_make(ExecRuntime **rt, ExecContext *c, const char *id); ExecRuntime *exec_runtime_ref(ExecRuntime *r); ExecRuntime *exec_runtime_unref(ExecRuntime *r); -int exec_runtime_serialize(ExecRuntime *rt, Unit *u, FILE *f, FDSet *fds); -int exec_runtime_deserialize_item(ExecRuntime **rt, Unit *u, const char *key, const char *value, FDSet *fds); +int exec_runtime_serialize(Unit *unit, ExecRuntime *rt, FILE *f, FDSet *fds); +int exec_runtime_deserialize_item(Unit *unit, ExecRuntime **rt, const char *key, const char *value, FDSet *fds); void exec_runtime_destroy(ExecRuntime *rt); diff --git a/src/core/job.c b/src/core/job.c index a26f7de450..49fcac97dc 100644 --- a/src/core/job.c +++ b/src/core/job.c @@ -193,7 +193,7 @@ Job* job_install(Job *j) { if (uj->state == JOB_WAITING || (job_type_allows_late_merge(j->type) && job_type_is_superset(uj->type, j->type))) { job_merge_into_installed(uj, j); - log_unit_debug(uj->unit->id, + log_unit_debug(uj->unit, "Merged into installed job %s/%s as %u", uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id); return uj; @@ -203,7 +203,7 @@ Job* job_install(Job *j) { /* XXX It should be safer to queue j to run after uj finishes, but it is * not currently possible to have more than one installed job per unit. */ job_merge_into_installed(uj, j); - log_unit_debug(uj->unit->id, + log_unit_debug(uj->unit, "Merged into running job, re-running: %s/%s as %u", uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id); @@ -218,7 +218,7 @@ Job* job_install(Job *j) { j->installed = true; j->manager->n_installed_jobs ++; - log_unit_debug(j->unit->id, + log_unit_debug(j->unit, "Installed new job %s/%s as %u", j->unit->id, job_type_to_string(j->type), (unsigned) j->id); return j; @@ -236,7 +236,7 @@ int job_install_deserialized(Job *j) { pj = (j->type == JOB_NOP) ? &j->unit->nop_job : &j->unit->job; if (*pj) { - log_unit_debug(j->unit->id, "Unit %s already has a job installed. Not installing deserialized job.", j->unit->id); + log_unit_debug(j->unit, "Unit already has a job installed. Not installing deserialized job."); return -EEXIST; } @@ -246,7 +246,7 @@ int job_install_deserialized(Job *j) { if (j->state == JOB_RUNNING) j->unit->manager->n_running_jobs++; - log_unit_debug(j->unit->id, + log_unit_debug(j->unit, "Reinstalled deserialized job %s/%s as %u", j->unit->id, job_type_to_string(j->type), (unsigned) j->id); return 0; @@ -485,7 +485,9 @@ static bool job_is_runnable(Job *j) { } static void job_change_type(Job *j, JobType newtype) { - log_unit_debug(j->unit->id, + assert(j); + + log_unit_debug(j->unit, "Converting job %s/%s -> %s/%s", j->unit->id, job_type_to_string(j->type), j->unit->id, job_type_to_string(newtype)); @@ -764,28 +766,28 @@ static void job_log_status_message(Unit *u, JobType t, JobResult result) { sd_id128_t mid; mid = result == JOB_DONE ? SD_MESSAGE_UNIT_STARTED : SD_MESSAGE_UNIT_FAILED; - log_unit_struct(u->id, - result == JOB_DONE ? LOG_INFO : LOG_ERR, - LOG_MESSAGE_ID(mid), - LOG_MESSAGE("%s", buf), - "RESULT=%s", job_result_to_string(result), - NULL); + log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR, + LOG_MESSAGE_ID(mid), + LOG_UNIT_ID(u), + LOG_MESSAGE("%s", buf), + "RESULT=%s", job_result_to_string(result), + NULL); } else if (t == JOB_STOP) - log_unit_struct(u->id, - result == JOB_DONE ? LOG_INFO : LOG_ERR, - LOG_MESSAGE_ID(SD_MESSAGE_UNIT_STOPPED), - LOG_MESSAGE("%s", buf), - "RESULT=%s", job_result_to_string(result), - NULL); + log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR, + LOG_MESSAGE_ID(SD_MESSAGE_UNIT_STOPPED), + LOG_UNIT_ID(u), + LOG_MESSAGE("%s", buf), + "RESULT=%s", job_result_to_string(result), + NULL); else if (t == JOB_RELOAD) - log_unit_struct(u->id, - result == JOB_DONE ? LOG_INFO : LOG_ERR, - LOG_MESSAGE_ID(SD_MESSAGE_UNIT_RELOADED), - LOG_MESSAGE("%s", buf), - "RESULT=%s", job_result_to_string(result), - NULL); + log_struct(result == JOB_DONE ? LOG_INFO : LOG_ERR, + LOG_MESSAGE_ID(SD_MESSAGE_UNIT_RELOADED), + LOG_UNIT_ID(u), + LOG_MESSAGE("%s", buf), + "RESULT=%s", job_result_to_string(result), + NULL); } int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) { @@ -803,8 +805,7 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) { j->result = result; - log_unit_debug(u->id, "Job %s/%s finished, result=%s", - u->id, job_type_to_string(t), job_result_to_string(result)); + log_unit_debug(u, "Job %s/%s finished, result=%s", u->id, job_type_to_string(t), job_result_to_string(result)); job_print_status_message(u, t, result); job_log_status_message(u, t, result); @@ -868,15 +869,15 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) { * this context. And JOB_FAILURE is already handled by the * unit itself. */ if (result == JOB_TIMEOUT || result == JOB_DEPENDENCY) { - log_unit_struct(u->id, - LOG_NOTICE, - "JOB_TYPE=%s", job_type_to_string(t), - "JOB_RESULT=%s", job_result_to_string(result), - LOG_MESSAGE("Job %s/%s failed with result '%s'.", + log_struct(LOG_NOTICE, + "JOB_TYPE=%s", job_type_to_string(t), + "JOB_RESULT=%s", job_result_to_string(result), + LOG_UNIT_ID(u), + LOG_UNIT_MESSAGE(u, "Job %s/%s failed with result '%s'.", u->id, job_type_to_string(t), job_result_to_string(result)), - NULL); + NULL); unit_start_on_failure(u); } @@ -904,7 +905,7 @@ static int job_dispatch_timer(sd_event_source *s, uint64_t monotonic, void *user assert(j); assert(s == j->timer_event_source); - log_unit_warning(j->unit->id, "Job %s/%s timed out.", j->unit->id, job_type_to_string(j->type)); + log_unit_warning(j->unit, "Job %s/%s timed out.", j->unit->id, job_type_to_string(j->type)); u = j->unit; job_finish_and_invalidate(j, JOB_TIMEOUT, true); diff --git a/src/core/main.c b/src/core/main.c index 09436774c9..ac2f1172e8 100644 --- a/src/core/main.c +++ b/src/core/main.c @@ -471,7 +471,7 @@ static int config_parse_cpu_affinity2( if (c) { if (sched_setaffinity(0, CPU_ALLOC_SIZE(ncpus), c) < 0) - log_unit_warning(unit, "Failed to set CPU affinity: %m"); + log_warning("Failed to set CPU affinity: %m"); CPU_FREE(c); } diff --git a/src/core/manager.c b/src/core/manager.c index dba945a1ea..285abe16d3 100644 --- a/src/core/manager.c +++ b/src/core/manager.c @@ -528,7 +528,19 @@ static int manager_default_environment(Manager *m) { return 0; } + int manager_new(SystemdRunningAs running_as, bool test_run, Manager **_m) { + + static const char * const unit_log_fields[_SYSTEMD_RUNNING_AS_MAX] = { + [SYSTEMD_SYSTEM] = "UNIT=", + [SYSTEMD_USER] = "USER_UNIT=", + }; + + static const char * const unit_log_format_strings[_SYSTEMD_RUNNING_AS_MAX] = { + [SYSTEMD_SYSTEM] = "UNIT=%s", + [SYSTEMD_USER] = "USER_UNIT=%s", + }; + Manager *m; int r; @@ -549,6 +561,10 @@ int manager_new(SystemdRunningAs running_as, bool test_run, Manager **_m) { m->exit_code = _MANAGER_EXIT_CODE_INVALID; m->default_timer_accuracy_usec = USEC_PER_MINUTE; + /* Prepare log fields we can use for structured logging */ + m->unit_log_field = unit_log_fields[running_as]; + m->unit_log_format_string = unit_log_format_strings[running_as]; + m->idle_pipe[0] = m->idle_pipe[1] = m->idle_pipe[2] = m->idle_pipe[3] = -1; m->pin_cgroupfs_fd = m->notify_fd = m->signal_fd = m->time_change_fd = m->dev_autofs_fd = m->private_listen_fd = m->kdbus_fd = m->utab_inotify_fd = -1; @@ -861,7 +877,7 @@ static unsigned manager_dispatch_gc_queue(Manager *m) { if (u->gc_marker == gc_marker + GC_OFFSET_BAD || u->gc_marker == gc_marker + GC_OFFSET_UNSURE) { if (u->id) - log_unit_debug(u->id, "Collecting %s", u->id); + log_unit_debug(u, "Collecting."); u->gc_marker = gc_marker + GC_OFFSET_BAD; unit_add_to_cleanup_queue(u); } @@ -1186,9 +1202,7 @@ int manager_add_job(Manager *m, JobType type, Unit *unit, JobMode mode, bool ove if (mode == JOB_ISOLATE && !unit->allow_isolate) return sd_bus_error_setf(e, BUS_ERROR_NO_ISOLATION, "Operation refused, unit may not be isolated."); - log_unit_debug(unit->id, - "Trying to enqueue job %s/%s/%s", unit->id, - job_type_to_string(type), job_mode_to_string(mode)); + log_unit_debug(unit, "Trying to enqueue job %s/%s/%s", unit->id, job_type_to_string(type), job_mode_to_string(mode)); job_type_collapse(&type, unit); @@ -1212,7 +1226,7 @@ int manager_add_job(Manager *m, JobType type, Unit *unit, JobMode mode, bool ove if (r < 0) goto tr_abort; - log_unit_debug(unit->id, + log_unit_debug(unit, "Enqueued job %s/%s as %u", unit->id, job_type_to_string(type), (unsigned) tr->anchor_job->id); @@ -1482,7 +1496,7 @@ static void manager_invoke_notify_message(Manager *m, Unit *u, pid_t pid, char * return; } - log_unit_debug(u->id, "Got notification message for unit %s", u->id); + log_unit_debug(u, "Got notification message for unit."); if (UNIT_VTABLE(u)->notify_message) UNIT_VTABLE(u)->notify_message(u, pid, tags, fds); @@ -1605,7 +1619,7 @@ static void invoke_sigchld_event(Manager *m, Unit *u, siginfo_t *si) { assert(u); assert(si); - log_unit_debug(u->id, "Child "PID_FMT" belongs to %s", si->si_pid, u->id); + log_unit_debug(u, "Child "PID_FMT" belongs to %s", si->si_pid, u->id); unit_unwatch_pid(u, si->si_pid); UNIT_VTABLE(u)->sigchld_event(u, si->si_pid, si->si_code, si->si_status); @@ -1677,11 +1691,11 @@ static int manager_start_target(Manager *m, const char *name, JobMode mode) { _cleanup_bus_error_free_ sd_bus_error error = SD_BUS_ERROR_NULL; int r; - log_unit_debug(name, "Activating special unit %s", name); + log_debug("Activating special unit %s", name); r = manager_add_job_by_name(m, JOB_START, name, mode, true, &error, NULL); if (r < 0) - log_unit_error(name, "Failed to enqueue %s job: %s", name, bus_error_message(&error, r)); + log_error("Failed to enqueue %s job: %s", name, bus_error_message(&error, r)); return r; } diff --git a/src/core/manager.h b/src/core/manager.h index a9834a9def..524cdf97b9 100644 --- a/src/core/manager.h +++ b/src/core/manager.h @@ -292,6 +292,9 @@ struct Manager { /* When the user hits C-A-D more than 7 times per 2s, reboot immediately... */ RateLimit ctrl_alt_del_ratelimit; + + const char *unit_log_field; + const char *unit_log_format_string; }; int manager_new(SystemdRunningAs running_as, bool test_run, Manager **m); diff --git a/src/core/mount.c b/src/core/mount.c index 5a1547728b..155cd2df1d 100644 --- a/src/core/mount.c +++ b/src/core/mount.c @@ -447,25 +447,25 @@ static int mount_verify(Mount *m) { r = unit_name_from_path(m->where, ".mount", &e); if (r < 0) - return log_unit_error_errno(UNIT(m)->id, r, "Failed to generate unit name from mount path: %m"); + return log_unit_error_errno(UNIT(m), r, "Failed to generate unit name from mount path: %m"); if (!unit_has_name(UNIT(m), e)) { - log_unit_error(UNIT(m)->id, "%s's Where= setting doesn't match unit name. Refusing.", UNIT(m)->id); + log_unit_error(UNIT(m), "Where= setting doesn't match unit name. Refusing."); return -EINVAL; } if (mount_point_is_api(m->where) || mount_point_ignore(m->where)) { - log_unit_error(UNIT(m)->id, "Cannot create mount unit for API file system %s. Refusing.", m->where); + log_unit_error(UNIT(m), "Cannot create mount unit for API file system %s. Refusing.", m->where); return -EINVAL; } if (UNIT(m)->fragment_path && !m->parameters_fragment.what) { - log_unit_error(UNIT(m)->id, "%s's What setting is missing. Refusing.", UNIT(m)->id); + log_unit_error(UNIT(m), "What= setting is missing. Refusing."); return -EBADMSG; } if (m->exec_context.pam_name && m->kill_context.kill_mode != KILL_CONTROL_GROUP) { - log_unit_error(UNIT(m)->id, "%s has PAM enabled. Kill mode must be set to control-group'. Refusing.",UNIT(m)->id); + log_unit_error(UNIT(m), "Unit has PAM enabled. Kill mode must be set to control-group'. Refusing."); return -EINVAL; } @@ -596,11 +596,7 @@ static void mount_set_state(Mount *m, MountState state) { mount_notify_automount(m, old_state, state); if (state != old_state) - log_unit_debug(UNIT(m)->id, - "%s changed %s -> %s", - UNIT(m)->id, - mount_state_to_string(old_state), - mount_state_to_string(state)); + log_unit_debug(UNIT(m), "Changed %s -> %s", mount_state_to_string(old_state), mount_state_to_string(state)); unit_notify(UNIT(m), state_translation_table[old_state], state_translation_table[state], m->reload_result == MOUNT_SUCCESS); m->reload_result = MOUNT_SUCCESS; @@ -721,9 +717,9 @@ static int mount_spawn(Mount *m, ExecCommand *c, pid_t *_pid) { exec_params.cgroup_path = UNIT(m)->cgroup_path; exec_params.cgroup_delegate = m->cgroup_context.delegate; exec_params.runtime_prefix = manager_get_runtime_prefix(UNIT(m)->manager); - exec_params.unit_id = UNIT(m)->id; - r = exec_spawn(c, + r = exec_spawn(UNIT(m), + c, &m->exec_context, &exec_params, m->exec_runtime, @@ -808,8 +804,7 @@ static void mount_enter_signal(Mount *m, MountState state, MountResult f) { return; fail: - log_unit_warning(UNIT(m)->id, - "%s failed to kill processes: %s", UNIT(m)->id, strerror(-r)); + log_unit_warning_errno(UNIT(m), r, "Failed to kill processes: %m"); if (state == MOUNT_REMOUNTING_SIGTERM || state == MOUNT_REMOUNTING_SIGKILL) mount_enter_mounted(m, MOUNT_FAILURE_RESOURCES); @@ -817,44 +812,50 @@ fail: mount_enter_dead(m, MOUNT_FAILURE_RESOURCES); } -void warn_if_dir_nonempty(const char *unit, const char* where) { +void unit_warn_if_dir_nonempty(Unit *u, const char* where) { int r; - assert(unit); + assert(u); assert(where); r = dir_is_empty(where); if (r > 0) return; - else if (r == 0) - log_unit_struct(unit, - LOG_NOTICE, - LOG_MESSAGE_ID(SD_MESSAGE_OVERMOUNTING), - LOG_MESSAGE("%s: Directory %s to mount over is not empty, mounting anyway.", - unit, where), - "WHERE=%s", where, - NULL); - else - log_unit_warning(unit, - "MESSAGE=Failed to check directory %s: %s", - where, strerror(-r)); + if (r < 0) { + log_unit_warning_errno(u, r, "Failed to check directory %s: %m", where); + return; + } + + log_struct(LOG_NOTICE, + LOG_MESSAGE_ID(SD_MESSAGE_OVERMOUNTING), + LOG_UNIT_ID(u), + LOG_UNIT_MESSAGE(u, "Directory %s to mount over is not empty, mounting anyway.", where), + "WHERE=%s", where, + NULL); } -static int fail_if_symlink(const char *unit, const char* where) { - assert(where); +int unit_fail_if_symlink(Unit *u, const char* where) { + int r; - if (is_symlink(where) > 0) { - log_unit_struct(unit, - LOG_ERR, - LOG_MESSAGE_ID(SD_MESSAGE_OVERMOUNTING), - LOG_MESSAGE("%s: Mount on symlink %s not allowed.", - unit, where), - "WHERE=%s", where, - NULL); + assert(u); + assert(where); - return -ELOOP; + r = is_symlink(where); + if (r < 0) { + log_unit_debug_errno(u, r, "Failed to check symlink %s, ignoring: %m", where); + return 0; } - return 0; + if (r == 0) + return 0; + + log_struct(LOG_ERR, + LOG_MESSAGE_ID(SD_MESSAGE_OVERMOUNTING), + LOG_UNIT_ID(u), + LOG_UNIT_MESSAGE(u, "Mount on symlink %s not allowed.", where), + "WHERE=%s", where, + NULL); + + return -ELOOP; } static void mount_enter_unmounting(Mount *m) { @@ -889,9 +890,7 @@ static void mount_enter_unmounting(Mount *m) { return; fail: - log_unit_warning(UNIT(m)->id, - "%s failed to run 'umount' task: %s", - UNIT(m)->id, strerror(-r)); + log_unit_warning_errno(UNIT(m), r, "Failed to run 'umount' task: %m"); mount_enter_mounted(m, MOUNT_FAILURE_RESOURCES); } @@ -904,18 +903,18 @@ static void mount_enter_mounting(Mount *m) { m->control_command_id = MOUNT_EXEC_MOUNT; m->control_command = m->exec_command + MOUNT_EXEC_MOUNT; - mkdir_p_label(m->where, m->directory_mode); + r = unit_fail_if_symlink(UNIT(m), m->where); + if (r < 0) + goto fail; + + (void) mkdir_p_label(m->where, m->directory_mode); - warn_if_dir_nonempty(m->meta.id, m->where); + unit_warn_if_dir_nonempty(UNIT(m), m->where); /* Create the source directory for bind-mounts if needed */ p = get_mount_parameters_fragment(m); if (p && mount_is_bind(p)) - mkdir_p_label(p->what, m->directory_mode); - - r = fail_if_symlink(m->meta.id, m->where); - if (r < 0) - goto fail; + (void) mkdir_p_label(p->what, m->directory_mode); if (m->from_fragment) { _cleanup_free_ char *opts = NULL; @@ -952,9 +951,7 @@ static void mount_enter_mounting(Mount *m) { return; fail: - log_unit_warning(UNIT(m)->id, - "%s failed to run 'mount' task: %s", - UNIT(m)->id, strerror(-r)); + log_unit_warning_errno(UNIT(m), r, "Failed to run 'mount' task: %m"); mount_enter_dead(m, MOUNT_FAILURE_RESOURCES); } @@ -1000,9 +997,7 @@ static void mount_enter_remounting(Mount *m) { return; fail: - log_unit_warning(UNIT(m)->id, - "%s failed to run 'remount' task: %s", - UNIT(m)->id, strerror(-r)); + log_unit_warning_errno(UNIT(m), r, "Failed to run 'remount' task: %m"); m->reload_result = MOUNT_FAILURE_RESOURCES; mount_enter_mounted(m, MOUNT_SUCCESS); } @@ -1105,7 +1100,7 @@ static int mount_deserialize_item(Unit *u, const char *key, const char *value, F MountState state; if ((state = mount_state_from_string(value)) < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else m->deserialized_state = state; } else if (streq(key, "result")) { @@ -1113,8 +1108,7 @@ static int mount_deserialize_item(Unit *u, const char *key, const char *value, F f = mount_result_from_string(value); if (f < 0) - log_unit_debug(UNIT(m)->id, - "Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != MOUNT_SUCCESS) m->result = f; @@ -1123,8 +1117,7 @@ static int mount_deserialize_item(Unit *u, const char *key, const char *value, F f = mount_result_from_string(value); if (f < 0) - log_unit_debug(UNIT(m)->id, - "Failed to parse reload result value %s", value); + log_unit_debug(u, "Failed to parse reload result value: %s", value); else if (f != MOUNT_SUCCESS) m->reload_result = f; @@ -1132,23 +1125,21 @@ static int mount_deserialize_item(Unit *u, const char *key, const char *value, F pid_t pid; if (parse_pid(value, &pid) < 0) - log_unit_debug(UNIT(m)->id, - "Failed to parse control-pid value %s", value); + log_unit_debug(u, "Failed to parse control-pid value: %s", value); else m->control_pid = pid; } else if (streq(key, "control-command")) { MountExecCommand id; - if ((id = mount_exec_command_from_string(value)) < 0) - log_unit_debug(UNIT(m)->id, - "Failed to parse exec-command value %s", value); + id = mount_exec_command_from_string(value); + if (id < 0) + log_unit_debug(u, "Failed to parse exec-command value: %s", value); else { m->control_command_id = id; m->control_command = m->exec_command + id; } } else - log_unit_debug(UNIT(m)->id, - "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -1206,10 +1197,8 @@ static void mount_sigchld_event(Unit *u, pid_t pid, int code, int status) { m->control_command_id = _MOUNT_EXEC_COMMAND_INVALID; } - log_unit_full(u->id, - f == MOUNT_SUCCESS ? LOG_DEBUG : LOG_NOTICE, - "%s mount process exited, code=%s status=%i", - u->id, sigchld_code_to_string(code), status); + log_unit_full(u, f == MOUNT_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, + "Mount process exited, code=%s status=%i", sigchld_code_to_string(code), status); /* Note that mount(8) returning and the kernel sending us a * mount table change event might happen out-of-order. If an @@ -1263,11 +1252,11 @@ static void mount_sigchld_event(Unit *u, pid_t pid, int code, int status) { * the mount command. */ if (m->n_retry_umount < RETRY_UMOUNT_MAX) { - log_unit_debug(u->id, "%s: mount still present, trying again.", u->id); + log_unit_debug(u, "Mount still present, trying again."); m->n_retry_umount++; mount_enter_unmounting(m); } else { - log_unit_debug(u->id, "%s: mount still present after %u attempts to unmount, giving up.", u->id, m->n_retry_umount); + log_unit_debug(u, "Mount still present after %u attempts to unmount, giving up.", m->n_retry_umount); mount_enter_mounted(m, f); } } else @@ -1297,33 +1286,27 @@ static int mount_dispatch_timer(sd_event_source *source, usec_t usec, void *user case MOUNT_MOUNTING: case MOUNT_MOUNTING_DONE: - log_unit_warning(UNIT(m)->id, - "%s mounting timed out. Stopping.", UNIT(m)->id); + log_unit_warning(UNIT(m), "Mounting timed out. Stopping."); mount_enter_signal(m, MOUNT_MOUNTING_SIGTERM, MOUNT_FAILURE_TIMEOUT); break; case MOUNT_REMOUNTING: - log_unit_warning(UNIT(m)->id, - "%s remounting timed out. Stopping.", UNIT(m)->id); + log_unit_warning(UNIT(m), "Remounting timed out. Stopping."); m->reload_result = MOUNT_FAILURE_TIMEOUT; mount_enter_mounted(m, MOUNT_SUCCESS); break; case MOUNT_UNMOUNTING: - log_unit_warning(UNIT(m)->id, - "%s unmounting timed out. Stopping.", UNIT(m)->id); + log_unit_warning(UNIT(m), "Unmounting timed out. Stopping."); mount_enter_signal(m, MOUNT_UNMOUNTING_SIGTERM, MOUNT_FAILURE_TIMEOUT); break; case MOUNT_MOUNTING_SIGTERM: if (m->kill_context.send_sigkill) { - log_unit_warning(UNIT(m)->id, - "%s mounting timed out. Killing.", UNIT(m)->id); + log_unit_warning(UNIT(m), "Mounting timed out. Killing."); mount_enter_signal(m, MOUNT_MOUNTING_SIGKILL, MOUNT_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(m)->id, - "%s mounting timed out. Skipping SIGKILL. Ignoring.", - UNIT(m)->id); + log_unit_warning(UNIT(m), "Mounting timed out. Skipping SIGKILL. Ignoring."); if (m->from_proc_self_mountinfo) mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT); @@ -1334,13 +1317,10 @@ static int mount_dispatch_timer(sd_event_source *source, usec_t usec, void *user case MOUNT_REMOUNTING_SIGTERM: if (m->kill_context.send_sigkill) { - log_unit_warning(UNIT(m)->id, - "%s remounting timed out. Killing.", UNIT(m)->id); + log_unit_warning(UNIT(m), "Remounting timed out. Killing."); mount_enter_signal(m, MOUNT_REMOUNTING_SIGKILL, MOUNT_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(m)->id, - "%s remounting timed out. Skipping SIGKILL. Ignoring.", - UNIT(m)->id); + log_unit_warning(UNIT(m), "Remounting timed out. Skipping SIGKILL. Ignoring."); if (m->from_proc_self_mountinfo) mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT); @@ -1351,13 +1331,10 @@ static int mount_dispatch_timer(sd_event_source *source, usec_t usec, void *user case MOUNT_UNMOUNTING_SIGTERM: if (m->kill_context.send_sigkill) { - log_unit_warning(UNIT(m)->id, - "%s unmounting timed out. Killing.", UNIT(m)->id); + log_unit_warning(UNIT(m), "Unmounting timed out. Killing."); mount_enter_signal(m, MOUNT_UNMOUNTING_SIGKILL, MOUNT_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(m)->id, - "%s unmounting timed out. Skipping SIGKILL. Ignoring.", - UNIT(m)->id); + log_unit_warning(UNIT(m), "Unmounting timed out. Skipping SIGKILL. Ignoring."); if (m->from_proc_self_mountinfo) mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT); @@ -1369,9 +1346,7 @@ static int mount_dispatch_timer(sd_event_source *source, usec_t usec, void *user case MOUNT_MOUNTING_SIGKILL: case MOUNT_REMOUNTING_SIGKILL: case MOUNT_UNMOUNTING_SIGKILL: - log_unit_warning(UNIT(m)->id, - "%s mount process still around after SIGKILL. Ignoring.", - UNIT(m)->id); + log_unit_warning(UNIT(m),"Mount process still around after SIGKILL. Ignoring."); if (m->from_proc_self_mountinfo) mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT); diff --git a/src/core/mount.h b/src/core/mount.h index 072b0e0447..79cdc8dbfc 100644 --- a/src/core/mount.h +++ b/src/core/mount.h @@ -129,4 +129,5 @@ MountExecCommand mount_exec_command_from_string(const char *s) _pure_; const char* mount_result_to_string(MountResult i) _const_; MountResult mount_result_from_string(const char *s) _pure_; -void warn_if_dir_nonempty(const char *unit, const char* where); +void unit_warn_if_dir_nonempty(Unit *u, const char* where); +int unit_fail_if_symlink(Unit *u, const char* where); diff --git a/src/core/path.c b/src/core/path.c index b6322bdbcd..fc27e33511 100644 --- a/src/core/path.c +++ b/src/core/path.c @@ -99,9 +99,7 @@ int path_spec_watch(PathSpec *s, sd_event_io_handler_t handler) { break; } - log_warning("Failed to add watch on %s: %s", s->path, - errno == ENOSPC ? "too many watches" : strerror(-r)); - r = -errno; + r = log_warning_errno(errno, "Failed to add watch on %s: %s", s->path, errno == ENOSPC ? "too many watches" : strerror(-r)); if (cut) *cut = tmp; goto fail; @@ -136,9 +134,8 @@ int path_spec_watch(PathSpec *s, sd_event_io_handler_t handler) { } if (!exists) { - log_error_errno(errno, "Failed to add watch on any of the components of %s: %m", - s->path); - r = -errno; /* either EACCESS or ENOENT */ + r = log_error_errno(errno, "Failed to add watch on any of the components of %s: %m", s->path); + /* either EACCESS or ENOENT */ goto fail; } @@ -300,8 +297,7 @@ static int path_verify(Path *p) { return 0; if (!p->specs) { - log_unit_error(UNIT(p)->id, - "%s lacks path setting. Refusing.", UNIT(p)->id); + log_unit_error(UNIT(p), "Path unit lacks path setting. Refusing."); return -EINVAL; } @@ -430,10 +426,7 @@ static void path_set_state(Path *p, PathState state) { path_unwatch(p); if (state != old_state) - log_debug("%s changed %s -> %s", - UNIT(p)->id, - path_state_to_string(old_state), - path_state_to_string(state)); + log_debug("Changed %s -> %s", path_state_to_string(old_state), path_state_to_string(state)); unit_notify(UNIT(p), state_translation_table[old_state], state_translation_table[state], true); } @@ -492,8 +485,7 @@ static void path_enter_running(Path *p) { return; fail: - log_warning("%s failed to queue unit startup job: %s", - UNIT(p)->id, bus_error_message(&error, r)); + log_unit_warning(UNIT(p), "Failed to queue unit startup job: %s", bus_error_message(&error, r)); path_enter_dead(p, PATH_FAILURE_RESOURCES); } @@ -518,7 +510,7 @@ static void path_enter_waiting(Path *p, bool initial, bool recheck) { if (recheck) if (path_check_good(p, initial)) { - log_debug("%s got triggered.", UNIT(p)->id); + log_unit_debug(UNIT(p), "Got triggered."); path_enter_running(p); return; } @@ -533,7 +525,7 @@ static void path_enter_waiting(Path *p, bool initial, bool recheck) { if (recheck) if (path_check_good(p, false)) { - log_debug("%s got triggered.", UNIT(p)->id); + log_unit_debug(UNIT(p), "Got triggered."); path_enter_running(p); return; } @@ -542,7 +534,7 @@ static void path_enter_waiting(Path *p, bool initial, bool recheck) { return; fail: - log_warning_errno(r, "%s failed to enter waiting state: %m", UNIT(p)->id); + log_unit_warning_errno(UNIT(p), r, "Failed to enter waiting state: %m"); path_enter_dead(p, PATH_FAILURE_RESOURCES); } @@ -611,7 +603,7 @@ static int path_deserialize_item(Unit *u, const char *key, const char *value, FD state = path_state_from_string(value); if (state < 0) - log_debug("Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else p->deserialized_state = state; @@ -620,12 +612,12 @@ static int path_deserialize_item(Unit *u, const char *key, const char *value, FD f = path_result_from_string(value); if (f < 0) - log_debug("Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != PATH_SUCCESS) p->result = f; } else - log_debug("Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -703,9 +695,7 @@ static void path_trigger_notify(Unit *u, Unit *other) { if (p->state == PATH_RUNNING && UNIT_IS_INACTIVE_OR_FAILED(unit_active_state(other))) { - log_unit_debug(UNIT(p)->id, - "%s got notified about unit deactivation.", - UNIT(p)->id); + log_unit_debug(UNIT(p), "Got notified about unit deactivation."); /* Hmm, so inotify was triggered since the * last activation, so I guess we need to diff --git a/src/core/scope.c b/src/core/scope.c index b99eca90e0..9ab54eeb1a 100644 --- a/src/core/scope.c +++ b/src/core/scope.c @@ -137,7 +137,7 @@ static int scope_verify(Scope *s) { return 0; if (set_isempty(UNIT(s)->pids) && UNIT(s)->manager->n_reloading <= 0) { - log_unit_error(UNIT(s)->id, "Scope %s has no PIDs. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Scope has no PIDs. Refusing."); return -EINVAL; } @@ -268,8 +268,7 @@ static void scope_enter_signal(Scope *s, ScopeState state, ScopeResult f) { return; fail: - log_unit_warning(UNIT(s)->id, - "%s failed to kill processes: %s", UNIT(s)->id, strerror(-r)); + log_unit_warning_errno(UNIT(s), r, "Failed to kill processes: %m"); scope_enter_dead(s, SCOPE_FAILURE_RESOURCES); } @@ -298,7 +297,7 @@ static int scope_start(Unit *u) { r = unit_attach_pids_to_cgroup(u); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s: Failed to add PIDs to scope's control group: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to add PIDs to scope's control group: %m"); scope_enter_dead(s, SCOPE_FAILURE_RESOURCES); return r; } @@ -378,12 +377,12 @@ static int scope_deserialize_item(Unit *u, const char *key, const char *value, F state = scope_state_from_string(value); if (state < 0) - log_debug("Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else s->deserialized_state = state; } else - log_debug("Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -409,7 +408,7 @@ static void scope_notify_cgroup_empty_event(Unit *u) { Scope *s = SCOPE(u); assert(u); - log_unit_debug(u->id, "%s: cgroup is empty", u->id); + log_unit_debug(u, "cgroup is empty"); if (IN_SET(s->state, SCOPE_RUNNING, SCOPE_ABANDONED, SCOPE_STOP_SIGTERM, SCOPE_STOP_SIGKILL)) scope_enter_dead(s, SCOPE_SUCCESS); @@ -441,17 +440,17 @@ static int scope_dispatch_timer(sd_event_source *source, usec_t usec, void *user case SCOPE_STOP_SIGTERM: if (s->kill_context.send_sigkill) { - log_unit_warning(UNIT(s)->id, "%s stopping timed out. Killing.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out. Killing."); scope_enter_signal(s, SCOPE_STOP_SIGKILL, SCOPE_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(s)->id, "%s stopping timed out. Skipping SIGKILL.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out. Skipping SIGKILL."); scope_enter_dead(s, SCOPE_FAILURE_TIMEOUT); } break; case SCOPE_STOP_SIGKILL: - log_unit_warning(UNIT(s)->id, "%s still around after SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Still around after SIGKILL. Ignoring."); scope_enter_dead(s, SCOPE_FAILURE_TIMEOUT); break; diff --git a/src/core/service.c b/src/core/service.c index 1c55e53c3c..d11bcb1028 100644 --- a/src/core/service.c +++ b/src/core/service.c @@ -138,7 +138,7 @@ static void service_unwatch_pid_file(Service *s) { if (!s->pid_file_pathspec) return; - log_unit_debug(UNIT(s)->id, "Stopping watch for %s's PID file %s", UNIT(s)->id, s->pid_file_pathspec->path); + log_unit_debug(UNIT(s), "Stopping watch for PID file %s", s->pid_file_pathspec->path); path_spec_unwatch(s->pid_file_pathspec); path_spec_done(s->pid_file_pathspec); free(s->pid_file_pathspec); @@ -168,7 +168,7 @@ static int service_set_main_pid(Service *s, pid_t pid) { s->main_pid_known = true; if (get_parent_of_pid(pid, &ppid) >= 0 && ppid != getpid()) { - log_unit_warning(UNIT(s)->id, "%s: Supervising process "PID_FMT" which is not our child. We'll most likely not notice when it exits.", UNIT(s)->id, pid); + log_unit_warning(UNIT(s), "Supervising process "PID_FMT" which is not our child. We'll most likely not notice when it exits.", pid); s->main_pid_alien = true; } else s->main_pid_alien = false; @@ -210,7 +210,7 @@ static void service_start_watchdog(Service *s) { if (s->watchdog_event_source) { r = sd_event_source_set_time(s->watchdog_event_source, s->watchdog_timestamp.monotonic + s->watchdog_usec); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to reset watchdog timer: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to reset watchdog timer: %m"); return; } @@ -223,7 +223,7 @@ static void service_start_watchdog(Service *s) { s->watchdog_timestamp.monotonic + s->watchdog_usec, 0, service_dispatch_watchdog, s); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to add watchdog timer: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to add watchdog timer: %m"); return; } @@ -235,7 +235,7 @@ static void service_start_watchdog(Service *s) { } if (r < 0) - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to install watchdog timer: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to install watchdog timer: %m"); } static void service_reset_watchdog(Service *s) { @@ -273,7 +273,7 @@ static void service_release_resources(Unit *u) { if (!s->fd_store) return; - log_debug("Releasing all resources for %s", u->id); + log_unit_debug(u, "Releasing all resources."); while (s->fd_store) service_fd_store_unlink(s->fd_store); @@ -399,16 +399,16 @@ static int service_add_fd_store_set(Service *s, FDSet *fds) { r = service_add_fd_store(s, fd); if (r < 0) - return log_unit_error_errno(UNIT(s)->id, r, "%s: Couldn't add fd to fd store: %m", UNIT(s)->id); + return log_unit_error_errno(UNIT(s), r, "Couldn't add fd to fd store: %m"); if (r > 0) { - log_unit_debug(UNIT(s)->id, "%s: added fd to fd store.", UNIT(s)->id); + log_unit_debug(UNIT(s), "Added fd to fd store."); fd = -1; } } if (fdset_size(fds) > 0) - log_unit_warning(UNIT(s)->id, "%s: tried to store more fds than FDStoreMax=%u allows, closing remaining.", UNIT(s)->id, s->n_fd_store_max); + log_unit_warning(UNIT(s), "Tried to store more fds than FDStoreMax=%u allows, closing remaining.", s->n_fd_store_max); return 0; } @@ -447,45 +447,45 @@ static int service_verify(Service *s) { return 0; if (!s->exec_command[SERVICE_EXEC_START] && !s->exec_command[SERVICE_EXEC_STOP]) { - log_unit_error(UNIT(s)->id, "%s lacks both ExecStart= and ExecStop= setting. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service lacks both ExecStart= and ExecStop= setting. Refusing."); return -EINVAL; } if (s->type != SERVICE_ONESHOT && !s->exec_command[SERVICE_EXEC_START]) { - log_unit_error(UNIT(s)->id, "%s has no ExecStart= setting, which is only allowed for Type=oneshot services. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service has no ExecStart= setting, which is only allowed for Type=oneshot services. Refusing."); return -EINVAL; } if (!s->remain_after_exit && !s->exec_command[SERVICE_EXEC_START]) { - log_unit_error(UNIT(s)->id, "%s has no ExecStart= setting, which is only allowed for RemainAfterExit=yes services. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service has no ExecStart= setting, which is only allowed for RemainAfterExit=yes services. Refusing."); return -EINVAL; } if (s->type != SERVICE_ONESHOT && s->exec_command[SERVICE_EXEC_START]->command_next) { - log_unit_error(UNIT(s)->id, "%s has more than one ExecStart= setting, which is only allowed for Type=oneshot services. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service has more than one ExecStart= setting, which is only allowed for Type=oneshot services. Refusing."); return -EINVAL; } if (s->type == SERVICE_ONESHOT && s->restart != SERVICE_RESTART_NO) { - log_unit_error(UNIT(s)->id, "%s has Restart= setting other than no, which isn't allowed for Type=oneshot services. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service has Restart= setting other than no, which isn't allowed for Type=oneshot services. Refusing."); return -EINVAL; } if (s->type == SERVICE_ONESHOT && !exit_status_set_is_empty(&s->restart_force_status)) { - log_unit_error(UNIT(s)->id, "%s has RestartForceStatus= set, which isn't allowed for Type=oneshot services. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service has RestartForceStatus= set, which isn't allowed for Type=oneshot services. Refusing."); return -EINVAL; } if (s->type == SERVICE_DBUS && !s->bus_name) { - log_unit_error(UNIT(s)->id, "%s is of type D-Bus but no D-Bus service name has been specified. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service is of type D-Bus but no D-Bus service name has been specified. Refusing."); return -EINVAL; } if (s->bus_name && s->type != SERVICE_DBUS) - log_unit_warning(UNIT(s)->id, "%s has a D-Bus service name specified, but is not of type dbus. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Service has a D-Bus service name specified, but is not of type dbus. Ignoring."); if (s->exec_context.pam_name && !(s->kill_context.kill_mode == KILL_CONTROL_GROUP || s->kill_context.kill_mode == KILL_MIXED)) { - log_unit_error(UNIT(s)->id, "%s has PAM enabled. Kill mode must be set to 'control-group' or 'mixed'. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service has PAM enabled. Kill mode must be set to 'control-group' or 'mixed'. Refusing."); return -EINVAL; } @@ -724,20 +724,20 @@ static int service_load_pid_file(Service *s, bool may_warn) { r = read_one_line_file(s->pid_file, &k); if (r < 0) { if (may_warn) - log_unit_info(UNIT(s)->id, "PID file %s not readable (yet?) after %s.", s->pid_file, service_state_to_string(s->state)); + log_unit_info_errno(UNIT(s), r, "PID file %s not readable (yet?) after %s: %m", s->pid_file, service_state_to_string(s->state)); return r; } r = parse_pid(k, &pid); if (r < 0) { if (may_warn) - log_unit_info_errno(UNIT(s)->id, r, "Failed to read PID from file %s: %m", s->pid_file); + log_unit_info_errno(UNIT(s), r, "Failed to read PID from file %s: %m", s->pid_file); return r; } if (!pid_is_alive(pid)) { if (may_warn) - log_unit_info(UNIT(s)->id, "PID "PID_FMT" read from file %s does not exist or is a zombie.", pid, s->pid_file); + log_unit_info(UNIT(s), "PID "PID_FMT" read from file %s does not exist or is a zombie.", pid, s->pid_file); return -ESRCH; } @@ -745,12 +745,12 @@ static int service_load_pid_file(Service *s, bool may_warn) { if (pid == s->main_pid) return 0; - log_unit_debug(UNIT(s)->id, "Main PID changing: "PID_FMT" -> "PID_FMT, s->main_pid, pid); + log_unit_debug(UNIT(s), "Main PID changing: "PID_FMT" -> "PID_FMT, s->main_pid, pid); service_unwatch_main_pid(s); s->main_pid_known = false; } else - log_unit_debug(UNIT(s)->id, "Main PID loaded: "PID_FMT, pid); + log_unit_debug(UNIT(s), "Main PID loaded: "PID_FMT, pid); r = service_set_main_pid(s, pid); if (r < 0) @@ -759,7 +759,7 @@ static int service_load_pid_file(Service *s, bool may_warn) { r = unit_watch_pid(UNIT(s), pid); if (r < 0) { /* FIXME: we need to do something here */ - log_unit_warning(UNIT(s)->id, "Failed to watch PID "PID_FMT" from service %s", pid, UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to watch PID "PID_FMT" for service: %m", pid); return r; } @@ -786,7 +786,7 @@ static int service_search_main_pid(Service *s) { if (pid <= 0) return -ENOENT; - log_unit_debug(UNIT(s)->id, "Main PID guessed: "PID_FMT, pid); + log_unit_debug(UNIT(s), "Main PID guessed: "PID_FMT, pid); r = service_set_main_pid(s, pid); if (r < 0) return r; @@ -794,7 +794,7 @@ static int service_search_main_pid(Service *s) { r = unit_watch_pid(UNIT(s), pid); if (r < 0) { /* FIXME: we need to do something here */ - log_unit_warning(UNIT(s)->id, "Failed to watch PID "PID_FMT" from service %s", pid, UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to watch PID "PID_FMT" from: %m", pid); return r; } @@ -883,7 +883,7 @@ static void service_set_state(Service *s, ServiceState state) { } if (old_state != state) - log_unit_debug(UNIT(s)->id, "%s changed %s -> %s", UNIT(s)->id, service_state_to_string(old_state), service_state_to_string(state)); + log_unit_debug(UNIT(s), "Changed %s -> %s", service_state_to_string(old_state), service_state_to_string(state)); unit_notify(UNIT(s), table[old_state], table[state], s->reload_result == SERVICE_SUCCESS); s->reload_result = SERVICE_SUCCESS; @@ -1202,13 +1202,13 @@ static int service_spawn( exec_params.cgroup_path = path; exec_params.cgroup_delegate = s->cgroup_context.delegate; exec_params.runtime_prefix = manager_get_runtime_prefix(UNIT(s)->manager); - exec_params.unit_id = UNIT(s)->id; exec_params.watchdog_usec = s->watchdog_usec; exec_params.bus_endpoint_path = bus_endpoint_path; if (s->type == SERVICE_IDLE) exec_params.idle_pipe = UNIT(s)->manager->idle_pipe; - r = exec_spawn(c, + r = exec_spawn(UNIT(s), + c, &s->exec_context, &exec_params, s->exec_runtime, @@ -1331,7 +1331,7 @@ static void service_enter_dead(Service *s, ServiceResult f, bool allow_restart) service_set_state(s, s->result != SERVICE_SUCCESS ? SERVICE_FAILED : SERVICE_DEAD); if (s->result != SERVICE_SUCCESS) { - log_unit_warning(UNIT(s)->id, "%s failed.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Failed with result '%s'.", service_result_to_string(s->result)); failure_action(UNIT(s)->manager, s->failure_action, s->reboot_arg); } @@ -1344,6 +1344,7 @@ static void service_enter_dead(Service *s, ServiceResult f, bool allow_restart) service_set_state(s, SERVICE_AUTO_RESTART); } + /* The next restart might not be a manual stop, hence reset the flag indicating manual stops */ s->forbid_restart = false; /* We want fresh tmpdirs in case service is started again immediately */ @@ -1362,7 +1363,7 @@ static void service_enter_dead(Service *s, ServiceResult f, bool allow_restart) return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run install restart timer: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run install restart timer: %m"); service_enter_dead(s, SERVICE_FAILURE_RESOURCES, false); } @@ -1399,7 +1400,7 @@ static void service_enter_stop_post(Service *s, ServiceResult f) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'stop-post' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'stop-post' task: %m"); service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_RESOURCES); } @@ -1463,7 +1464,7 @@ static void service_enter_signal(Service *s, ServiceState state, ServiceResult f return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to kill processes: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to kill processes: %m"); if (IN_SET(state, SERVICE_STOP_SIGABRT, SERVICE_STOP_SIGTERM, SERVICE_STOP_SIGKILL)) service_enter_stop_post(s, SERVICE_FAILURE_RESOURCES); @@ -1517,7 +1518,7 @@ static void service_enter_stop(Service *s, ServiceResult f) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'stop' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'stop' task: %m"); service_enter_signal(s, SERVICE_STOP_SIGTERM, SERVICE_FAILURE_RESOURCES); } @@ -1579,7 +1580,7 @@ static void service_enter_start_post(Service *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'start-post' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'start-post' task: %m"); service_enter_stop(s, SERVICE_FAILURE_RESOURCES); } @@ -1672,7 +1673,7 @@ static void service_enter_start(Service *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'start' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'start' task: %m"); service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_RESOURCES); } @@ -1710,7 +1711,7 @@ static void service_enter_start_pre(Service *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'start-pre' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'start-pre' task: %m"); service_enter_dead(s, SERVICE_FAILURE_RESOURCES, true); } @@ -1722,7 +1723,7 @@ static void service_enter_restart(Service *s) { if (UNIT(s)->job && UNIT(s)->job->type == JOB_STOP) { /* Don't restart things if we are going down anyway */ - log_unit_info(UNIT(s)->id, "Stop job pending for unit, delaying automatic restart."); + log_unit_info(UNIT(s), "Stop job pending for unit, delaying automatic restart."); r = service_arm_timer(s, s->restart_usec); if (r < 0) @@ -1743,11 +1744,11 @@ static void service_enter_restart(Service *s) { * it will be canceled as part of the service_stop() call that * is executed as part of JOB_RESTART. */ - log_unit_debug(UNIT(s)->id, "%s scheduled restart job.", UNIT(s)->id); + log_unit_debug(UNIT(s), "Scheduled restart job."); return; fail: - log_unit_warning(UNIT(s)->id, "%s failed to schedule restart job: %s", UNIT(s)->id, bus_error_message(&error, -r)); + log_unit_warning(UNIT(s), "Failed to schedule restart job: %s", bus_error_message(&error, -r)); service_enter_dead(s, SERVICE_FAILURE_RESOURCES, false); } @@ -1790,7 +1791,7 @@ static void service_enter_reload(Service *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'reload' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'reload' task: %m"); s->reload_result = SERVICE_FAILURE_RESOURCES; service_enter_running(s, SERVICE_SUCCESS); } @@ -1823,7 +1824,7 @@ static void service_run_next_control(Service *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run next control task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run next control task: %m"); if (s->state == SERVICE_START_PRE) service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_RESOURCES); @@ -1867,7 +1868,7 @@ static void service_run_next_main(Service *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run next main task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run next main task: %m"); service_enter_stop(s, SERVICE_FAILURE_RESOURCES); } @@ -1877,7 +1878,7 @@ static int service_start_limit_test(Service *s) { if (ratelimit_test(&s->start_limit)) return 0; - log_unit_warning(UNIT(s)->id, "start request repeated too quickly for %s", UNIT(s)->id); + log_unit_warning(UNIT(s), "Start request repeated too quickly."); return failure_action(UNIT(s)->manager, s->start_limit_action, s->reboot_arg); } @@ -2007,8 +2008,12 @@ static int service_serialize(Unit *u, FILE *f, FDSet *fds) { unit_serialize_item(u, f, "main-pid-known", yes_no(s->main_pid_known)); - if (s->status_text) - unit_serialize_item(u, f, "status-text", s->status_text); + if (s->status_text) { + _cleanup_free_ char *c = NULL; + + c = cescape(s->status_text); + unit_serialize_item(u, f, "status-text", strempty(c)); + } /* FIXME: There's a minor uncleanliness here: if there are * multiple commands attached here, we will start from the @@ -2080,7 +2085,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, state = service_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else s->deserialized_state = state; } else if (streq(key, "result")) { @@ -2088,7 +2093,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, f = service_result_from_string(value); if (f < 0) - log_unit_debug(u->id, "Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != SERVICE_SUCCESS) s->result = f; @@ -2097,7 +2102,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, f = service_result_from_string(value); if (f < 0) - log_unit_debug(u->id, "Failed to parse reload result value %s", value); + log_unit_debug(u, "Failed to parse reload result value: %s", value); else if (f != SERVICE_SUCCESS) s->reload_result = f; @@ -2105,14 +2110,14 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, pid_t pid; if (parse_pid(value, &pid) < 0) - log_unit_debug(u->id, "Failed to parse control-pid value %s", value); + log_unit_debug(u, "Failed to parse control-pid value: %s", value); else s->control_pid = pid; } else if (streq(key, "main-pid")) { pid_t pid; if (parse_pid(value, &pid) < 0) - log_unit_debug(u->id, "Failed to parse main-pid value %s", value); + log_unit_debug(u, "Failed to parse main-pid value: %s", value); else { service_set_main_pid(s, pid); unit_watch_pid(UNIT(s), pid); @@ -2122,15 +2127,15 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, b = parse_boolean(value); if (b < 0) - log_unit_debug(u->id, "Failed to parse main-pid-known value %s", value); + log_unit_debug(u, "Failed to parse main-pid-known value: %s", value); else s->main_pid_known = b; } else if (streq(key, "status-text")) { char *t; - t = strdup(value); - if (!t) - log_oom(); + r = cunescape(value, 0, &t); + if (r < 0) + log_unit_debug_errno(u, r, "Failed to unescape status text: %s", value); else { free(s->status_text); s->status_text = t; @@ -2141,7 +2146,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, id = service_exec_command_from_string(value); if (id < 0) - log_unit_debug(u->id, "Failed to parse exec-command value %s", value); + log_unit_debug(u, "Failed to parse exec-command value: %s", value); else { s->control_command_id = id; s->control_command = s->exec_command[id]; @@ -2150,7 +2155,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, int fd; if (safe_atoi(value, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse socket-fd value %s", value); + log_unit_debug(u, "Failed to parse socket-fd value: %s", value); else { asynchronous_close(s->socket_fd); s->socket_fd = fdset_remove(fds, fd); @@ -2159,7 +2164,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, int fd; if (safe_atoi(value, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse endpoint-fd value %s", value); + log_unit_debug(u, "Failed to parse endpoint-fd value: %s", value); else { safe_close(s->bus_endpoint_fd); s->bus_endpoint_fd = fdset_remove(fds, fd); @@ -2168,11 +2173,11 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, int fd; if (safe_atoi(value, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse fd-store-fd value %s", value); + log_unit_debug(u, "Failed to parse fd-store-fd value: %s", value); else { r = service_add_fd_store(s, fd); if (r < 0) - log_unit_error_errno(u->id, r, "Failed to add fd to store: %m"); + log_unit_error_errno(u, r, "Failed to add fd to store: %m"); else if (r > 0) fdset_remove(fds, fd); } @@ -2181,21 +2186,21 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, pid_t pid; if (parse_pid(value, &pid) < 0) - log_unit_debug(u->id, "Failed to parse main-exec-status-pid value %s", value); + log_unit_debug(u, "Failed to parse main-exec-status-pid value: %s", value); else s->main_exec_status.pid = pid; } else if (streq(key, "main-exec-status-code")) { int i; if (safe_atoi(value, &i) < 0) - log_unit_debug(u->id, "Failed to parse main-exec-status-code value %s", value); + log_unit_debug(u, "Failed to parse main-exec-status-code value: %s", value); else s->main_exec_status.code = i; } else if (streq(key, "main-exec-status-status")) { int i; if (safe_atoi(value, &i) < 0) - log_unit_debug(u->id, "Failed to parse main-exec-status-status value %s", value); + log_unit_debug(u, "Failed to parse main-exec-status-status value: %s", value); else s->main_exec_status.status = i; } else if (streq(key, "main-exec-status-start")) @@ -2209,11 +2214,11 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value, b = parse_boolean(value); if (b < 0) - log_unit_debug(u->id, "Failed to parse forbid-restart value %s", value); + log_unit_debug(u, "Failed to parse forbid-restart value: %s", value); else s->forbid_restart = b; } else - log_unit_debug(u->id, "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -2276,19 +2281,19 @@ static int service_retry_pid_file(Service *s) { static int service_watch_pid_file(Service *s) { int r; - log_unit_debug(UNIT(s)->id, "Setting watch for %s's PID file %s", UNIT(s)->id, s->pid_file_pathspec->path); + log_unit_debug(UNIT(s), "Setting watch for PID file %s", s->pid_file_pathspec->path); r = path_spec_watch(s->pid_file_pathspec, service_dispatch_io); if (r < 0) goto fail; /* the pidfile might have appeared just before we set the watch */ - log_unit_debug(UNIT(s)->id, "Trying to read %s's PID file %s in case it changed", UNIT(s)->id, s->pid_file_pathspec->path); + log_unit_debug(UNIT(s), "Trying to read PID file %s in case it changed", s->pid_file_pathspec->path); service_retry_pid_file(s); return 0; fail: - log_unit_error_errno(UNIT(s)->id, r, "Failed to set a watch for %s's PID file %s: %m", UNIT(s)->id, s->pid_file_pathspec->path); + log_unit_error_errno(UNIT(s), r, "Failed to set a watch for PID file %s: %m", s->pid_file_pathspec->path); service_unwatch_pid_file(s); return r; } @@ -2336,7 +2341,7 @@ static int service_dispatch_io(sd_event_source *source, int fd, uint32_t events, assert(s->pid_file_pathspec); assert(path_spec_owns_inotify_fd(s->pid_file_pathspec, fd)); - log_unit_debug(UNIT(s)->id, "inotify event for %s", UNIT(s)->id); + log_unit_debug(UNIT(s), "inotify event"); if (path_spec_fd_event(p, events) < 0) goto fail; @@ -2360,7 +2365,7 @@ static void service_notify_cgroup_empty_event(Unit *u) { assert(u); - log_unit_debug(u->id, "%s: cgroup is empty", u->id); + log_unit_debug(u, "cgroup is empty"); switch (s->state) { @@ -2375,7 +2380,7 @@ static void service_notify_cgroup_empty_event(Unit *u) { /* If we were hoping for the daemon to write its PID file, * we can give up now. */ if (s->pid_file_pathspec) { - log_unit_warning(u->id, "%s never wrote its PID file. Failing.", UNIT(s)->id); + log_unit_warning(u, "Daemon never wrote its PID file. Failing."); service_unwatch_pid_file(s); if (s->state == SERVICE_START) @@ -2462,16 +2467,16 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { f = SERVICE_SUCCESS; } - log_unit_struct(u->id, - f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, - LOG_MESSAGE("%s: main process exited, code=%s, status=%i/%s", - u->id, sigchld_code_to_string(code), status, + log_struct(f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, + LOG_UNIT_ID(u), + LOG_UNIT_MESSAGE(u, "Main process exited, code=%s, status=%i/%s", + sigchld_code_to_string(code), status, strna(code == CLD_EXITED ? exit_status_to_string(status, EXIT_STATUS_FULL) : signal_to_string(status))), - "EXIT_CODE=%s", sigchld_code_to_string(code), - "EXIT_STATUS=%i", status, - NULL); + "EXIT_CODE=%s", sigchld_code_to_string(code), + "EXIT_STATUS=%i", status, + NULL); if (f != SERVICE_SUCCESS) s->result = f; @@ -2483,7 +2488,7 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { /* There is another command to * * execute, so let's do that. */ - log_unit_debug(u->id, "%s running next main command for state %s", u->id, service_state_to_string(s->state)); + log_unit_debug(u, "Running next main command for state %s.", service_state_to_string(s->state)); service_run_next_main(s); } else { @@ -2550,10 +2555,9 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { f = SERVICE_SUCCESS; } - log_unit_full(u->id, - f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, - "%s: control process exited, code=%s status=%i", - u->id, sigchld_code_to_string(code), status); + log_unit_full(u, f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, + "Control process exited, code=%s status=%i", + sigchld_code_to_string(code), status); if (f != SERVICE_SUCCESS) s->result = f; @@ -2570,7 +2574,7 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { /* There is another command to * * execute, so let's do that. */ - log_unit_debug(u->id, "%s running next control command for state %s", u->id, service_state_to_string(s->state)); + log_unit_debug(u, "Running next control command for state %s.", service_state_to_string(s->state)); service_run_next_control(s); } else { @@ -2580,7 +2584,7 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) { s->control_command = NULL; s->control_command_id = _SERVICE_EXEC_COMMAND_INVALID; - log_unit_debug(u->id, "%s got final SIGCHLD for state %s", u->id, service_state_to_string(s->state)); + log_unit_debug(u, "Got final SIGCHLD for state %s.", service_state_to_string(s->state)); switch (s->state) { @@ -2709,37 +2713,37 @@ static int service_dispatch_timer(sd_event_source *source, usec_t usec, void *us case SERVICE_START_PRE: case SERVICE_START: - log_unit_warning(UNIT(s)->id, "%s %s operation timed out. Terminating.", UNIT(s)->id, s->state == SERVICE_START ? "start" : "start-pre"); + log_unit_warning(UNIT(s), "%s operation timed out. Terminating.", s->state == SERVICE_START ? "Start" : "Start-pre"); service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_TIMEOUT); break; case SERVICE_START_POST: - log_unit_warning(UNIT(s)->id, "%s start-post operation timed out. Stopping.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Start-post operation timed out. Stopping."); service_enter_stop(s, SERVICE_FAILURE_TIMEOUT); break; case SERVICE_RELOAD: - log_unit_warning(UNIT(s)->id, "%s reload operation timed out. Stopping.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Reload operation timed out. Stopping."); s->reload_result = SERVICE_FAILURE_TIMEOUT; service_enter_running(s, SERVICE_SUCCESS); break; case SERVICE_STOP: - log_unit_warning(UNIT(s)->id, "%s stopping timed out. Terminating.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out. Terminating."); service_enter_signal(s, SERVICE_STOP_SIGTERM, SERVICE_FAILURE_TIMEOUT); break; case SERVICE_STOP_SIGABRT: - log_unit_warning(UNIT(s)->id, "%s stop-sigabrt timed out. Terminating.", UNIT(s)->id); + log_unit_warning(UNIT(s), "State 'stop-sigabrt' timed out. Terminating."); service_enter_signal(s, SERVICE_STOP_SIGTERM, SERVICE_FAILURE_TIMEOUT); break; case SERVICE_STOP_SIGTERM: if (s->kill_context.send_sigkill) { - log_unit_warning(UNIT(s)->id, "%s stop-sigterm timed out. Killing.", UNIT(s)->id); + log_unit_warning(UNIT(s), "State 'stop-sigterm' timed out. Killing."); service_enter_signal(s, SERVICE_STOP_SIGKILL, SERVICE_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(s)->id, "%s stop-sigterm timed out. Skipping SIGKILL.", UNIT(s)->id); + log_unit_warning(UNIT(s), "State 'stop-sigterm' timed out. Skipping SIGKILL."); service_enter_stop_post(s, SERVICE_FAILURE_TIMEOUT); } @@ -2750,37 +2754,36 @@ static int service_dispatch_timer(sd_event_source *source, usec_t usec, void *us * Must be something we cannot kill, so let's just be * weirded out and continue */ - log_unit_warning(UNIT(s)->id, "%s still around after SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Processes still around after SIGKILL. Ignoring."); service_enter_stop_post(s, SERVICE_FAILURE_TIMEOUT); break; case SERVICE_STOP_POST: - log_unit_warning(UNIT(s)->id, "%s stop-post timed out. Terminating.", UNIT(s)->id); + log_unit_warning(UNIT(s), "State 'stop-post' timed out. Terminating."); service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_TIMEOUT); break; case SERVICE_FINAL_SIGTERM: if (s->kill_context.send_sigkill) { - log_unit_warning(UNIT(s)->id, "%s stop-final-sigterm timed out. Killing.", UNIT(s)->id); + log_unit_warning(UNIT(s), "State 'stop-final-sigterm' timed out. Killing."); service_enter_signal(s, SERVICE_FINAL_SIGKILL, SERVICE_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(s)->id, "%s stop-final-sigterm timed out. Skipping SIGKILL. Entering failed mode.", UNIT(s)->id); + log_unit_warning(UNIT(s), "State 'stop-final-sigterm' timed out. Skipping SIGKILL. Entering failed mode."); service_enter_dead(s, SERVICE_FAILURE_TIMEOUT, false); } break; case SERVICE_FINAL_SIGKILL: - log_unit_warning(UNIT(s)->id, "%s still around after final SIGKILL. Entering failed mode.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Processes still around after final SIGKILL. Entering failed mode."); service_enter_dead(s, SERVICE_FAILURE_TIMEOUT, true); break; case SERVICE_AUTO_RESTART: - log_unit_info(UNIT(s)->id, + log_unit_info(UNIT(s), s->restart_usec > 0 ? - "%s holdoff time over, scheduling restart." : - "%s has no holdoff time, scheduling restart.", - UNIT(s)->id); + "Service hold-off time over, scheduling restart." : + "Service has no hold-off time, scheduling restart."); service_enter_restart(s); break; @@ -2798,7 +2801,7 @@ static int service_dispatch_watchdog(sd_event_source *source, usec_t usec, void assert(s); assert(source == s->watchdog_event_source); - log_unit_error(UNIT(s)->id, "%s watchdog timeout (limit %s)!", UNIT(s)->id, + log_unit_error(UNIT(s), "Watchdog timeout (limit %s)!", format_timespan(t, sizeof(t), s->watchdog_usec, 1)); service_enter_signal(s, SERVICE_STOP_SIGABRT, SERVICE_FAILURE_WATCHDOG); @@ -2815,19 +2818,18 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) assert(u); cc = strv_join(tags, ", "); - log_unit_debug(u->id, "%s: Got notification message from PID "PID_FMT" (%s)", - u->id, pid, isempty(cc) ? "n/a" : cc); + log_unit_debug(u, "Got notification message from PID "PID_FMT" (%s)", pid, isempty(cc) ? "n/a" : cc); if (s->notify_access == NOTIFY_NONE) { - log_unit_warning(u->id, "%s: Got notification message from PID "PID_FMT", but reception is disabled.", u->id, pid); + log_unit_warning(u, "Got notification message from PID "PID_FMT", but reception is disabled.", pid); return; } if (s->notify_access == NOTIFY_MAIN && pid != s->main_pid) { if (s->main_pid != 0) - log_unit_warning(u->id, "%s: Got notification message from PID "PID_FMT", but reception only permitted for main PID "PID_FMT, u->id, pid, s->main_pid); + log_unit_warning(u, "Got notification message from PID "PID_FMT", but reception only permitted for main PID "PID_FMT, pid, s->main_pid); else - log_unit_debug(u->id, "%s: Got notification message from PID "PID_FMT", but reception only permitted for main PID which is currently not known", u->id, pid); + log_unit_debug(u, "Got notification message from PID "PID_FMT", but reception only permitted for main PID which is currently not known", pid); return; } @@ -2835,9 +2837,9 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) e = strv_find_startswith(tags, "MAINPID="); if (e && IN_SET(s->state, SERVICE_START, SERVICE_START_POST, SERVICE_RUNNING, SERVICE_RELOAD)) { if (parse_pid(e, &pid) < 0) - log_unit_warning(u->id, "Failed to parse MAINPID= field in notification message: %s", e); + log_unit_warning(u, "Failed to parse MAINPID= field in notification message: %s", e); else { - log_unit_debug(u->id, "%s: got MAINPID=%s", u->id, e); + log_unit_debug(u, "Got MAINPID=%s", e); service_set_main_pid(s, pid); unit_watch_pid(UNIT(s), pid); @@ -2848,7 +2850,7 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) /* Interpret RELOADING= */ if (strv_find(tags, "RELOADING=1")) { - log_unit_debug(u->id, "%s: got RELOADING=1", u->id); + log_unit_debug(u, "Got RELOADING=1"); s->notify_state = NOTIFY_RELOADING; if (s->state == SERVICE_RUNNING) @@ -2860,7 +2862,7 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) /* Interpret READY= */ if (strv_find(tags, "READY=1")) { - log_unit_debug(u->id, "%s: got READY=1", u->id); + log_unit_debug(u, "Ggot READY=1"); s->notify_state = NOTIFY_READY; /* Type=notify services inform us about completed @@ -2879,7 +2881,7 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) /* Interpret STOPPING= */ if (strv_find(tags, "STOPPING=1")) { - log_unit_debug(u->id, "%s: got STOPPING=1", u->id); + log_unit_debug(u, "Got STOPPING=1"); s->notify_state = NOTIFY_STOPPING; if (s->state == SERVICE_RUNNING) @@ -2895,9 +2897,9 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) if (!isempty(e)) { if (!utf8_is_valid(e)) - log_unit_warning(u->id, "Status message in notification is not UTF-8 clean."); + log_unit_warning(u, "Status message in notification message is not UTF-8 clean."); else { - log_unit_debug(u->id, "%s: got STATUS=%s", u->id, e); + log_unit_debug(u, "Got STATUS=%s", e); t = strdup(e); if (!t) @@ -2921,9 +2923,9 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) int status_errno; if (safe_atoi(e, &status_errno) < 0 || status_errno < 0) - log_unit_warning(u->id, "Failed to parse ERRNO= field in notification message: %s", e); + log_unit_warning(u, "Failed to parse ERRNO= field in notification message: %s", e); else { - log_unit_debug(u->id, "%s: got ERRNO=%s", u->id, e); + log_unit_debug(u, "Got ERRNO=%s", e); if (s->status_errno != status_errno) { s->status_errno = status_errno; @@ -2934,13 +2936,13 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags, FDSet *fds) /* Interpret WATCHDOG= */ if (strv_find(tags, "WATCHDOG=1")) { - log_unit_debug(u->id, "%s: got WATCHDOG=1", u->id); + log_unit_debug(u, "Got WATCHDOG=1"); service_reset_watchdog(s); } /* Add the passed fds to the fd store */ if (strv_find(tags, "FDSTORE=1")) { - log_unit_debug(u->id, "%s: got FDSTORE=1", u->id); + log_unit_debug(u, "Got FDSTORE=1"); service_add_fd_store_set(s, fds); } @@ -2979,11 +2981,11 @@ static void service_bus_name_owner_change( assert(old_owner || new_owner); if (old_owner && new_owner) - log_unit_debug(u->id, "%s's D-Bus name %s changed owner from %s to %s", u->id, name, old_owner, new_owner); + log_unit_debug(u, "D-Bus name %s changed owner from %s to %s", name, old_owner, new_owner); else if (old_owner) - log_unit_debug(u->id, "%s's D-Bus name %s no longer registered by %s", u->id, name, old_owner); + log_unit_debug(u, "D-Bus name %s no longer registered by %s", name, old_owner); else - log_unit_debug(u->id, "%s's D-Bus name %s now registered by %s", u->id, name, new_owner); + log_unit_debug(u, "D-Bus name %s now registered by %s", name, new_owner); s->bus_name_good = !!new_owner; @@ -3012,7 +3014,7 @@ static void service_bus_name_owner_change( if (r >= 0) r = sd_bus_creds_get_pid(creds, &pid); if (r >= 0) { - log_unit_debug(u->id, "%s's D-Bus name %s is now owned by process %u", u->id, name, (unsigned) pid); + log_unit_debug(u, "D-Bus name %s is now owned by process %u", name, (unsigned) pid); service_set_main_pid(s, pid); unit_watch_pid(UNIT(s), pid); diff --git a/src/core/slice.c b/src/core/slice.c index b965850dab..e52bf71515 100644 --- a/src/core/slice.c +++ b/src/core/slice.c @@ -104,16 +104,16 @@ static int slice_verify(Slice *s) { return 0; if (!slice_name_is_valid(UNIT(s)->id)) { - log_unit_error(UNIT(s)->id, "Slice name %s is not valid. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Slice name %s is not valid. Refusing.", UNIT(s)->id); return -EINVAL; } r = slice_build_parent_slice(UNIT(s)->id, &parent); if (r < 0) - return log_unit_error_errno(UNIT(s)->id, r, "Failed to determine parent slice: %m"); + return log_unit_error_errno(UNIT(s), r, "Failed to determine parent slice: %m"); if (parent ? !unit_has_name(UNIT_DEREF(UNIT(s)->slice), parent) : UNIT_ISSET(UNIT(s)->slice)) { - log_unit_error(UNIT(s)->id, "%s located outside its parent slice. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Located outside of parent slice. Refusing."); return -EINVAL; } diff --git a/src/core/snapshot.c b/src/core/snapshot.c index 2c00680f16..1e634b9bc1 100644 --- a/src/core/snapshot.c +++ b/src/core/snapshot.c @@ -51,11 +51,7 @@ static void snapshot_set_state(Snapshot *s, SnapshotState state) { s->state = state; if (state != old_state) - log_unit_debug(UNIT(s)->id, - "%s changed %s -> %s", - UNIT(s)->id, - snapshot_state_to_string(old_state), - snapshot_state_to_string(state)); + log_unit_debug(UNIT(s), "Changed %s -> %s", snapshot_state_to_string(old_state), snapshot_state_to_string(state)); unit_notify(UNIT(s), state_translation_table[old_state], state_translation_table[state], true); } @@ -155,7 +151,7 @@ static int snapshot_deserialize_item(Unit *u, const char *key, const char *value state = snapshot_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else s->deserialized_state = state; @@ -163,7 +159,7 @@ static int snapshot_deserialize_item(Unit *u, const char *key, const char *value r = parse_boolean(value); if (r < 0) - log_unit_debug(u->id, "Failed to parse cleanup value %s", value); + log_unit_debug(u, "Failed to parse cleanup value: %s", value); else s->cleanup = r; @@ -173,7 +169,7 @@ static int snapshot_deserialize_item(Unit *u, const char *key, const char *value if (r < 0) return r; } else - log_unit_debug(u->id, "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -258,7 +254,7 @@ int snapshot_create(Manager *m, const char *name, bool cleanup, sd_bus_error *e, SNAPSHOT(u)->cleanup = cleanup; *_s = SNAPSHOT(u); - log_unit_info(u->id, "Created snapshot %s.", u->id); + log_unit_info(u, "Created snapshot."); return 0; @@ -272,7 +268,7 @@ fail: void snapshot_remove(Snapshot *s) { assert(s); - log_unit_info(UNIT(s)->id, "Removing snapshot %s.", UNIT(s)->id); + log_unit_info(UNIT(s), "Removing snapshot."); unit_add_to_cleanup_queue(UNIT(s)); } diff --git a/src/core/socket.c b/src/core/socket.c index 3fb3b362e1..33682073c9 100644 --- a/src/core/socket.c +++ b/src/core/socket.c @@ -398,33 +398,32 @@ static int socket_verify(Socket *s) { return 0; if (!s->ports) { - log_unit_error(UNIT(s)->id, "%s lacks Listen setting. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Unit lacks Listen setting. Refusing."); return -EINVAL; } if (s->accept && have_non_accept_socket(s)) { - log_unit_error(UNIT(s)->id, "%s configured for accepting sockets, but sockets are non-accepting. Refusing.", - UNIT(s)->id); + log_unit_error(UNIT(s), "Unit configured for accepting sockets, but sockets are non-accepting. Refusing."); return -EINVAL; } if (s->accept && s->max_connections <= 0) { - log_unit_error(UNIT(s)->id, "%s's MaxConnection setting too small. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "MaxConnection= setting too small. Refusing."); return -EINVAL; } if (s->accept && UNIT_DEREF(s->service)) { - log_unit_error(UNIT(s)->id, "Explicit service configuration for accepting sockets not supported on %s. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Explicit service configuration for accepting socket units not supported. Refusing."); return -EINVAL; } if (s->exec_context.pam_name && s->kill_context.kill_mode != KILL_CONTROL_GROUP) { - log_unit_error(UNIT(s)->id, "%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Unit has PAM enabled. Kill mode must be set to 'control-group'. Refusing."); return -EINVAL; } if (!strv_isempty(s->symlinks) && !socket_find_symlink_target(s)) { - log_unit_error(UNIT(s)->id, "%s has symlinks set but none or more than one node in the file system. Refusing.", UNIT(s)->id); + log_unit_error(UNIT(s), "Unit has symlinks set but none or more than one node in the file system. Refusing."); return -EINVAL; } @@ -822,60 +821,60 @@ static void socket_apply_socket_options(Socket *s, int fd) { if (s->keep_alive) { int b = s->keep_alive; if (setsockopt(fd, SOL_SOCKET, SO_KEEPALIVE, &b, sizeof(b)) < 0) - log_unit_warning(UNIT(s)->id, "SO_KEEPALIVE failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_KEEPALIVE failed: %m"); } if (s->keep_alive_time) { int value = s->keep_alive_time / USEC_PER_SEC; if (setsockopt(fd, SOL_TCP, TCP_KEEPIDLE, &value, sizeof(value)) < 0) - log_unit_warning(UNIT(s)->id, "TCP_KEEPIDLE failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "TCP_KEEPIDLE failed: %m"); } if (s->keep_alive_interval) { int value = s->keep_alive_interval / USEC_PER_SEC; if (setsockopt(fd, SOL_TCP, TCP_KEEPINTVL, &value, sizeof(value)) < 0) - log_unit_warning(UNIT(s)->id, "TCP_KEEPINTVL failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "TCP_KEEPINTVL failed: %m"); } if (s->keep_alive_cnt) { int value = s->keep_alive_cnt; if (setsockopt(fd, SOL_SOCKET, TCP_KEEPCNT, &value, sizeof(value)) < 0) - log_unit_warning(UNIT(s)->id, "TCP_KEEPCNT failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "TCP_KEEPCNT failed: %m"); } if (s->defer_accept) { int value = s->defer_accept / USEC_PER_SEC; if (setsockopt(fd, SOL_TCP, TCP_DEFER_ACCEPT, &value, sizeof(value)) < 0) - log_unit_warning(UNIT(s)->id, "TCP_DEFER_ACCEPT failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "TCP_DEFER_ACCEPT failed: %m"); } if (s->no_delay) { int b = s->no_delay; if (setsockopt(fd, SOL_TCP, TCP_NODELAY, &b, sizeof(b)) < 0) - log_unit_warning(UNIT(s)->id, "TCP_NODELAY failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "TCP_NODELAY failed: %m"); } if (s->broadcast) { int one = 1; if (setsockopt(fd, SOL_SOCKET, SO_BROADCAST, &one, sizeof(one)) < 0) - log_unit_warning(UNIT(s)->id, "SO_BROADCAST failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_BROADCAST failed: %m"); } if (s->pass_cred) { int one = 1; if (setsockopt(fd, SOL_SOCKET, SO_PASSCRED, &one, sizeof(one)) < 0) - log_unit_warning(UNIT(s)->id, "SO_PASSCRED failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_PASSCRED failed: %m"); } if (s->pass_sec) { int one = 1; if (setsockopt(fd, SOL_SOCKET, SO_PASSSEC, &one, sizeof(one)) < 0) - log_unit_warning(UNIT(s)->id, "SO_PASSSEC failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_PASSSEC failed: %m"); } if (s->priority >= 0) if (setsockopt(fd, SOL_SOCKET, SO_PRIORITY, &s->priority, sizeof(s->priority)) < 0) - log_unit_warning(UNIT(s)->id, "SO_PRIORITY failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_PRIORITY failed: %m"); if (s->receive_buffer > 0) { int value = (int) s->receive_buffer; @@ -884,23 +883,23 @@ static void socket_apply_socket_options(Socket *s, int fd) { if (setsockopt(fd, SOL_SOCKET, SO_RCVBUFFORCE, &value, sizeof(value)) < 0) if (setsockopt(fd, SOL_SOCKET, SO_RCVBUF, &value, sizeof(value)) < 0) - log_unit_warning(UNIT(s)->id, "SO_RCVBUF failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_RCVBUF failed: %m"); } if (s->send_buffer > 0) { int value = (int) s->send_buffer; if (setsockopt(fd, SOL_SOCKET, SO_SNDBUFFORCE, &value, sizeof(value)) < 0) if (setsockopt(fd, SOL_SOCKET, SO_SNDBUF, &value, sizeof(value)) < 0) - log_unit_warning(UNIT(s)->id, "SO_SNDBUF failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_SNDBUF failed: %m"); } if (s->mark >= 0) if (setsockopt(fd, SOL_SOCKET, SO_MARK, &s->mark, sizeof(s->mark)) < 0) - log_unit_warning(UNIT(s)->id, "SO_MARK failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_MARK failed: %m"); if (s->ip_tos >= 0) if (setsockopt(fd, IPPROTO_IP, IP_TOS, &s->ip_tos, sizeof(s->ip_tos)) < 0) - log_unit_warning(UNIT(s)->id, "IP_TOS failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "IP_TOS failed: %m"); if (s->ip_ttl >= 0) { int x; @@ -915,30 +914,29 @@ static void socket_apply_socket_options(Socket *s, int fd) { } if (r < 0 && x < 0) - log_unit_warning(UNIT(s)->id, - "IP_TTL/IPV6_UNICAST_HOPS failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "IP_TTL/IPV6_UNICAST_HOPS failed: %m"); } if (s->tcp_congestion) if (setsockopt(fd, SOL_TCP, TCP_CONGESTION, s->tcp_congestion, strlen(s->tcp_congestion)+1) < 0) - log_unit_warning(UNIT(s)->id, "TCP_CONGESTION failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "TCP_CONGESTION failed: %m"); if (s->reuse_port) { int b = s->reuse_port; if (setsockopt(fd, SOL_SOCKET, SO_REUSEPORT, &b, sizeof(b)) < 0) - log_unit_warning(UNIT(s)->id, "SO_REUSEPORT failed: %m"); + log_unit_warning_errno(UNIT(s), errno, "SO_REUSEPORT failed: %m"); } if (s->smack_ip_in) { r = mac_smack_apply_ip_in_fd(fd, s->smack_ip_in); if (r < 0) - log_unit_error_errno(UNIT(s)->id, r, "mac_smack_apply_ip_in_fd: %m"); + log_unit_error_errno(UNIT(s), r, "mac_smack_apply_ip_in_fd: %m"); } if (s->smack_ip_out) { r = mac_smack_apply_ip_out_fd(fd, s->smack_ip_out); if (r < 0) - log_unit_error_errno(UNIT(s)->id, r, "mac_smack_apply_ip_out_fd: %m"); + log_unit_error_errno(UNIT(s), r, "mac_smack_apply_ip_out_fd: %m"); } } @@ -950,12 +948,12 @@ static void socket_apply_fifo_options(Socket *s, int fd) { if (s->pipe_size > 0) if (fcntl(fd, F_SETPIPE_SZ, s->pipe_size) < 0) - log_unit_warning(UNIT(s)->id, "F_SETPIPE_SZ: %m"); + log_unit_warning_errno(UNIT(s), errno, "F_SETPIPE_SZ: %m"); if (s->smack) { r = mac_smack_apply_fd(fd, s->smack); if (r < 0) - log_unit_error_errno(UNIT(s)->id, r, "mac_smack_apply_fd: %m"); + log_unit_error_errno(UNIT(s), r, "mac_smack_apply_fd: %m"); } } @@ -1256,7 +1254,7 @@ static void socket_unwatch_fds(Socket *s) { r = sd_event_source_set_enabled(p->event_source, SD_EVENT_OFF); if (r < 0) - log_unit_debug(UNIT(s)->id, "Failed to disable event source."); + log_unit_debug_errno(UNIT(s), r, "Failed to disable event source: %m"); } } @@ -1276,7 +1274,7 @@ static int socket_watch_fds(Socket *s) { r = sd_event_add_io(UNIT(s)->manager->event, &p->event_source, p->fd, EPOLLIN, socket_dispatch_io, p); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "Failed to watch listening fds: %m"); + log_unit_warning_errno(UNIT(s), r, "Failed to watch listening fds: %m"); goto fail; } @@ -1328,8 +1326,7 @@ static void socket_set_state(Socket *s, SocketState state) { socket_close_fds(s); if (state != old_state) - log_unit_debug(UNIT(s)->id, "%s changed %s -> %s", - UNIT(s)->id, socket_state_to_string(old_state), socket_state_to_string(state)); + log_unit_debug(UNIT(s), "Changed %s -> %s", socket_state_to_string(old_state), socket_state_to_string(state)); unit_notify(UNIT(s), state_translation_table[old_state], state_translation_table[state], true); } @@ -1430,9 +1427,9 @@ static int socket_spawn(Socket *s, ExecCommand *c, pid_t *_pid) { exec_params.cgroup_path = UNIT(s)->cgroup_path; exec_params.cgroup_delegate = s->cgroup_context.delegate; exec_params.runtime_prefix = manager_get_runtime_prefix(UNIT(s)->manager); - exec_params.unit_id = UNIT(s)->id; - r = exec_spawn(c, + r = exec_spawn(UNIT(s), + c, &s->exec_context, &exec_params, s->exec_runtime, @@ -1576,9 +1573,7 @@ static void socket_enter_stop_post(Socket *s, SocketResult f) { return; fail: - log_unit_warning(UNIT(s)->id, - "%s failed to run 'stop-post' task: %s", - UNIT(s)->id, strerror(-r)); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'stop-post' task: %m"); socket_enter_signal(s, SOCKET_FINAL_SIGTERM, SOCKET_FAILURE_RESOURCES); } @@ -1619,7 +1614,7 @@ static void socket_enter_signal(Socket *s, SocketState state, SocketResult f) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to kill processes: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to kill processes: %m"); if (state == SOCKET_STOP_PRE_SIGTERM || state == SOCKET_STOP_PRE_SIGKILL) socket_enter_stop_post(s, SOCKET_FAILURE_RESOURCES); @@ -1650,7 +1645,7 @@ static void socket_enter_stop_pre(Socket *s, SocketResult f) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'stop-pre' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'stop-pre' task: %m"); socket_enter_stop_post(s, SOCKET_FAILURE_RESOURCES); } @@ -1660,7 +1655,7 @@ static void socket_enter_listening(Socket *s) { r = socket_watch_fds(s); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to watch sockets: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to watch sockets: %m"); goto fail; } @@ -1682,7 +1677,7 @@ static void socket_enter_start_post(Socket *s) { if (s->control_command) { r = socket_spawn(s, s->control_command, &s->control_pid); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'start-post' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'start-post' task: %m"); goto fail; } @@ -1703,7 +1698,7 @@ static void socket_enter_start_chown(Socket *s) { r = socket_open_fds(s); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to listen on sockets: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to listen on sockets: %m"); goto fail; } @@ -1715,7 +1710,7 @@ static void socket_enter_start_chown(Socket *s) { r = socket_chown(s, &s->control_pid); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to fork 'start-chown' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to fork 'start-chown' task: %m"); goto fail; } @@ -1740,7 +1735,7 @@ static void socket_enter_start_pre(Socket *s) { if (s->control_command) { r = socket_spawn(s, s->control_command, &s->control_pid); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'start-pre' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'start-pre' task: %m"); goto fail; } @@ -1764,7 +1759,7 @@ static void socket_enter_running(Socket *s, int cfd) { * shut down anyway */ if (unit_stop_pending(UNIT(s))) { - log_unit_debug(UNIT(s)->id, "Suppressing connection request on %s since unit stop is scheduled.", UNIT(s)->id); + log_unit_debug(UNIT(s), "Suppressing connection request since unit stop is scheduled."); if (cfd >= 0) safe_close(cfd); @@ -1774,14 +1769,14 @@ static void socket_enter_running(Socket *s, int cfd) { r = socket_open_fds(s); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to listen on sockets: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to listen on sockets: %m"); socket_enter_stop_pre(s, SOCKET_FAILURE_RESOURCES); return; } r = socket_watch_fds(s); if (r < 0) { - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to watch sockets: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to watch sockets: %m"); socket_enter_stop_pre(s, SOCKET_FAILURE_RESOURCES); } } @@ -1804,7 +1799,7 @@ static void socket_enter_running(Socket *s, int cfd) { if (!pending) { if (!UNIT_ISSET(s->service)) { - log_unit_error(UNIT(s)->id, "%s: service to activate vanished, refusing activation.", UNIT(s)->id); + log_unit_error(UNIT(s), "Service to activate vanished, refusing activation."); r = -ENOENT; goto fail; } @@ -1820,7 +1815,7 @@ static void socket_enter_running(Socket *s, int cfd) { Service *service; if (s->n_connections >= s->max_connections) { - log_unit_warning(UNIT(s)->id, "%s: Too many incoming connections (%u)", UNIT(s)->id, s->n_connections); + log_unit_warning(UNIT(s), "Too many incoming connections (%u)", s->n_connections); safe_close(cfd); return; } @@ -1878,8 +1873,8 @@ static void socket_enter_running(Socket *s, int cfd) { return; fail: - log_unit_warning(UNIT(s)->id, "%s failed to queue service startup job (Maybe the service file is missing or not a %s unit?): %s", - UNIT(s)->id, cfd >= 0 ? "template" : "non-template", + log_unit_warning(UNIT(s), "Failed to queue service startup job (Maybe the service file is missing or not a %s unit?): %s", + cfd >= 0 ? "template" : "non-template", bus_error_message(&error, r)); socket_enter_stop_pre(s, SOCKET_FAILURE_RESOURCES); @@ -1904,7 +1899,7 @@ static void socket_run_next(Socket *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run next task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run next task: %m"); if (s->state == SOCKET_START_POST) socket_enter_stop_pre(s, SOCKET_FAILURE_RESOURCES); @@ -1944,7 +1939,7 @@ static int socket_start(Unit *u) { service = SERVICE(UNIT_DEREF(s->service)); if (UNIT(service)->load_state != UNIT_LOADED) { - log_unit_error(u->id, "Socket service %s not loaded, refusing.", UNIT(service)->id); + log_unit_error(u, "Socket service %s not loaded, refusing.", UNIT(service)->id); return -ENOENT; } @@ -1953,7 +1948,7 @@ static int socket_start(Unit *u) { if (service->state != SERVICE_DEAD && service->state != SERVICE_FAILED && service->state != SERVICE_AUTO_RESTART) { - log_unit_error(u->id, "Socket service %s already active, refusing.", UNIT(service)->id); + log_unit_error(u, "Socket service %s already active, refusing.", UNIT(service)->id); return -EBUSY; } } @@ -2065,7 +2060,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, state = socket_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else s->deserialized_state = state; } else if (streq(key, "result")) { @@ -2073,7 +2068,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, f = socket_result_from_string(value); if (f < 0) - log_unit_debug(u->id, "Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != SOCKET_SUCCESS) s->result = f; @@ -2081,14 +2076,14 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, unsigned k; if (safe_atou(value, &k) < 0) - log_unit_debug(u->id, "Failed to parse n-accepted value %s", value); + log_unit_debug(u, "Failed to parse n-accepted value: %s", value); else s->n_accepted += k; } else if (streq(key, "control-pid")) { pid_t pid; if (parse_pid(value, &pid) < 0) - log_unit_debug(u->id, "Failed to parse control-pid value %s", value); + log_unit_debug(u, "Failed to parse control-pid value: %s", value); else s->control_pid = pid; } else if (streq(key, "control-command")) { @@ -2096,7 +2091,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, id = socket_exec_command_from_string(value); if (id < 0) - log_unit_debug(u->id, "Failed to parse exec-command value %s", value); + log_unit_debug(u, "Failed to parse exec-command value: %s", value); else { s->control_command_id = id; s->control_command = s->exec_command[id]; @@ -2106,7 +2101,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, SocketPort *p; if (sscanf(value, "%i %n", &fd, &skip) < 1 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse fifo value %s", value); + log_unit_debug(u, "Failed to parse fifo value: %s", value); else { LIST_FOREACH(port, p, s->ports) @@ -2125,7 +2120,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, SocketPort *p; if (sscanf(value, "%i %n", &fd, &skip) < 1 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse special value %s", value); + log_unit_debug(u, "Failed to parse special value: %s", value); else { LIST_FOREACH(port, p, s->ports) @@ -2144,7 +2139,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, SocketPort *p; if (sscanf(value, "%i %n", &fd, &skip) < 1 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse mqueue value %s", value); + log_unit_debug(u, "Failed to parse mqueue value: %s", value); else { LIST_FOREACH(port, p, s->ports) @@ -2163,7 +2158,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, SocketPort *p; if (sscanf(value, "%i %i %n", &fd, &type, &skip) < 2 || fd < 0 || type < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse socket value %s", value); + log_unit_debug(u, "Failed to parse socket value: %s", value); else { LIST_FOREACH(port, p, s->ports) @@ -2181,7 +2176,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, SocketPort *p; if (sscanf(value, "%i %n", &fd, &skip) < 1 || fd < 0 || !fdset_contains(fds, fd)) - log_unit_debug(u->id, "Failed to parse socket value %s", value); + log_unit_debug(u, "Failed to parse socket value: %s", value); else { LIST_FOREACH(port, p, s->ports) @@ -2194,7 +2189,7 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value, } } } else - log_unit_debug(UNIT(s)->id, "Unknown serialization key '%s'", key); + log_unit_debug(UNIT(s), "Unknown serialization key: %s", key); return 0; } @@ -2298,16 +2293,14 @@ static int socket_dispatch_io(sd_event_source *source, int fd, uint32_t revents, if (p->socket->state != SOCKET_LISTENING) return 0; - log_unit_debug(UNIT(p->socket)->id, "Incoming traffic on %s", UNIT(p->socket)->id); + log_unit_debug(UNIT(p->socket), "Incoming traffic"); if (revents != EPOLLIN) { if (revents & EPOLLHUP) - log_unit_error(UNIT(p->socket)->id, "%s: Got POLLHUP on a listening socket. The service probably invoked shutdown() on it, and should better not do that.", - UNIT(p->socket)->id); + log_unit_error(UNIT(p->socket), "Got POLLHUP on a listening socket. The service probably invoked shutdown() on it, and should better not do that."); else - log_unit_error(UNIT(p->socket)->id, "%s: Got unexpected poll event (0x%x) on socket.", - UNIT(p->socket)->id, revents); + log_unit_error(UNIT(p->socket), "Got unexpected poll event (0x%x) on socket.", revents); goto fail; } @@ -2324,7 +2317,7 @@ static int socket_dispatch_io(sd_event_source *source, int fd, uint32_t revents, if (errno == EINTR) continue; - log_unit_error(UNIT(p->socket)->id, "Failed to accept socket: %m"); + log_unit_error_errno(UNIT(p->socket), errno, "Failed to accept socket: %m"); goto fail; } @@ -2372,10 +2365,9 @@ static void socket_sigchld_event(Unit *u, pid_t pid, int code, int status) { f = SOCKET_SUCCESS; } - log_unit_full(u->id, - f == SOCKET_SUCCESS ? LOG_DEBUG : LOG_NOTICE, - "%s control process exited, code=%s status=%i", - u->id, sigchld_code_to_string(code), status); + log_unit_full(u, f == SOCKET_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, + "Control process exited, code=%s status=%i", + sigchld_code_to_string(code), status); if (f != SOCKET_SUCCESS) s->result = f; @@ -2384,9 +2376,7 @@ static void socket_sigchld_event(Unit *u, pid_t pid, int code, int status) { s->control_command->command_next && f == SOCKET_SUCCESS) { - log_unit_debug(u->id, - "%s running next command for state %s", - u->id, socket_state_to_string(s->state)); + log_unit_debug(u, "Running next command for state %s", socket_state_to_string(s->state)); socket_run_next(s); } else { s->control_command = NULL; @@ -2395,9 +2385,7 @@ static void socket_sigchld_event(Unit *u, pid_t pid, int code, int status) { /* No further commands for this step, so let's figure * out what to do next */ - log_unit_debug(u->id, - "%s got final SIGCHLD for state %s", - u->id, socket_state_to_string(s->state)); + log_unit_debug(u, "Got final SIGCHLD for state %s", socket_state_to_string(s->state)); switch (s->state) { @@ -2452,53 +2440,53 @@ static int socket_dispatch_timer(sd_event_source *source, usec_t usec, void *use switch (s->state) { case SOCKET_START_PRE: - log_unit_warning(UNIT(s)->id, "%s starting timed out. Terminating.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Starting timed out. Terminating."); socket_enter_signal(s, SOCKET_FINAL_SIGTERM, SOCKET_FAILURE_TIMEOUT); break; case SOCKET_START_CHOWN: case SOCKET_START_POST: - log_unit_warning(UNIT(s)->id, "%s starting timed out. Stopping.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Starting timed out. Stopping."); socket_enter_stop_pre(s, SOCKET_FAILURE_TIMEOUT); break; case SOCKET_STOP_PRE: - log_unit_warning(UNIT(s)->id, "%s stopping timed out. Terminating.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out. Terminating."); socket_enter_signal(s, SOCKET_STOP_PRE_SIGTERM, SOCKET_FAILURE_TIMEOUT); break; case SOCKET_STOP_PRE_SIGTERM: if (s->kill_context.send_sigkill) { - log_unit_warning(UNIT(s)->id, "%s stopping timed out. Killing.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out. Killing."); socket_enter_signal(s, SOCKET_STOP_PRE_SIGKILL, SOCKET_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(s)->id, "%s stopping timed out. Skipping SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out. Skipping SIGKILL. Ignoring."); socket_enter_stop_post(s, SOCKET_FAILURE_TIMEOUT); } break; case SOCKET_STOP_PRE_SIGKILL: - log_unit_warning(UNIT(s)->id, "%s still around after SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Processes still around after SIGKILL. Ignoring."); socket_enter_stop_post(s, SOCKET_FAILURE_TIMEOUT); break; case SOCKET_STOP_POST: - log_unit_warning(UNIT(s)->id, "%s stopping timed out (2). Terminating.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out (2). Terminating."); socket_enter_signal(s, SOCKET_FINAL_SIGTERM, SOCKET_FAILURE_TIMEOUT); break; case SOCKET_FINAL_SIGTERM: if (s->kill_context.send_sigkill) { - log_unit_warning(UNIT(s)->id, "%s stopping timed out (2). Killing.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out (2). Killing."); socket_enter_signal(s, SOCKET_FINAL_SIGKILL, SOCKET_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(s)->id, "%s stopping timed out (2). Skipping SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Stopping timed out (2). Skipping SIGKILL. Ignoring."); socket_enter_dead(s, SOCKET_FAILURE_TIMEOUT); } break; case SOCKET_FINAL_SIGKILL: - log_unit_warning(UNIT(s)->id, "%s still around after SIGKILL (2). Entering failed mode.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Still around after SIGKILL (2). Entering failed mode."); socket_enter_dead(s, SOCKET_FAILURE_TIMEOUT); break; @@ -2568,7 +2556,7 @@ static void socket_notify_service_dead(Socket *s, bool failed_permanent) { * services. */ if (s->state == SOCKET_RUNNING) { - log_unit_debug(UNIT(s)->id, "%s got notified about service death (failed permanently: %s)", UNIT(s)->id, yes_no(failed_permanent)); + log_unit_debug(UNIT(s), "Got notified about service death (failed permanently: %s)", yes_no(failed_permanent)); if (failed_permanent) socket_enter_stop_pre(s, SOCKET_FAILURE_SERVICE_FAILED_PERMANENT); else @@ -2587,7 +2575,7 @@ void socket_connection_unref(Socket *s) { assert(s->n_connections > 0); s->n_connections--; - log_unit_debug(UNIT(s)->id, "%s: One connection closed, %u left.", UNIT(s)->id, s->n_connections); + log_unit_debug(UNIT(s), "One connection closed, %u left.", s->n_connections); } static void socket_trigger_notify(Unit *u, Unit *other) { diff --git a/src/core/swap.c b/src/core/swap.c index 0d04bb4de8..1cf3f2a864 100644 --- a/src/core/swap.c +++ b/src/core/swap.c @@ -230,15 +230,15 @@ static int swap_verify(Swap *s) { r = unit_name_from_path(s->what, ".swap", &e); if (r < 0) - return log_unit_error_errno(UNIT(s)->id, r, "%s: failed to generate unit name from path: %m", UNIT(s)->id); + return log_unit_error_errno(UNIT(s), r, "Failed to generate unit name from path: %m"); if (!unit_has_name(UNIT(s), e)) { - log_unit_error(UNIT(s)->id, "%s: Value of \"What\" and unit name do not match, not loading.", UNIT(s)->id); + log_unit_error(UNIT(s), "Value of What= and unit name do not match, not loading."); return -EINVAL; } if (s->exec_context.pam_name && s->kill_context.kill_mode != KILL_CONTROL_GROUP) { - log_unit_error(UNIT(s)->id, "%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing to load.", UNIT(s)->id); + log_unit_error(UNIT(s), "Unit has PAM enabled. Kill mode must be set to 'control-group'. Refusing to load."); return -EINVAL; } @@ -359,7 +359,7 @@ static int swap_setup_unit( r = unit_name_from_path(what, ".swap", &e); if (r < 0) - return log_error_errno(r, "Failed to generate unit name from path: %m"); + return log_unit_error_errno(u, r, "Failed to generate unit name from path: %m"); u = manager_get_unit(m, e); @@ -414,7 +414,7 @@ static int swap_setup_unit( return 0; fail: - log_unit_warning_errno(e, r, "Failed to load swap unit: %m"); + log_unit_warning_errno(u, r, "Failed to load swap unit: %m"); if (delete && u) unit_free(u); @@ -497,11 +497,7 @@ static void swap_set_state(Swap *s, SwapState state) { } if (state != old_state) - log_unit_debug(UNIT(s)->id, - "%s changed %s -> %s", - UNIT(s)->id, - swap_state_to_string(old_state), - swap_state_to_string(state)); + log_unit_debug(UNIT(s), "Changed %s -> %s", swap_state_to_string(old_state), swap_state_to_string(state)); unit_notify(UNIT(s), state_translation_table[old_state], state_translation_table[state], true); @@ -634,9 +630,9 @@ static int swap_spawn(Swap *s, ExecCommand *c, pid_t *_pid) { exec_params.cgroup_path = UNIT(s)->cgroup_path; exec_params.cgroup_delegate = s->cgroup_context.delegate; exec_params.runtime_prefix = manager_get_runtime_prefix(UNIT(s)->manager); - exec_params.unit_id = UNIT(s)->id; - r = exec_spawn(c, + r = exec_spawn(UNIT(s), + c, &s->exec_context, &exec_params, s->exec_runtime, @@ -716,7 +712,7 @@ static void swap_enter_signal(Swap *s, SwapState state, SwapResult f) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to kill processes: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to kill processes: %m"); swap_enter_dead(s, SWAP_FAILURE_RESOURCES); } @@ -730,15 +726,13 @@ static void swap_enter_activating(Swap *s) { s->control_command = s->exec_command + SWAP_EXEC_ACTIVATE; if (s->from_fragment) { - fstab_filter_options(s->parameters_fragment.options, "discard\0", - NULL, &discard, NULL); + fstab_filter_options(s->parameters_fragment.options, "discard\0", NULL, &discard, NULL); priority = s->parameters_fragment.priority; if (priority < 0) { r = fstab_find_pri(s->parameters_fragment.options, &priority); if (r < 0) - log_notice_errno(r, "Failed to parse swap priority \"%s\", ignoring: %m", - s->parameters_fragment.options); + log_notice_errno(r, "Failed to parse swap priority \"%s\", ignoring: %m", s->parameters_fragment.options); } } @@ -783,7 +777,7 @@ static void swap_enter_activating(Swap *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'swapon' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'swapon' task: %m"); swap_enter_dead(s, SWAP_FAILURE_RESOURCES); } @@ -813,7 +807,7 @@ static void swap_enter_deactivating(Swap *s) { return; fail: - log_unit_warning_errno(UNIT(s)->id, r, "%s failed to run 'swapoff' task: %m", UNIT(s)->id); + log_unit_warning_errno(UNIT(s), r, "Failed to run 'swapoff' task: %m"); swap_enter_active(s, SWAP_FAILURE_RESOURCES); } @@ -907,7 +901,7 @@ static int swap_deserialize_item(Unit *u, const char *key, const char *value, FD state = swap_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else s->deserialized_state = state; } else if (streq(key, "result")) { @@ -915,14 +909,14 @@ static int swap_deserialize_item(Unit *u, const char *key, const char *value, FD f = swap_result_from_string(value); if (f < 0) - log_unit_debug(u->id, "Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != SWAP_SUCCESS) s->result = f; } else if (streq(key, "control-pid")) { pid_t pid; if (parse_pid(value, &pid) < 0) - log_unit_debug(u->id, "Failed to parse control-pid value %s", value); + log_unit_debug(u, "Failed to parse control-pid value: %s", value); else s->control_pid = pid; @@ -931,13 +925,13 @@ static int swap_deserialize_item(Unit *u, const char *key, const char *value, FD id = swap_exec_command_from_string(value); if (id < 0) - log_unit_debug(u->id, "Failed to parse exec-command value %s", value); + log_unit_debug(u, "Failed to parse exec-command value: %s", value); else { s->control_command_id = id; s->control_command = s->exec_command + id; } } else - log_unit_debug(u->id, "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -995,10 +989,8 @@ static void swap_sigchld_event(Unit *u, pid_t pid, int code, int status) { s->control_command_id = _SWAP_EXEC_COMMAND_INVALID; } - log_unit_full(u->id, - f == SWAP_SUCCESS ? LOG_DEBUG : LOG_NOTICE, - "%s swap process exited, code=%s status=%i", - u->id, sigchld_code_to_string(code), status); + log_unit_full(u, f == SWAP_SUCCESS ? LOG_DEBUG : LOG_NOTICE, 0, + "Swap process exited, code=%s status=%i", sigchld_code_to_string(code), status); switch (s->state) { @@ -1038,38 +1030,38 @@ static int swap_dispatch_timer(sd_event_source *source, usec_t usec, void *userd case SWAP_ACTIVATING: case SWAP_ACTIVATING_DONE: - log_unit_warning(UNIT(s)->id, "%s activation timed out. Stopping.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Activation timed out. Stopping."); swap_enter_signal(s, SWAP_ACTIVATING_SIGTERM, SWAP_FAILURE_TIMEOUT); break; case SWAP_DEACTIVATING: - log_unit_warning(UNIT(s)->id, "%s deactivation timed out. Stopping.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Deactivation timed out. Stopping."); swap_enter_signal(s, SWAP_DEACTIVATING_SIGTERM, SWAP_FAILURE_TIMEOUT); break; case SWAP_ACTIVATING_SIGTERM: if (s->kill_context.send_sigkill) { - log_unit_warning(UNIT(s)->id, "%s activation timed out. Killing.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Activation timed out. Killing."); swap_enter_signal(s, SWAP_ACTIVATING_SIGKILL, SWAP_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(s)->id, "%s activation timed out. Skipping SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Activation timed out. Skipping SIGKILL. Ignoring."); swap_enter_dead(s, SWAP_FAILURE_TIMEOUT); } break; case SWAP_DEACTIVATING_SIGTERM: if (s->kill_context.send_sigkill) { - log_unit_warning(UNIT(s)->id, "%s deactivation timed out. Killing.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Deactivation timed out. Killing."); swap_enter_signal(s, SWAP_DEACTIVATING_SIGKILL, SWAP_FAILURE_TIMEOUT); } else { - log_unit_warning(UNIT(s)->id, "%s deactivation timed out. Skipping SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Deactivation timed out. Skipping SIGKILL. Ignoring."); swap_enter_dead(s, SWAP_FAILURE_TIMEOUT); } break; case SWAP_ACTIVATING_SIGKILL: case SWAP_DEACTIVATING_SIGKILL: - log_unit_warning(UNIT(s)->id, "%s swap process still around after SIGKILL. Ignoring.", UNIT(s)->id); + log_unit_warning(UNIT(s), "Swap process still around after SIGKILL. Ignoring."); swap_enter_dead(s, SWAP_FAILURE_TIMEOUT); break; diff --git a/src/core/timer.c b/src/core/timer.c index d6905bb510..eb73b64a48 100644 --- a/src/core/timer.c +++ b/src/core/timer.c @@ -85,7 +85,7 @@ static int timer_verify(Timer *t) { return 0; if (!t->values) { - log_unit_error(UNIT(t)->id, "%s lacks value setting. Refusing.", UNIT(t)->id); + log_unit_error(UNIT(t), "Timer unit lacks value setting. Refusing."); return -EINVAL; } @@ -147,7 +147,7 @@ static int timer_setup_persistent(Timer *t) { r = get_home_dir(&h); if (r < 0) - return log_error_errno(r, "Failed to determine home directory: %m"); + return log_unit_error_errno(UNIT(t), r, "Failed to determine home directory: %m"); t->stamp_path = strjoin(h, "/.local/share/systemd/timers/stamp-", UNIT(t)->id, NULL); } @@ -257,10 +257,7 @@ static void timer_set_state(Timer *t, TimerState state) { } if (state != old_state) - log_unit_debug(UNIT(t)->id, - "%s changed %s -> %s", UNIT(t)->id, - timer_state_to_string(old_state), - timer_state_to_string(state)); + log_unit_debug(UNIT(t), "Changed %s -> %s", timer_state_to_string(old_state), timer_state_to_string(state)); unit_notify(UNIT(t), state_translation_table[old_state], state_translation_table[state], true); } @@ -416,7 +413,7 @@ static void timer_enter_waiting(Timer *t, bool initial) { } if (!found_monotonic && !found_realtime) { - log_unit_debug(UNIT(t)->id, "%s: Timer is elapsed.", UNIT(t)->id); + log_unit_debug(UNIT(t), "Timer is elapsed."); timer_set_state(t, TIMER_ELAPSED); return; } @@ -424,9 +421,7 @@ static void timer_enter_waiting(Timer *t, bool initial) { if (found_monotonic) { char buf[FORMAT_TIMESPAN_MAX]; - log_unit_debug(UNIT(t)->id, "%s: Monotonic timer elapses in %s.", - UNIT(t)->id, - format_timespan(buf, sizeof(buf), t->next_elapse_monotonic_or_boottime > ts_monotonic ? t->next_elapse_monotonic_or_boottime - ts_monotonic : 0, 0)); + log_unit_debug(UNIT(t), "Monotonic timer elapses in %s.", format_timespan(buf, sizeof(buf), t->next_elapse_monotonic_or_boottime > ts_monotonic ? t->next_elapse_monotonic_or_boottime - ts_monotonic : 0, 0)); if (t->monotonic_event_source) { r = sd_event_source_set_time(t->monotonic_event_source, t->next_elapse_monotonic_or_boottime); @@ -455,7 +450,7 @@ static void timer_enter_waiting(Timer *t, bool initial) { if (found_realtime) { char buf[FORMAT_TIMESTAMP_MAX]; - log_unit_debug(UNIT(t)->id, "%s: Realtime timer elapses at %s.", UNIT(t)->id, format_timestamp(buf, sizeof(buf), t->next_elapse_realtime)); + log_unit_debug(UNIT(t), "Realtime timer elapses at %s.", format_timestamp(buf, sizeof(buf), t->next_elapse_realtime)); if (t->realtime_event_source) { r = sd_event_source_set_time(t->realtime_event_source, t->next_elapse_realtime); @@ -486,7 +481,7 @@ static void timer_enter_waiting(Timer *t, bool initial) { return; fail: - log_unit_warning_errno(UNIT(t)->id, r, "%s failed to enter waiting state: %m", UNIT(t)->id); + log_unit_warning_errno(UNIT(t), r, "Failed to enter waiting state: %m"); timer_enter_dead(t, TIMER_FAILURE_RESOURCES); } @@ -514,9 +509,7 @@ static void timer_enter_running(Timer *t) { return; fail: - log_unit_warning(UNIT(t)->id, - "%s failed to queue unit startup job: %s", - UNIT(t)->id, bus_error_message(&error, r)); + log_unit_warning(UNIT(t), "Failed to queue unit startup job: %s", bus_error_message(&error, r)); timer_enter_dead(t, TIMER_FAILURE_RESOURCES); } @@ -597,7 +590,7 @@ static int timer_deserialize_item(Unit *u, const char *key, const char *value, F state = timer_state_from_string(value); if (state < 0) - log_unit_debug(u->id, "Failed to parse state value %s", value); + log_unit_debug(u, "Failed to parse state value: %s", value); else t->deserialized_state = state; } else if (streq(key, "result")) { @@ -605,23 +598,23 @@ static int timer_deserialize_item(Unit *u, const char *key, const char *value, F f = timer_result_from_string(value); if (f < 0) - log_unit_debug(u->id, "Failed to parse result value %s", value); + log_unit_debug(u, "Failed to parse result value: %s", value); else if (f != TIMER_SUCCESS) t->result = f; } else if (streq(key, "last-trigger-realtime")) { r = safe_atou64(value, &t->last_trigger.realtime); if (r < 0) - log_unit_debug(u->id, "Failed to parse last-trigger-realtime value %s", value); + log_unit_debug(u, "Failed to parse last-trigger-realtime value: %s", value); } else if (streq(key, "last-trigger-monotonic")) { r = safe_atou64(value, &t->last_trigger.monotonic); if (r < 0) - log_unit_debug(u->id, "Failed to parse last-trigger-monotonic value %s", value); + log_unit_debug(u, "Failed to parse last-trigger-monotonic value: %s", value); } else - log_unit_debug(u->id, "Unknown serialization key '%s'", key); + log_unit_debug(u, "Unknown serialization key: %s", key); return 0; } @@ -646,7 +639,7 @@ static int timer_dispatch(sd_event_source *s, uint64_t usec, void *userdata) { if (t->state != TIMER_WAITING) return 0; - log_unit_debug(UNIT(t)->id, "Timer elapsed on %s", UNIT(t)->id); + log_unit_debug(UNIT(t), "Timer elapsed."); timer_enter_running(t); return 0; } @@ -679,7 +672,7 @@ static void timer_trigger_notify(Unit *u, Unit *other) { case TIMER_RUNNING: if (UNIT_IS_INACTIVE_OR_FAILED(unit_active_state(other))) { - log_unit_debug(UNIT(t)->id, "%s got notified about unit deactivation.", UNIT(t)->id); + log_unit_debug(UNIT(t), "Got notified about unit deactivation."); timer_enter_waiting(t, false); } break; @@ -712,7 +705,7 @@ static void timer_time_change(Unit *u) { if (t->state != TIMER_WAITING) return; - log_unit_debug(u->id, "%s: time change, recalculating next elapse.", u->id); + log_unit_debug(u, "Time change, recalculating next elapse."); timer_enter_waiting(t, false); } diff --git a/src/core/transaction.c b/src/core/transaction.c index 7b19e2f841..d1f7b7f2bf 100644 --- a/src/core/transaction.c +++ b/src/core/transaction.c @@ -189,11 +189,11 @@ static int delete_one_unmergeable_job(Transaction *tr, Job *j) { * another unit in which case we * rather remove the start. */ - log_unit_debug(j->unit->id, + log_unit_debug(j->unit, "Looking at job %s/%s conflicted_by=%s", j->unit->id, job_type_to_string(j->type), yes_no(j->type == JOB_STOP && job_is_conflicted_by(j))); - log_unit_debug(k->unit->id, + log_unit_debug(k->unit, "Looking at job %s/%s conflicted_by=%s", k->unit->id, job_type_to_string(k->type), yes_no(k->type == JOB_STOP && job_is_conflicted_by(k))); @@ -222,7 +222,7 @@ static int delete_one_unmergeable_job(Transaction *tr, Job *j) { return -ENOEXEC; /* Ok, we can drop one, so let's do so. */ - log_unit_debug(d->unit->id, + log_unit_debug(d->unit, "Fixing conflicting jobs %s/%s,%s/%s by deleting job %s/%s", j->unit->id, job_type_to_string(j->type), k->unit->id, job_type_to_string(k->type), @@ -368,7 +368,7 @@ static int transaction_verify_order_one(Transaction *tr, Job *j, Job *from, unsi * job to remove. We use the marker to find our way * back, since smart how we are we stored our way back * in there. */ - log_unit_warning(j->unit->id, + log_unit_warning(j->unit, "Found ordering cycle on %s/%s", j->unit->id, job_type_to_string(j->type)); @@ -376,7 +376,7 @@ static int transaction_verify_order_one(Transaction *tr, Job *j, Job *from, unsi for (k = from; k; k = ((k->generation == generation && k->marker != k) ? k->marker : NULL)) { /* logging for j not k here here to provide consistent narrative */ - log_unit_warning(j->unit->id, + log_unit_warning(j->unit, "Found dependency on %s/%s", k->unit->id, job_type_to_string(k->type)); @@ -396,10 +396,10 @@ static int transaction_verify_order_one(Transaction *tr, Job *j, Job *from, unsi if (delete) { /* logging for j not k here here to provide consistent narrative */ - log_unit_warning(j->unit->id, + log_unit_warning(j->unit, "Breaking ordering cycle by deleting job %s/%s", delete->unit->id, job_type_to_string(delete->type)); - log_unit_error(delete->unit->id, + log_unit_error(delete->unit, "Job %s/%s deleted to break ordering cycle starting with %s/%s", delete->unit->id, job_type_to_string(delete->type), j->unit->id, job_type_to_string(j->type)); @@ -552,17 +552,17 @@ rescan: continue; if (stops_running_service) - log_unit_debug(j->unit->id, + log_unit_debug(j->unit, "%s/%s would stop a running service.", j->unit->id, job_type_to_string(j->type)); if (changes_existing_job) - log_unit_debug(j->unit->id, + log_unit_debug(j->unit, "%s/%s would change existing job.", j->unit->id, job_type_to_string(j->type)); /* Ok, let's get rid of this */ - log_unit_debug(j->unit->id, + log_unit_debug(j->unit, "Deleting %s/%s to minimize impact.", j->unit->id, job_type_to_string(j->type)); @@ -817,7 +817,7 @@ static void transaction_unlink_job(Transaction *tr, Job *j, bool delete_dependen job_dependency_free(j->object_list); if (other && delete_dependencies) { - log_unit_debug(other->unit->id, + log_unit_debug(other->unit, "Deleting job %s/%s as dependency of job %s/%s", other->unit->id, job_type_to_string(other->type), j->unit->id, job_type_to_string(j->type)); @@ -920,9 +920,7 @@ int transaction_add_job_and_dependencies( SET_FOREACH(dep, following, i) { r = transaction_add_job_and_dependencies(tr, type, dep, ret, false, override, false, false, ignore_order, e); if (r < 0) { - log_unit_warning(dep->id, - "Cannot add dependency job for unit %s, ignoring: %s", - dep->id, bus_error_message(e, r)); + log_unit_warning(dep, "Cannot add dependency job for, ignoring: %s", bus_error_message(e, r)); if (e) sd_bus_error_free(e); @@ -959,10 +957,10 @@ int transaction_add_job_and_dependencies( SET_FOREACH(dep, ret->unit->dependencies[UNIT_REQUIRES_OVERRIDABLE], i) { r = transaction_add_job_and_dependencies(tr, JOB_START, dep, ret, !override, override, false, false, ignore_order, e); if (r < 0) { - log_unit_full(dep->id, - r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, - "Cannot add dependency job for unit %s, ignoring: %s", - dep->id, bus_error_message(e, r)); + log_unit_full(dep, + r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, r, + "Cannot add dependency job, ignoring: %s", + bus_error_message(e, r)); if (e) sd_bus_error_free(e); @@ -972,10 +970,10 @@ int transaction_add_job_and_dependencies( SET_FOREACH(dep, ret->unit->dependencies[UNIT_WANTS], i) { r = transaction_add_job_and_dependencies(tr, JOB_START, dep, ret, false, false, false, false, ignore_order, e); if (r < 0) { - log_unit_full(dep->id, - r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, - "Cannot add dependency job for unit %s, ignoring: %s", - dep->id, bus_error_message(e, r)); + log_unit_full(dep, + r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, r, + "Cannot add dependency job, ignoring: %s", + bus_error_message(e, r)); if (e) sd_bus_error_free(e); @@ -996,10 +994,10 @@ int transaction_add_job_and_dependencies( SET_FOREACH(dep, ret->unit->dependencies[UNIT_REQUISITE_OVERRIDABLE], i) { r = transaction_add_job_and_dependencies(tr, JOB_VERIFY_ACTIVE, dep, ret, !override, override, false, false, ignore_order, e); if (r < 0) { - log_unit_full(dep->id, - r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, - "Cannot add dependency job for unit %s, ignoring: %s", - dep->id, bus_error_message(e, r)); + log_unit_full(dep, + r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, r, + "Cannot add dependency job, ignoring: %s", + bus_error_message(e, r)); if (e) sd_bus_error_free(e); @@ -1020,9 +1018,9 @@ int transaction_add_job_and_dependencies( SET_FOREACH(dep, ret->unit->dependencies[UNIT_CONFLICTED_BY], i) { r = transaction_add_job_and_dependencies(tr, JOB_STOP, dep, ret, false, override, false, false, ignore_order, e); if (r < 0) { - log_unit_warning(dep->id, - "Cannot add dependency job for unit %s, ignoring: %s", - dep->id, bus_error_message(e, r)); + log_unit_warning(dep, + "Cannot add dependency job, ignoring: %s", + bus_error_message(e, r)); if (e) sd_bus_error_free(e); @@ -1073,9 +1071,9 @@ int transaction_add_job_and_dependencies( SET_FOREACH(dep, ret->unit->dependencies[UNIT_PROPAGATES_RELOAD_TO], i) { r = transaction_add_job_and_dependencies(tr, JOB_RELOAD, dep, ret, false, override, false, false, ignore_order, e); if (r < 0) { - log_unit_warning(dep->id, - "Cannot add dependency reload job for unit %s, ignoring: %s", - dep->id, bus_error_message(e, r)); + log_unit_warning(dep, + "Cannot add dependency reload job, ignoring: %s", + bus_error_message(e, r)); if (e) sd_bus_error_free(e); @@ -1120,9 +1118,7 @@ int transaction_add_isolate_jobs(Transaction *tr, Manager *m) { r = transaction_add_job_and_dependencies(tr, JOB_STOP, u, tr->anchor_job, true, false, false, false, false, NULL); if (r < 0) - log_unit_warning(u->id, - "Cannot add isolate job for unit %s, ignoring: %s", - u->id, strerror(-r)); + log_unit_warning_errno(u, r, "Cannot add isolate job, ignoring: %m"); } return 0; diff --git a/src/core/unit.c b/src/core/unit.c index 6513bcb1cb..25d0859bf3 100644 --- a/src/core/unit.c +++ b/src/core/unit.c @@ -65,7 +65,7 @@ const UnitVTable * const unit_vtable[_UNIT_TYPE_MAX] = { [UNIT_SCOPE] = &scope_vtable }; -static int maybe_warn_about_dependency(const char *id, const char *other, UnitDependency dependency); +static void maybe_warn_about_dependency(Unit *u, const char *other, UnitDependency dependency); Unit *unit_new(Manager *m, size_t size) { Unit *u; @@ -652,7 +652,7 @@ static void merge_dependencies(Unit *u, Unit *other, const char *other_id, UnitD /* Do not add dependencies between u and itself */ if (back == u) { if (set_remove(back->dependencies[k], other)) - maybe_warn_about_dependency(u->id, other_id, k); + maybe_warn_about_dependency(u, other_id, k); } else { r = set_remove_and_put(back->dependencies[k], other, u); if (r == -EEXIST) @@ -666,7 +666,7 @@ static void merge_dependencies(Unit *u, Unit *other, const char *other_id, UnitD /* Also do not move dependencies on u to itself */ back = set_remove(other->dependencies[d], u); if (back) - maybe_warn_about_dependency(u->id, other_id, d); + maybe_warn_about_dependency(u, other_id, d); /* The move cannot fail. The caller must have performed a reservation. */ assert_se(complete_move(&u->dependencies[d], &other->dependencies[d]) == 0); @@ -1226,7 +1226,7 @@ int unit_load(Unit *u) { goto fail; if (u->on_failure_job_mode == JOB_ISOLATE && set_size(u->dependencies[UNIT_ON_FAILURE]) > 1) { - log_unit_error(u->id, "More than one OnFailure= dependencies specified for %s but OnFailureJobMode=isolate set. Refusing.", u->id); + log_unit_error(u, "More than one OnFailure= dependencies specified but OnFailureJobMode=isolate set. Refusing."); r = -EINVAL; goto fail; } @@ -1247,8 +1247,7 @@ fail: unit_add_to_dbus_queue(u); unit_add_to_gc_queue(u); - log_unit_debug(u->id, "Failed to load configuration for %s: %s", - u->id, strerror(-r)); + log_unit_debug_errno(u, r, "Failed to load configuration: %m"); return r; } @@ -1272,23 +1271,20 @@ static bool unit_condition_test_list(Unit *u, Condition *first, const char *(*to r = condition_test(c); if (r < 0) - log_unit_warning(u->id, - "Couldn't determine result for %s=%s%s%s for %s, assuming failed: %s", + log_unit_warning(u, + "Couldn't determine result for %s=%s%s%s, assuming failed: %m", to_string(c->type), c->trigger ? "|" : "", c->negate ? "!" : "", - c->parameter, - u->id, - strerror(-r)); + c->parameter); else - log_unit_debug(u->id, - "%s=%s%s%s %s for %s.", + log_unit_debug(u, + "%s=%s%s%s %s.", to_string(c->type), c->trigger ? "|" : "", c->negate ? "!" : "", c->parameter, - condition_result_to_string(c->result), - u->id); + condition_result_to_string(c->result)); if (!c->trigger && r <= 0) return false; @@ -1401,11 +1397,17 @@ static void unit_status_log_starting_stopping_reloading(Unit *u, JobType t) { t == JOB_STOP ? SD_MESSAGE_UNIT_STOPPING : SD_MESSAGE_UNIT_RELOADING; - log_unit_struct(u->id, - LOG_INFO, - LOG_MESSAGE_ID(mid), - LOG_MESSAGE("%s", buf), - NULL); + /* Note that we deliberately use LOG_MESSAGE() instead of + * LOG_UNIT_MESSAGE() here, since this is supposed to mimic + * closely what is written to screen using the status output, + * which is supposed the highest level, friendliest output + * possible, which means we should avoid the low-level unit + * name. */ + log_struct(LOG_INFO, + LOG_MESSAGE_ID(mid), + LOG_UNIT_ID(u), + LOG_MESSAGE("%s", buf), + NULL); } /* Errors: @@ -1439,21 +1441,21 @@ int unit_start(Unit *u) { * but we don't want to recheck the condition in that case. */ if (state != UNIT_ACTIVATING && !unit_condition_test(u)) { - log_unit_debug(u->id, "Starting of %s requested but condition failed. Not starting unit.", u->id); + log_unit_debug(u, "Starting requested but condition failed. Not starting unit."); return -EALREADY; } /* If the asserts failed, fail the entire job */ if (state != UNIT_ACTIVATING && !unit_assert_test(u)) { - log_unit_debug(u->id, "Starting of %s requested but asserts failed.", u->id); + log_unit_notice(u, "Starting requested but asserts failed."); return -EPROTO; } /* Forward to the main object, if we aren't it. */ following = unit_following(u); if (following) { - log_unit_debug(u->id, "Redirecting start request from %s to %s.", u->id, following->id); + log_unit_debug(u, "Redirecting start request from %s to %s.", u->id, following->id); return unit_start(following); } @@ -1513,7 +1515,7 @@ int unit_stop(Unit *u) { following = unit_following(u); if (following) { - log_unit_debug(u->id, "Redirecting stop request from %s to %s.", u->id, following->id); + log_unit_debug(u, "Redirecting stop request from %s to %s.", u->id, following->id); return unit_stop(following); } @@ -1554,13 +1556,13 @@ int unit_reload(Unit *u) { return -EALREADY; if (state != UNIT_ACTIVE) { - log_unit_warning(u->id, "Unit %s cannot be reloaded because it is inactive.", u->id); + log_unit_warning(u, "Unit cannot be reloaded because it is inactive."); return -ENOEXEC; } following = unit_following(u); if (following) { - log_unit_debug(u->id, "Redirecting reload request from %s to %s.", u->id, following->id); + log_unit_debug(u, "Redirecting reload request from %s to %s.", u->id, following->id); return unit_reload(following); } @@ -1617,7 +1619,7 @@ static void unit_check_unneeded(Unit *u) { if (unit_active_or_pending(other)) return; - log_unit_info(u->id, "Unit %s is not needed anymore. Stopping.", u->id); + log_unit_info(u, "Unit not needed anymore. Stopping."); /* Ok, nobody needs us anymore. Sniff. Then let's commit suicide */ manager_add_job(u->manager, JOB_STOP, u, JOB_FAIL, true, NULL, NULL); @@ -1651,7 +1653,7 @@ static void unit_check_binds_to(Unit *u) { return; assert(other); - log_unit_info(u->id, "Unit %s is bound to inactive unit %s. Stopping, too.", u->id, other->id); + log_unit_info(u, "Unit is bound to inactive unit %s. Stopping, too.", other->id); /* A unit we need to run is gone. Sniff. Let's stop this. */ manager_add_job(u->manager, JOB_STOP, u, JOB_FAIL, true, NULL, NULL); @@ -1743,14 +1745,14 @@ void unit_start_on_failure(Unit *u) { if (set_size(u->dependencies[UNIT_ON_FAILURE]) <= 0) return; - log_unit_info(u->id, "Triggering OnFailure= dependencies of %s.", u->id); + log_unit_info(u, "Triggering OnFailure= dependencies."); SET_FOREACH(other, u->dependencies[UNIT_ON_FAILURE], i) { int r; r = manager_add_job(u->manager, JOB_START, other, u->on_failure_job_mode, true, NULL, NULL); if (r < 0) - log_unit_error_errno(u->id, r, "Failed to enqueue OnFailure= job: %m"); + log_unit_error_errno(u, r, "Failed to enqueue OnFailure= job: %m"); } } @@ -1911,7 +1913,7 @@ void unit_notify(Unit *u, UnitActiveState os, UnitActiveState ns, bool reload_su check_unneeded_dependencies(u); if (ns != os && ns == UNIT_FAILED) { - log_unit_notice(u->id, "Unit %s entered failed state.", u->id); + log_unit_notice(u, "Unit entered failed state."); unit_start_on_failure(u); } } @@ -2142,51 +2144,17 @@ bool unit_job_is_applicable(Unit *u, JobType j) { } } -static int maybe_warn_about_dependency(const char *id, const char *other, UnitDependency dependency) { - assert(id); - - switch (dependency) { - case UNIT_REQUIRES: - case UNIT_REQUIRES_OVERRIDABLE: - case UNIT_WANTS: - case UNIT_REQUISITE: - case UNIT_REQUISITE_OVERRIDABLE: - case UNIT_BINDS_TO: - case UNIT_PART_OF: - case UNIT_REQUIRED_BY: - case UNIT_REQUIRED_BY_OVERRIDABLE: - case UNIT_WANTED_BY: - case UNIT_BOUND_BY: - case UNIT_CONSISTS_OF: - case UNIT_REFERENCES: - case UNIT_REFERENCED_BY: - case UNIT_PROPAGATES_RELOAD_TO: - case UNIT_RELOAD_PROPAGATED_FROM: - case UNIT_JOINS_NAMESPACE_OF: - return 0; - - case UNIT_CONFLICTS: - case UNIT_CONFLICTED_BY: - case UNIT_BEFORE: - case UNIT_AFTER: - case UNIT_ON_FAILURE: - case UNIT_TRIGGERS: - case UNIT_TRIGGERED_BY: - if (streq_ptr(id, other)) - log_unit_warning(id, "Dependency %s=%s dropped from unit %s", - unit_dependency_to_string(dependency), id, other); - else - log_unit_warning(id, "Dependency %s=%s dropped from unit %s merged into %s", - unit_dependency_to_string(dependency), id, - strna(other), id); - return -EINVAL; +static void maybe_warn_about_dependency(Unit *u, const char *other, UnitDependency dependency) { + assert(u); - case _UNIT_DEPENDENCY_MAX: - case _UNIT_DEPENDENCY_INVALID: - break; - } + /* Only warn about some unit types */ + if (!IN_SET(dependency, UNIT_CONFLICTS, UNIT_CONFLICTED_BY, UNIT_BEFORE, UNIT_AFTER, UNIT_ON_FAILURE, UNIT_TRIGGERS, UNIT_TRIGGERED_BY)) + return; - assert_not_reached("Invalid dependency type"); + if (streq_ptr(u->id, other)) + log_unit_warning(u, "Dependency %s=%s dropped", unit_dependency_to_string(dependency), u->id); + else + log_unit_warning(u, "Dependency %s=%s dropped, merged into %s", unit_dependency_to_string(dependency), strna(other), u->id); } int unit_add_dependency(Unit *u, UnitDependency d, Unit *other, bool add_reference) { @@ -2230,7 +2198,7 @@ int unit_add_dependency(Unit *u, UnitDependency d, Unit *other, bool add_referen /* We won't allow dependencies on ourselves. We will not * consider them an error however. */ if (u == other) { - maybe_warn_about_dependency(orig_u->id, orig_other->id, d); + maybe_warn_about_dependency(orig_u, orig_other->id, d); return 0; } @@ -2577,7 +2545,7 @@ int unit_serialize(Unit *u, FILE *f, FDSet *fds, bool serialize_jobs) { rt = unit_get_exec_runtime(u); if (rt) { - r = exec_runtime_serialize(rt, u, f, fds); + r = exec_runtime_serialize(u, rt, f, fds); if (r < 0) return r; } @@ -2669,7 +2637,7 @@ static int unit_set_cgroup_path(Unit *u, const char *path) { } if (u->cgroup_path) { - log_unit_debug(u->id, "%s: Changing cgroup path from %s to %s.", u->id, u->cgroup_path, strna(p)); + log_unit_debug(u, "Changing cgroup path from %s to %s.", u->cgroup_path, strna(p)); hashmap_remove(u->manager->cgroup_unit, u->cgroup_path); free(u->cgroup_path); } @@ -2751,7 +2719,7 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) { type = job_type_from_string(v); if (type < 0) - log_debug("Failed to parse job type value %s", v); + log_unit_debug(u, "Failed to parse job type value: %s", v); else u->deserialized_job = type; } @@ -2778,7 +2746,7 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) { r = parse_boolean(v); if (r < 0) - log_debug("Failed to parse condition result value %s, ignoring.", v); + log_unit_debug(u, "Failed to parse condition result value %s, ignoring.", v); else u->condition_result = r; @@ -2788,7 +2756,7 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) { r = parse_boolean(v); if (r < 0) - log_debug("Failed to parse assert result value %s, ignoring.", v); + log_unit_debug(u, "Failed to parse assert result value %s, ignoring.", v); else u->assert_result = r; @@ -2798,7 +2766,7 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) { r = parse_boolean(v); if (r < 0) - log_debug("Failed to parse transient bool %s, ignoring.", v); + log_unit_debug(u, "Failed to parse transient bool %s, ignoring.", v); else u->transient = r; @@ -2808,7 +2776,7 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) { r = safe_atou64(v, &u->cpuacct_usage_base); if (r < 0) - log_debug("Failed to parse CPU usage %s, ignoring.", v); + log_unit_debug(u, "Failed to parse CPU usage %s, ignoring.", v); continue; @@ -2816,16 +2784,16 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) { r = unit_set_cgroup_path(u, v); if (r < 0) - log_debug_errno(r, "Failed to set cgroup path %s, ignoring: %m", v); + log_unit_debug_errno(u, r, "Failed to set cgroup path %s, ignoring: %m", v); continue; } if (unit_can_serialize(u)) { if (rt) { - r = exec_runtime_deserialize_item(rt, u, l, v, fds); + r = exec_runtime_deserialize_item(u, rt, l, v, fds); if (r < 0) { - log_unit_warning(u->id, "Failed to deserialize runtime parameter '%s', ignoring.", l); + log_unit_warning(u, "Failed to deserialize runtime parameter '%s', ignoring.", l); continue; } @@ -2836,7 +2804,7 @@ int unit_deserialize(Unit *u, FILE *f, FDSet *fds) { r = UNIT_VTABLE(u)->deserialize_item(u, l, v, fds); if (r < 0) - log_unit_warning(u->id, "Failed to deserialize unit parameter '%s', ignoring.", l); + log_unit_warning(u, "Failed to deserialize unit parameter '%s', ignoring.", l); } } } @@ -3526,7 +3494,7 @@ int unit_kill_context( _cleanup_free_ char *comm = NULL; get_process_comm(main_pid, &comm); - log_unit_warning_errno(u->id, r, "Failed to kill main process " PID_FMT " (%s): %m", main_pid, strna(comm)); + log_unit_warning_errno(u, r, "Failed to kill main process " PID_FMT " (%s): %m", main_pid, strna(comm)); } else { if (!main_pid_alien) wait_for_exit = true; @@ -3543,7 +3511,7 @@ int unit_kill_context( _cleanup_free_ char *comm = NULL; get_process_comm(control_pid, &comm); - log_unit_warning_errno(u->id, r, "Failed to kill control process " PID_FMT " (%s): %m", control_pid, strna(comm)); + log_unit_warning_errno(u, r, "Failed to kill control process " PID_FMT " (%s): %m", control_pid, strna(comm)); } else { wait_for_exit = true; @@ -3563,7 +3531,7 @@ int unit_kill_context( r = cg_kill_recursive(SYSTEMD_CGROUP_CONTROLLER, u->cgroup_path, sig, true, true, false, pid_set); if (r < 0) { if (r != -EAGAIN && r != -ESRCH && r != -ENOENT) - log_unit_warning_errno(u->id, r, "Failed to kill control group: %m"); + log_unit_warning_errno(u, r, "Failed to kill control group: %m"); } else if (r > 0) { /* FIXME: For now, we will not wait for the diff --git a/src/core/unit.h b/src/core/unit.h index 31b12157c2..094510ba5d 100644 --- a/src/core/unit.h +++ b/src/core/unit.h @@ -612,20 +612,24 @@ UnitActiveState unit_active_state_from_string(const char *s) _pure_; /* Macros which append UNIT= or USER_UNIT= to the message */ -#define log_unit_full_errno(unit, level, error, ...) log_object_internal(level, error, __FILE__, __LINE__, __func__, getpid() == 1 ? "UNIT=" : "USER_UNIT=", unit, __VA_ARGS__) -#define log_unit_full(unit, level, ...) log_unit_full_errno(unit, level, 0, __VA_ARGS__) - -#define log_unit_debug(unit, ...) log_unit_full(unit, LOG_DEBUG, __VA_ARGS__) -#define log_unit_info(unit, ...) log_unit_full(unit, LOG_INFO, __VA_ARGS__) -#define log_unit_notice(unit, ...) log_unit_full(unit, LOG_NOTICE, __VA_ARGS__) -#define log_unit_warning(unit, ...) log_unit_full(unit, LOG_WARNING, __VA_ARGS__) -#define log_unit_error(unit, ...) log_unit_full(unit, LOG_ERR, __VA_ARGS__) - -#define log_unit_debug_errno(unit, error, ...) log_unit_full_errno(unit, LOG_DEBUG, error, __VA_ARGS__) -#define log_unit_info_errno(unit, error, ...) log_unit_full_errno(unit, LOG_INFO, error, __VA_ARGS__) -#define log_unit_notice_errno(unit, error, ...) log_unit_full_errno(unit, LOG_NOTICE, error, __VA_ARGS__) -#define log_unit_warning_errno(unit, error, ...) log_unit_full_errno(unit, LOG_WARNING, error, __VA_ARGS__) -#define log_unit_error_errno(unit, error, ...) log_unit_full_errno(unit, LOG_ERR, error, __VA_ARGS__) - -#define log_unit_struct(unit, level, ...) log_struct(level, getpid() == 1 ? "UNIT=%s" : "USER_UNIT=%s", unit, __VA_ARGS__) -#define log_unit_struct_errno(unit, level, error, ...) log_struct_errno(level, error, getpid() == 1 ? "UNIT=%s" : "USER_UNIT=%s", unit, __VA_ARGS__) +#define log_unit_full(unit, level, error, ...) \ + ({ \ + Unit *_u = (unit); \ + _u ? log_object_internal(level, error, __FILE__, __LINE__, __func__, _u->manager->unit_log_field, _u->id, ##__VA_ARGS__) : \ + log_internal(level, error, __FILE__, __LINE__, __func__, ##__VA_ARGS__); \ + }) + +#define log_unit_debug(unit, ...) log_unit_full(unit, LOG_DEBUG, 0, ##__VA_ARGS__) +#define log_unit_info(unit, ...) log_unit_full(unit, LOG_INFO, 0, ##__VA_ARGS__) +#define log_unit_notice(unit, ...) log_unit_full(unit, LOG_NOTICE, 0, ##__VA_ARGS__) +#define log_unit_warning(unit, ...) log_unit_full(unit, LOG_WARNING, 0, ##__VA_ARGS__) +#define log_unit_error(unit, ...) log_unit_full(unit, LOG_ERR, 0, ##__VA_ARGS__) + +#define log_unit_debug_errno(unit, error, ...) log_unit_full(unit, LOG_DEBUG, error, ##__VA_ARGS__) +#define log_unit_info_errno(unit, error, ...) log_unit_full(unit, LOG_INFO, error, ##__VA_ARGS__) +#define log_unit_notice_errno(unit, error, ...) log_unit_full(unit, LOG_NOTICE, error, ##__VA_ARGS__) +#define log_unit_warning_errno(unit, error, ...) log_unit_full(unit, LOG_WARNING, error, ##__VA_ARGS__) +#define log_unit_error_errno(unit, error, ...) log_unit_full(unit, LOG_ERR, error, ##__VA_ARGS__) + +#define LOG_UNIT_MESSAGE(unit, fmt, ...) "MESSAGE=%s: " fmt, (unit)->id, ##__VA_ARGS__ +#define LOG_UNIT_ID(unit) (unit)->manager->unit_log_format_string, (unit)->id diff --git a/src/network/networkd-dhcp4.c b/src/network/networkd-dhcp4.c index 38321905e6..c99e92f56d 100644 --- a/src/network/networkd-dhcp4.c +++ b/src/network/networkd-dhcp4.c @@ -409,62 +409,43 @@ static int dhcp_lease_acquired(sd_dhcp_client *client, Link *link) { assert(link); r = sd_dhcp_client_get_lease(client, &lease); - if (r < 0) { - log_link_warning(link, "DHCP error: no lease: %s", - strerror(-r)); - return r; - } + if (r < 0) + return log_link_error_errno(link, r, "DHCP error: no lease: %m"); r = sd_dhcp_lease_get_address(lease, &address); - if (r < 0) { - log_link_warning(link, "DHCP error: no address: %s", - strerror(-r)); - return r; - } + if (r < 0) + return log_link_error_errno(link, r, "DHCP error: no address: %m"); r = sd_dhcp_lease_get_netmask(lease, &netmask); - if (r < 0) { - log_link_warning(link, "DHCP error: no netmask: %s", - strerror(-r)); - return r; - } + if (r < 0) + return log_link_error_errno(link, r, "DHCP error: no netmask: %m"); prefixlen = in_addr_netmask_to_prefixlen(&netmask); r = sd_dhcp_lease_get_router(lease, &gateway); - if (r < 0 && r != -ENOENT) { - log_link_warning(link, "DHCP error: could not get gateway: %s", - strerror(-r)); - return r; - } + if (r < 0 && r != -ENOENT) + return log_link_error_errno(link, r, "DHCP error: could not get gateway: %m"); if (r >= 0) - log_link_struct(link, LOG_INFO, - "MESSAGE=%-*s: DHCPv4 address %u.%u.%u.%u/%u via %u.%u.%u.%u", - IFNAMSIZ, - link->ifname, - ADDRESS_FMT_VAL(address), - prefixlen, - ADDRESS_FMT_VAL(gateway), - "ADDRESS=%u.%u.%u.%u", - ADDRESS_FMT_VAL(address), - "PREFIXLEN=%u", - prefixlen, - "GATEWAY=%u.%u.%u.%u", - ADDRESS_FMT_VAL(gateway), - NULL); + log_struct(LOG_INFO, + LOG_LINK_INTERFACE(link), + LOG_LINK_MESSAGE(link, "DHCPv4 address %u.%u.%u.%u/%u via %u.%u.%u.%u", + ADDRESS_FMT_VAL(address), + prefixlen, + ADDRESS_FMT_VAL(gateway)), + "ADDRESS=%u.%u.%u.%u", ADDRESS_FMT_VAL(address), + "PREFIXLEN=%u", prefixlen, + "GATEWAY=%u.%u.%u.%u", ADDRESS_FMT_VAL(gateway), + NULL); else - log_link_struct(link, LOG_INFO, - "MESSAGE=%-*s: DHCPv4 address %u.%u.%u.%u/%u", - IFNAMSIZ, - link->ifname, - ADDRESS_FMT_VAL(address), - prefixlen, - "ADDRESS=%u.%u.%u.%u", - ADDRESS_FMT_VAL(address), - "PREFIXLEN=%u", - prefixlen, - NULL); + log_struct(LOG_INFO, + LOG_LINK_INTERFACE(link), + LOG_LINK_MESSAGE(link, "DHCPv4 address %u.%u.%u.%u/%u", + ADDRESS_FMT_VAL(address), + prefixlen), + "ADDRESS=%u.%u.%u.%u", ADDRESS_FMT_VAL(address), + "PREFIXLEN=%u", prefixlen, + NULL); link->dhcp_lease = lease; @@ -475,8 +456,7 @@ static int dhcp_lease_acquired(sd_dhcp_client *client, Link *link) { if (r >= 0) { r = link_set_mtu(link, mtu); if (r < 0) - log_link_error(link, "Failed to set MTU " - "to %" PRIu16, mtu); + log_link_error_errno(link, r, "Failed to set MTU to %" PRIu16 ": %m", mtu); } } @@ -487,27 +467,21 @@ static int dhcp_lease_acquired(sd_dhcp_client *client, Link *link) { if (r >= 0) { r = link_set_hostname(link, hostname); if (r < 0) - log_link_error(link, - "Failed to set transient hostname to '%s'", - hostname); + log_link_error_errno(link, r, "Failed to set transient hostname to '%s': %m", hostname); } } if (!link->network->dhcp_critical) { - r = sd_dhcp_lease_get_lifetime(link->dhcp_lease, - &lifetime); + r = sd_dhcp_lease_get_lifetime(link->dhcp_lease, &lifetime); if (r < 0) { - log_link_warning(link, - "DHCP error: no lifetime: %s", - strerror(-r)); + log_link_warning_errno(link, r, "DHCP error: no lifetime: %m"); return r; } } r = dhcp4_update_address(link, &address, &netmask, lifetime); if (r < 0) { - log_link_warning(link, "could not update IP address: %s", - strerror(-r)); + log_link_warning_errno(link, r, "Could not update IP address: %m"); link_enter_failed(link); return r; } diff --git a/src/network/networkd-dhcp6.c b/src/network/networkd-dhcp6.c index 5668fdf16c..33e18137d2 100644 --- a/src/network/networkd-dhcp6.c +++ b/src/network/networkd-dhcp6.c @@ -83,16 +83,14 @@ static int dhcp6_address_update(Link *link, struct in6_addr *ip6_addr, addr->cinfo.ifa_prefered = lifetime_preferred; addr->cinfo.ifa_valid = lifetime_valid; - log_link_struct(link, LOG_INFO, "MESSAGE=%-*s: DHCPv6 address "SD_ICMP6_ADDRESS_FORMAT_STR"/%d timeout preferred %d valid %d", - IFNAMSIZ, - link->ifname, SD_ICMP6_ADDRESS_FORMAT_VAL(addr->in_addr.in6), - addr->prefixlen, lifetime_preferred, lifetime_valid, - NULL); + log_link_info(link, + "DHCPv6 address "SD_ICMP6_ADDRESS_FORMAT_STR"/%d timeout preferred %d valid %d", + SD_ICMP6_ADDRESS_FORMAT_VAL(addr->in_addr.in6), + addr->prefixlen, lifetime_preferred, lifetime_valid); r = address_update(addr, link, dhcp6_address_handler); if (r < 0) - log_link_warning(link, "Could not assign DHCPv6 address: %s", - strerror(-r)); + log_link_warning_errno(link, r, "Could not assign DHCPv6 address: %m"); return r; } @@ -289,11 +287,9 @@ static int dhcp6_prefix_expired(Link *link) { if (r < 0) return r; - log_link_struct(link, LOG_INFO, - "MESSAGE=%-*s: IPv6 prefix "SD_ICMP6_ADDRESS_FORMAT_STR"/%d expired", - IFNAMSIZ, link->ifname, - SD_ICMP6_ADDRESS_FORMAT_VAL(*expired_prefix), - expired_prefixlen, NULL); + log_link_info(link, "IPv6 prefix "SD_ICMP6_ADDRESS_FORMAT_STR"/%d expired", + SD_ICMP6_ADDRESS_FORMAT_VAL(*expired_prefix), + expired_prefixlen); sd_dhcp6_lease_reset_address_iter(lease); @@ -306,14 +302,9 @@ static int dhcp6_prefix_expired(Link *link) { if (r < 0) continue; - log_link_struct(link, LOG_INFO, - "MESSAGE=%-*s: IPv6 prefix length updated "SD_ICMP6_ADDRESS_FORMAT_STR"/%d", - IFNAMSIZ, link->ifname, - SD_ICMP6_ADDRESS_FORMAT_VAL(ip6_addr), 128, - NULL); + log_link_info(link, "IPv6 prefix length updated "SD_ICMP6_ADDRESS_FORMAT_STR"/%d", SD_ICMP6_ADDRESS_FORMAT_VAL(ip6_addr), 128); - dhcp6_address_update(link, &ip6_addr, 128, lifetime_preferred, - lifetime_valid); + dhcp6_address_update(link, &ip6_addr, 128, lifetime_preferred, lifetime_valid); } return 0; diff --git a/src/network/networkd-link.c b/src/network/networkd-link.c index 0c6bb658e6..5628ed92bf 100644 --- a/src/network/networkd-link.c +++ b/src/network/networkd-link.c @@ -722,12 +722,7 @@ static int link_set_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) { r = sd_rtnl_message_get_errno(m); if (r < 0 && r != -EEXIST) { - log_link_struct(link, LOG_ERR, - "MESSAGE=%-*s: could not join netdev: %s", - IFNAMSIZ, link->ifname, - strerror(-r), - "ERRNO=%d", -r, - NULL); + log_link_error_errno(link, r, "Could not join netdev: %m"); link_enter_failed(link); return 1; } @@ -1411,22 +1406,20 @@ static int link_enter_join_netdev(Link *link) { return link_joined(link); if (link->network->bond) { - log_link_struct(link, LOG_DEBUG, - "MESSAGE=%-*s: enslaving by '%s'", - IFNAMSIZ, link->ifname, - link->network->bond->ifname, - NETDEVIF(link->network->bond), - NULL); - - r = netdev_join(link->network->bond, link, &netdev_join_handler); + log_struct(LOG_DEBUG, + LOG_LINK_INTERFACE(link), + LOG_NETDEV_INTERFACE(link->network->bond), + LOG_LINK_MESSAGE(link, "Enslaving by '%s'", link->network->bond->ifname), + NULL); + + r = netdev_join(link->network->bond, link, netdev_join_handler); if (r < 0) { - log_link_struct(link, LOG_WARNING, - "MESSAGE=%-*s: could not join netdev '%s': %s", - IFNAMSIZ, link->ifname, - link->network->bond->ifname, - strerror(-r), - NETDEVIF(link->network->bond), - NULL); + log_struct_errno(LOG_WARNING, r, + LOG_LINK_INTERFACE(link), + LOG_NETDEV_INTERFACE(link->network->bond), + LOG_LINK_MESSAGE(link, "Could not join netdev '%s': %m", link->network->bond->ifname), + NULL); + link_enter_failed(link); return r; } @@ -1435,23 +1428,19 @@ static int link_enter_join_netdev(Link *link) { } if (link->network->bridge) { - log_link_struct(link, LOG_DEBUG, - "MESSAGE=%-*s: enslaving by '%s'", - IFNAMSIZ, link->ifname, - link->network->bridge->ifname, - NETDEVIF(link->network->bridge), - NULL); - - r = netdev_join(link->network->bridge, link, - &netdev_join_handler); + log_struct(LOG_DEBUG, + LOG_LINK_INTERFACE(link), + LOG_NETDEV_INTERFACE(link->network->bridge), + LOG_LINK_MESSAGE(link, "Enslaving by '%s'", link->network->bridge->ifname), + NULL); + + r = netdev_join(link->network->bridge, link, netdev_join_handler); if (r < 0) { - log_link_struct(link, LOG_WARNING, - "MESSAGE=%-*s: could not join netdev '%s': %s", - IFNAMSIZ, link->ifname, - link->network->bridge->ifname, - strerror(-r), - NETDEVIF(link->network->bridge), - NULL); + log_struct_errno(LOG_WARNING, r, + LOG_LINK_INTERFACE(link), + LOG_NETDEV_INTERFACE(link->network->bridge), + LOG_LINK_MESSAGE(link, "Could not join netdev '%s': %m", link->network->bridge->ifname), + NULL), link_enter_failed(link); return r; } @@ -1460,20 +1449,20 @@ static int link_enter_join_netdev(Link *link) { } HASHMAP_FOREACH(netdev, link->network->stacked_netdevs, i) { - log_link_struct(link, LOG_DEBUG, - "MESSAGE=%-*s: enslaving by '%s'", - IFNAMSIZ, link->ifname, - netdev->ifname, NETDEVIF(netdev), - NULL); - r = netdev_join(netdev, link, &netdev_join_handler); + log_struct(LOG_DEBUG, + LOG_LINK_INTERFACE(link), + LOG_NETDEV_INTERFACE(netdev), + LOG_LINK_MESSAGE(link, "Enslaving by '%s'", netdev->ifname), + NULL); + + r = netdev_join(netdev, link, netdev_join_handler); if (r < 0) { - log_link_struct(link, LOG_WARNING, - "MESSAGE=%-*s: could not join netdev '%s': %s", - IFNAMSIZ, link->ifname, - netdev->ifname, - strerror(-r), - NETDEVIF(netdev), NULL); + log_struct_errno(LOG_WARNING, r, + LOG_LINK_INTERFACE(link), + LOG_NETDEV_INTERFACE(netdev), + LOG_LINK_MESSAGE(link, "Could not join netdev '%s': %m", netdev->ifname), + NULL); link_enter_failed(link); return r; } diff --git a/src/network/networkd-link.h b/src/network/networkd-link.h index c3bc1b907b..c599952c45 100644 --- a/src/network/networkd-link.h +++ b/src/network/networkd-link.h @@ -141,14 +141,18 @@ DEFINE_TRIVIAL_CLEANUP_FUNC(Link*, link_unref); /* Macros which append INTERFACE= to the message */ -#define log_link_full(link, level, error, fmt, ...) \ - log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", link->ifname, "%-*s: " fmt, IFNAMSIZ, link->ifname, ##__VA_ARGS__) - -#define log_link_debug(link, ...) log_link_full(link, LOG_DEBUG, 0, ##__VA_ARGS__) -#define log_link_info(link, ...) log_link_full(link, LOG_INFO, 0, ##__VA_ARGS__) -#define log_link_notice(link, ...) log_link_full(link, LOG_NOTICE, 0, ##__VA_ARGS__) -#define log_link_warning(link, ...) log_link_full(link, LOG_WARNING, 0, ##__VA_ARGS__) -#define log_link_error(link, ...) log_link_full(link, LOG_ERR, 0, ##__VA_ARGS__) +#define log_link_full(link, level, error, ...) \ + ({ \ + Link *_l = (link); \ + _l ? log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", _l->ifname, ##__VA_ARGS__) : \ + log_internal(level, error, __FILE__, __LINE__, __func__, ##__VA_ARGS__); \ + }) \ + +#define log_link_debug(link, ...) log_link_full(link, LOG_DEBUG, 0, ##__VA_ARGS__) +#define log_link_info(link, ...) log_link_full(link, LOG_INFO, 0, ##__VA_ARGS__) +#define log_link_notice(link, ...) log_link_full(link, LOG_NOTICE, 0, ##__VA_ARGS__) +#define log_link_warning(link, ...) log_link_full(link, LOG_WARNING, 0, ##__VA_ARGS__) +#define log_link_error(link, ...) log_link_full(link, LOG_ERR, 0, ##__VA_ARGS__) #define log_link_debug_errno(link, error, ...) log_link_full(link, LOG_DEBUG, error, ##__VA_ARGS__) #define log_link_info_errno(link, error, ...) log_link_full(link, LOG_INFO, error, ##__VA_ARGS__) @@ -156,7 +160,8 @@ DEFINE_TRIVIAL_CLEANUP_FUNC(Link*, link_unref); #define log_link_warning_errno(link, error, ...) log_link_full(link, LOG_WARNING, error, ##__VA_ARGS__) #define log_link_error_errno(link, error, ...) log_link_full(link, LOG_ERR, error, ##__VA_ARGS__) -#define log_link_struct(link, level, ...) log_struct(level, "INTERFACE=%s", link->ifname, __VA_ARGS__) +#define LOG_LINK_MESSAGE(link, fmt, ...) "MESSAGE=%s: " fmt, (link)->ifname, ##__VA_ARGS__ +#define LOG_LINK_INTERFACE(link) "INTERFACE=%s", (link)->ifname #define ADDRESS_FMT_VAL(address) \ be32toh((address).s_addr) >> 24, \ diff --git a/src/network/networkd-netdev.h b/src/network/networkd-netdev.h index 8382606f1c..1ded495e4a 100644 --- a/src/network/networkd-netdev.h +++ b/src/network/networkd-netdev.h @@ -202,8 +202,12 @@ const struct ConfigPerfItem* network_netdev_gperf_lookup(const char *key, unsign /* Macros which append INTERFACE= to the message */ -#define log_netdev_full(netdev, level, error, fmt, ...) \ - log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", netdev->ifname, "%-*s: " fmt, IFNAMSIZ, netdev->ifname, ##__VA_ARGS__) +#define log_netdev_full(netdev, level, error, ...) \ + ({ \ + NetDev *_n = (netdev); \ + _n ? log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", _n->ifname, ##__VA_ARGS__) : \ + log_internal(level, error, __FILE__, __LINE__, __func__, ##__VA_ARGS__); \ + }) #define log_netdev_debug(netdev, ...) log_netdev_full(netdev, LOG_DEBUG, 0, ##__VA_ARGS__) #define log_netdev_info(netdev, ...) log_netdev_full(netdev, LOG_INFO, 0, ##__VA_ARGS__) @@ -217,6 +221,5 @@ const struct ConfigPerfItem* network_netdev_gperf_lookup(const char *key, unsign #define log_netdev_warning_errno(netdev, error, ...) log_netdev_full(netdev, LOG_WARNING, error, ##__VA_ARGS__) #define log_netdev_error_errno(netdev, error, ...) log_netdev_full(netdev, LOG_ERR, error, ##__VA_ARGS__) -#define log_netdev_struct(level, netdev, ...) log_struct(level, "INTERFACE=%s", netdev->ifname, __VA_ARGS__) - -#define NETDEVIF(netdev) "INTERFACE=%s", netdev->ifname +#define LOG_NETDEV_MESSAGE(netdev, fmt, ...) "MESSAGE=%s: " fmt, (netdev)->ifname, ##__VA_ARGS__ +#define LOG_NETDEV_INTERFACE(netdev) "INTERFACE=%s", (netdev)->ifname diff --git a/src/shared/log.c b/src/shared/log.c index e8b63a3ed9..6168a2955d 100644 --- a/src/shared/log.c +++ b/src/shared/log.c @@ -693,7 +693,8 @@ int log_object_internalv( va_list ap) { PROTECT_ERRNO; - char buffer[LINE_MAX]; + char *buffer, *b; + size_t l; if (error < 0) error = -error; @@ -705,7 +706,21 @@ int log_object_internalv( if (error != 0) errno = error; - vsnprintf(buffer, sizeof(buffer), format, ap); + /* Prepend the object name before the message */ + if (object) { + size_t n; + + n = strlen(object); + l = n + 2 + LINE_MAX; + + buffer = newa(char, l); + b = stpcpy(stpcpy(buffer, object), ": "); + } else { + l = LINE_MAX; + b = buffer = newa(char, l); + } + + vsnprintf(b, l, format, ap); return log_dispatch(level, error, file, line, func, object_field, object, buffer); } diff --git a/src/shared/log.h b/src/shared/log.h index 09d2fc767b..569762d083 100644 --- a/src/shared/log.h +++ b/src/shared/log.h @@ -204,7 +204,6 @@ LogTarget log_target_from_string(const char *s) _pure_; /* Helpers to prepare various fields for structured logging */ #define LOG_MESSAGE(fmt, ...) "MESSAGE=" fmt, ##__VA_ARGS__ #define LOG_MESSAGE_ID(x) "MESSAGE_ID=" SD_ID128_FORMAT_STR, SD_ID128_FORMAT_VAL(x) -#define LOG_ERRNO(error) "ERRNO=%i", abs(error) void log_received_signal(int level, const struct signalfd_siginfo *si); diff --git a/src/sysv-generator/sysv-generator.c b/src/sysv-generator/sysv-generator.c index 0c839c2c53..aecae801b7 100644 --- a/src/sysv-generator/sysv-generator.c +++ b/src/sysv-generator/sysv-generator.c @@ -31,10 +31,11 @@ #include "path-util.h" #include "path-lookup.h" #include "log.h" -#include "unit.h" #include "unit-name.h" #include "special.h" #include "hashmap.h" +#include "set.h" +#include "install.h" typedef enum RunlevelType { RUNLEVEL_UP, @@ -223,7 +224,7 @@ static int generate_unit_file(SysvStub *s) { STRV_FOREACH(p, s->wanted_by) { r = add_symlink(s->name, *p); if (r < 0) - log_unit_error_errno(s->name, r, "Failed to create 'Wants' symlink to %s: %m", *p); + log_error_errno(r, "Failed to create 'Wants' symlink to %s: %m", *p); } return 0; @@ -354,9 +355,7 @@ static int handle_provides(SysvStub *s, unsigned line, const char *full_text, co log_debug("Adding Provides: alias '%s' for '%s'", m, s->name); r = add_alias(s->name, m); if (r < 0) - log_unit_warning_errno(s->name, r, - "[%s:%u] Failed to add LSB Provides name %s, ignoring: %m", - s->path, line, m); + log_warning_errno(r, "[%s:%u] Failed to add LSB Provides name %s, ignoring: %m", s->path, line, m); } else { /* NB: SysV targets which are provided by a * service are pulled in by the services, as @@ -377,9 +376,7 @@ static int handle_provides(SysvStub *s, unsigned line, const char *full_text, co } } if (!isempty(state_)) - log_unit_error(s->name, - "[%s:%u] Trailing garbage in Provides, ignoring.", - s->path, line); + log_error("[%s:%u] Trailing garbage in Provides, ignoring.", s->path, line); return 0; } @@ -398,9 +395,7 @@ static int handle_dependencies(SysvStub *s, unsigned line, const char *full_text r = sysv_translate_facility(n, basename(s->path), &m); if (r < 0) { - log_unit_warning_errno(s->name, r, - "[%s:%u] Failed to translate LSB dependency %s, ignoring: %m", - s->path, line, n); + log_warning_errno(r, "[%s:%u] Failed to translate LSB dependency %s, ignoring: %m", s->path, line, n); continue; } if (r == 0) @@ -421,9 +416,7 @@ static int handle_dependencies(SysvStub *s, unsigned line, const char *full_text return log_oom(); } if (!isempty(state_)) - log_unit_warning(s->name, - "[%s:%u] Trailing garbage in %*s, ignoring.", - s->path, line, (int)(strchr(full_text, ':') - full_text), full_text); + log_warning("[%s:%u] Trailing garbage in %*s, ignoring.", s->path, line, (int)(strchr(full_text, ':') - full_text), full_text); return 0; } @@ -457,9 +450,7 @@ static int load_sysv(SysvStub *s) { if (feof(f)) break; - return log_unit_error_errno(s->name, errno, - "Failed to read configuration file '%s': %m", - s->path); + return log_error_errno(errno, "Failed to read configuration file '%s': %m", s->path); } line++; @@ -531,9 +522,7 @@ static int load_sysv(SysvStub *s) { fn = strstrip(t+8); if (!path_is_absolute(fn)) { - log_unit_error(s->name, - "[%s:%u] PID file not absolute. Ignoring.", - s->path, line); + log_error("[%s:%u] PID file not absolute. Ignoring.", s->path, line); continue; } |