picnoir
/
Systemd
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

systemd: use unit logging macros

This commit is contained in:
Zbigniew Jędrzejewski-Szmek 2013-01-05 12:00:35 -05:00
parent fdf9f9bbe4
commit 66870f90de
11 changed files with 665 additions and 335 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

66
src/core/automount.c
View File

@ -180,7 +180,7 @@ static int automount_verify(Automount *a) {
return 0;
if (path_equal(a->where, "/")) {
log_error("Cannot have an automount unit for the root directory. Refusing.");
log_error_unit(UNIT(a)->id, "Cannot have an automount unit for the root directory. Refusing.");
return -EINVAL;
}
@ -192,7 +192,7 @@ static int automount_verify(Automount *a) {
free(e);
if (!b) {
log_error("%s's Where setting doesn't match unit name. Refusing.", UNIT(a)->id);
log_error_unit(UNIT(a)->id, "%s's Where setting doesn't match unit name. Refusing.", UNIT(a)->id);
return -EINVAL;
}
@ -258,10 +258,11 @@ static void automount_set_state(Automount *a, AutomountState state) {
unmount_autofs(a);
if (state != old_state)
log_debug("%s changed %s -> %s",
UNIT(a)->id,
automount_state_to_string(old_state),
automount_state_to_string(state));
log_debug_unit(UNIT(a)->id,
"%s changed %s -> %s",
UNIT(a)->id,
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);
}
@ -455,9 +456,9 @@ int automount_send_ready(Automount *a, int status) {
}
if (status)
log_debug("Sending failure: %s", strerror(-status));
log_debug_unit(UNIT(a)->id, "Sending failure: %s", strerror(-status));
else
log_debug("Sending success.");
log_debug_unit(UNIT(a)->id, "Sending success.");
r = 0;
@ -579,7 +580,8 @@ fail:
if (mounted)
repeat_unmout(a->where);
log_error("Failed to initialize automounter: %s", strerror(-r));
log_error_unit(UNIT(a)->id,
"Failed to initialize automounter: %s", strerror(-r));
automount_enter_dead(a, AUTOMOUNT_FAILURE_RESOURCES);
}
@ -596,7 +598,8 @@ static void automount_enter_runnning(Automount *a) {
/* We don't take mount requests anymore if we are supposed to
* shut down anyway */
if (unit_pending_inactive(UNIT(a))) {
log_debug("Suppressing automount request on %s since unit stop is scheduled.", UNIT(a)->id);
log_debug_unit(UNIT(a)->id,
"Suppressing automount request on %s since unit stop is scheduled.", UNIT(a)->id);
automount_send_ready(a, -EHOSTDOWN);
return;
}
@ -605,14 +608,18 @@ 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_warning("%s failed to stat automount point: %m", UNIT(a)->id);
log_warning_unit(UNIT(a)->id,
"%s failed to stat automount point: %m", UNIT(a)->id);
goto fail;
}
if (!S_ISDIR(st.st_mode) || st.st_dev != a->dev_id)
log_info("%s's automount point already active?", UNIT(a)->id);
log_info_unit(UNIT(a)->id,
"%s's automount point already active?", UNIT(a)->id);
else if ((r = manager_add_job(UNIT(a)->manager, JOB_START, UNIT_DEREF(a->mount), JOB_REPLACE, true, &error, NULL)) < 0) {
log_warning("%s failed to queue mount startup job: %s", UNIT(a)->id, bus_error(&error, r));
log_warning_unit(UNIT(a)->id,
"%s failed to queue mount startup job: %s",
UNIT(a)->id, bus_error(&error, r));
goto fail;
}
@ -630,7 +637,9 @@ static int automount_start(Unit *u) {
assert(a->state == AUTOMOUNT_DEAD || a->state == AUTOMOUNT_FAILED);
if (path_is_mount_point(a->where, false)) {
log_error("Path %s is already a mount point, refusing start for %s", a->where, u->id);
log_error_unit(u->id,
"Path %s is already a mount point, refusing start for %s",
a->where, u->id);
return -EEXIST;
}
@ -693,7 +702,7 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu
state = automount_state_from_string(value);
if (state < 0)
log_debug("Failed to parse state value %s", value);
log_debug_unit(u->id, "Failed to parse state value %s", value);
else
a->deserialized_state = state;
} else if (streq(key, "result")) {
@ -701,7 +710,7 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu
f = automount_result_from_string(value);
if (f < 0)
log_debug("Failed to parse result value %s", value);
log_debug_unit(u->id, "Failed to parse result value %s", value);
else if (f != AUTOMOUNT_SUCCESS)
a->result = f;
@ -709,14 +718,14 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu
unsigned d;
if (safe_atou(value, &d) < 0)
log_debug("Failed to parse dev-id value %s", value);
log_debug_unit(u->id, "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_debug("Failed to parse token value %s", value);
log_debug_unit(u->id, "Failed to parse token value %s", value);
else {
if (!a->tokens)
if (!(a->tokens = set_new(trivial_hash_func, trivial_compare_func)))
@ -730,7 +739,7 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu
int fd;
if (safe_atoi(value, &fd) < 0 || fd < 0 || !fdset_contains(fds, fd))
log_debug("Failed to parse pipe-fd value %s", value);
log_debug_unit(u->id, "Failed to parse pipe-fd value %s", value);
else {
if (a->pipe_fd >= 0)
close_nointr_nofail(a->pipe_fd);
@ -738,7 +747,7 @@ static int automount_deserialize_item(Unit *u, const char *key, const char *valu
a->pipe_fd = fdset_remove(fds, fd);
}
} else
log_debug("Unknown serialization key '%s'", key);
log_debug_unit(u->id, "Unknown serialization key '%s'", key);
return 0;
}
@ -776,13 +785,13 @@ static void automount_fd_event(Unit *u, int fd, uint32_t events, Watch *w) {
assert(fd == a->pipe_fd);
if (events != EPOLLIN) {
log_error("Got invalid poll event on pipe.");
log_error_unit(u->id, "Got invalid poll event on pipe.");
goto fail;
}
l = loop_read(a->pipe_fd, &packet, sizeof(packet), true);
if (l != sizeof(packet)) {
log_error("Invalid read from pipe: %s", l < 0 ? strerror(-l) : "short read");
log_error_unit(u->id, "Invalid read from pipe: %s", l < 0 ? strerror(-l) : "short read");
goto fail;
}
@ -794,20 +803,21 @@ static void automount_fd_event(Unit *u, int fd, uint32_t events, Watch *w) {
_cleanup_free_ char *p = NULL;
get_process_comm(packet.v5_packet.pid, &p);
log_debug("Got direct mount request on %s, triggered by %lu (%s)",
a->where, (unsigned long) packet.v5_packet.pid, strna(p));
log_debug_unit(u->id,
"Got direct mount request on %s, triggered by %lu (%s)",
a->where, (unsigned long) packet.v5_packet.pid, strna(p));
} else
log_debug("Got direct mount request on %s", a->where);
log_debug_unit(u->id, "Got direct mount request on %s", a->where);
r = set_ensure_allocated(&a->tokens, trivial_hash_func, trivial_compare_func);
if (r < 0) {
log_error("Failed to allocate token set.");
log_error_unit(u->id, "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_error("Failed to remember token: %s", strerror(-r));
log_error_unit(u->id, "Failed to remember token: %s", strerror(-r));
goto fail;
}
@ -815,7 +825,7 @@ static void automount_fd_event(Unit *u, int fd, uint32_t events, Watch *w) {
break;
default:
log_error("Received unknown automount request %i", packet.hdr.type);
log_error_unit(u->id, "Received unknown automount request %i", packet.hdr.type);
break;
}

8
src/core/device.c
View File

@ -92,10 +92,10 @@ static void device_set_state(Device *d, DeviceState state) {
d->state = state;
if (state != old_state)
log_debug("%s changed %s -> %s",
UNIT(d)->id,
device_state_to_string(old_state),
device_state_to_string(state));
log_debug_unit(UNIT(d)->id,
"%s changed %s -> %s", UNIT(d)->id,
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);
}

46
src/core/job.c
View File

@ -187,8 +187,9 @@ Job* job_install(Job *j) {
if (j->type == JOB_NOP || 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_debug("Merged into installed job %s/%s as %u",
uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id);
log_debug_unit(uj->unit->id,
"Merged into installed job %s/%s as %u",
uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id);
return uj;
} else {
/* already running and not safe to merge into */
@ -196,8 +197,9 @@ 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_debug("Merged into running job, re-running: %s/%s as %u",
uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id);
log_debug_unit(uj->unit->id,
"Merged into running job, re-running: %s/%s as %u",
uj->unit->id, job_type_to_string(uj->type), (unsigned) uj->id);
uj->state = JOB_WAITING;
return uj;
}
@ -208,7 +210,9 @@ Job* job_install(Job *j) {
*pj = j;
j->installed = true;
j->manager->n_installed_jobs ++;
log_debug("Installed new job %s/%s as %u", j->unit->id, job_type_to_string(j->type), (unsigned) j->id);
log_debug_unit(j->unit->id,
"Installed new job %s/%s as %u",
j->unit->id, job_type_to_string(j->type), (unsigned) j->id);
return j;
}
@ -225,12 +229,16 @@ int job_install_deserialized(Job *j) {
pj = (j->type == JOB_NOP) ? &j->unit->nop_job : &j->unit->job;
if (*pj) {
log_debug("Unit %s already has a job installed. Not installing deserialized job.", j->unit->id);
log_debug_unit(j->unit->id,
"Unit %s already has a job installed. Not installing deserialized job.",
j->unit->id);
return -EEXIST;
}
*pj = j;
j->installed = true;
log_debug("Reinstalled deserialized job %s/%s as %u", j->unit->id, job_type_to_string(j->type), (unsigned) j->id);
log_debug_unit(j->unit->id,
"Reinstalled deserialized job %s/%s as %u",
j->unit->id, job_type_to_string(j->type), (unsigned) j->id);
return 0;
}
@ -457,9 +465,10 @@ bool job_is_runnable(Job *j) {
}
static void job_change_type(Job *j, JobType newtype) {
log_debug("Converting job %s/%s -> %s/%s",
j->unit->id, job_type_to_string(j->type),
j->unit->id, job_type_to_string(newtype));
log_debug_unit(j->unit->id,
"Converting job %s/%s -> %s/%s",
j->unit->id, job_type_to_string(j->type),
j->unit->id, job_type_to_string(newtype));
j->type = newtype;
}
@ -744,7 +753,8 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) {
j->result = result;
log_debug("Job %s/%s finished, result=%s", u->id, job_type_to_string(t), job_result_to_string(result));
log_debug_unit(u->id, "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);
@ -804,14 +814,19 @@ int job_finish_and_invalidate(Job *j, JobResult result, bool recursive) {
}
/* Trigger OnFailure dependencies that are not generated by
* the unit itself. We don't tread JOB_CANCELED as failure in
* the unit itself. We don't treat JOB_CANCELED as failure in
* this context. And JOB_FAILURE is already handled by the
* unit itself. */
if (result == JOB_TIMEOUT || result == JOB_DEPENDENCY) {
log_notice("Job %s/%s failed with result '%s'.",
log_struct(LOG_NOTICE,
"UNIT=%s", u->id,
"JOB_TYPE=%s", job_type_to_string(t),
"JOB_RESULT=%s", job_result_to_string(t),
"Job %s/%s failed with result '%s'.",
u->id,
job_type_to_string(t),
job_result_to_string(result));
job_result_to_string(result),
NULL);
unit_trigger_on_failure(u);
}
@ -918,7 +933,8 @@ void job_timer_event(Job *j, uint64_t n_elapsed, Watch *w) {
assert(j);
assert(w == &j->timer_watch);
log_warning("Job %s/%s timed out.", j->unit->id, job_type_to_string(j->type));
log_warning_unit(j->unit->id, "Job %s/%s timed out.",
j->unit->id, job_type_to_string(j->type));
job_finish_and_invalidate(j, JOB_TIMEOUT, true);
}

23
src/core/manager.c
View File

@ -487,7 +487,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) {
log_debug("Collecting %s", u->id);
log_debug_unit(u->id, "Collecting %s", u->id);
u->gc_marker = gc_marker + GC_OFFSET_BAD;
unit_add_to_cleanup_queue(u);
}
@ -749,7 +749,9 @@ int manager_add_job(Manager *m, JobType type, Unit *unit, JobMode mode, bool ove
return -EPERM;
}
log_debug("Trying to enqueue job %s/%s/%s", unit->id, job_type_to_string(type), job_mode_to_string(mode));
log_debug_unit(unit->id,
"Trying to enqueue job %s/%s/%s", unit->id,
job_type_to_string(type), job_mode_to_string(mode));
job_type_collapse(&type, unit);
@ -773,7 +775,9 @@ int manager_add_job(Manager *m, JobType type, Unit *unit, JobMode mode, bool ove
if (r < 0)
goto tr_abort;
log_debug("Enqueued job %s/%s as %u", unit->id, job_type_to_string(type), (unsigned) tr->anchor_job->id);
log_debug_unit(unit->id,
"Enqueued job %s/%s as %u", unit->id,
job_type_to_string(type), (unsigned) tr->anchor_job->id);
if (_ret)
*_ret = tr->anchor_job;
@ -1070,7 +1074,7 @@ static int manager_process_notify_fd(Manager *m) {
if (!tags)
return log_oom();
log_debug("Got notification message for unit %s", u->id);
log_debug_unit(u->id, "Got notification message for unit %s", u->id);
if (UNIT_VTABLE(u)->notify_message)
UNIT_VTABLE(u)->notify_message(u, ucred->pid, tags);
@ -1150,7 +1154,8 @@ static int manager_dispatch_sigchld(Manager *m) {
if (!u)
continue;
log_debug("Child %lu belongs to %s", (long unsigned) si.si_pid, u->id);
log_debug_unit(u->id,
"Child %lu belongs to %s", (long unsigned) si.si_pid, u->id);
hashmap_remove(m->watch_pids, LONG_TO_PTR(si.si_pid));
UNIT_VTABLE(u)->sigchld_event(u, si.si_pid, si.si_code, si.si_status);
@ -1165,11 +1170,12 @@ static int manager_start_target(Manager *m, const char *name, JobMode mode) {
dbus_error_init(&error);
log_debug("Activating special unit %s", name);
log_debug_unit(name, "Activating special unit %s", name);
r = manager_add_job_by_name(m, JOB_START, name, mode, true, &error, NULL);
if (r < 0)
log_error("Failed to enqueue %s job: %s", name, bus_error(&error, r));
log_error_unit(name,
"Failed to enqueue %s job: %s", name, bus_error(&error, r));
dbus_error_free(&error);
@ -1677,7 +1683,8 @@ void manager_send_unit_audit(Manager *m, Unit *u, int type, bool success) {
p = unit_name_to_prefix_and_instance(u->id);
if (!p) {
log_error("Failed to allocate unit name for audit message: %s", strerror(ENOMEM));
log_error_unit(u->id,
"Failed to allocate unit name for audit message: %s", strerror(ENOMEM));
return;
}

110
src/core/mount.c
View File

@ -387,7 +387,8 @@ static int mount_add_device_links(Mount *m) {
r = manager_load_unit_prepare(UNIT(m)->manager, name, NULL, NULL, &fsck);
if (r < 0) {
log_warning("Failed to prepare unit %s: %s", name, strerror(-r));
log_warning_unit(name,
"Failed to prepare unit %s: %s", name, strerror(-r));
free(name);
return r;
}
@ -498,7 +499,9 @@ static int mount_fix_timeouts(Mount *m) {
free(t);
if (r < 0) {
log_warning("Failed to parse timeout for %s, ignoring: %s", m->where, timeout);
log_warning_unit(UNIT(m)->id,
"Failed to parse timeout for %s, ignoring: %s",
m->where, timeout);
return r;
}
@ -530,22 +533,29 @@ static int mount_verify(Mount *m) {
free(e);
if (!b) {
log_error("%s's Where setting doesn't match unit name. Refusing.", UNIT(m)->id);
log_error_unit(UNIT(m)->id,
"%s's Where setting doesn't match unit name. Refusing.",
UNIT(m)->id);
return -EINVAL;
}
if (mount_point_is_api(m->where) || mount_point_ignore(m->where)) {
log_error("Cannot create mount unit for API file system %s. Refusing.", m->where);
log_error_unit(UNIT(m)->id,
"Cannot create mount unit for API file system %s. Refusing.",
m->where);
return -EINVAL;
}
if (UNIT(m)->fragment_path && !m->parameters_fragment.what) {
log_error("%s's What setting is missing. Refusing.", UNIT(m)->id);
log_error_unit(UNIT(m)->id,
"%s's What setting is missing. Refusing.", UNIT(m)->id);
return -EBADMSG;
}
if (m->exec_context.pam_name && m->kill_context.kill_mode != KILL_CONTROL_GROUP) {
log_error("%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing.", UNIT(m)->id);
log_error_unit(UNIT(m)->id,
"%s has PAM enabled. Kill mode must be set to control-group'. Refusing.",
UNIT(m)->id);
return -EINVAL;
}
@ -712,10 +722,11 @@ static void mount_set_state(Mount *m, MountState state) {
}
if (state != old_state)
log_debug("%s changed %s -> %s",
UNIT(m)->id,
mount_state_to_string(old_state),
mount_state_to_string(state));
log_debug_unit(UNIT(m)->id,
"%s changed %s -> %s",
UNIT(m)->id,
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;
@ -882,7 +893,9 @@ static void mount_enter_signal(Mount *m, MountState state, MountResult f) {
if (m->control_pid > 0) {
if (kill_and_sigcont(m->control_pid, sig) < 0 && errno != ESRCH)
log_warning("Failed to kill control process %li: %m", (long) m->control_pid);
log_warning_unit(UNIT(m)->id,
"Failed to kill control process %li: %m",
(long) m->control_pid);
else
wait_for_exit = true;
}
@ -902,7 +915,9 @@ static void mount_enter_signal(Mount *m, MountState state, MountResult f) {
r = cgroup_bonding_kill_list(UNIT(m)->cgroup_bondings, sig, true, false, pid_set, NULL);
if (r < 0) {
if (r != -EAGAIN && r != -ESRCH && r != -ENOENT)
log_warning("Failed to kill control group: %s", strerror(-r));
log_warning_unit(UNIT(m)->id,
"Failed to kill control group: %s",
strerror(-r));
} else if (r > 0)
wait_for_exit = true;
@ -925,7 +940,8 @@ static void mount_enter_signal(Mount *m, MountState state, MountResult f) {
return;
fail:
log_warning("%s failed to kill processes: %s", UNIT(m)->id, strerror(-r));
log_warning_unit(UNIT(m)->id,
"%s failed to kill processes: %s", UNIT(m)->id, strerror(-r));
if (state == MOUNT_REMOUNTING_SIGTERM || state == MOUNT_REMOUNTING_SIGKILL)
mount_enter_mounted(m, MOUNT_FAILURE_RESOURCES);
@ -973,7 +989,9 @@ static void mount_enter_unmounting(Mount *m) {
return;
fail:
log_warning("%s failed to run 'umount' task: %s", UNIT(m)->id, strerror(-r));
log_warning_unit(UNIT(m)->id,
"%s failed to run 'umount' task: %s",
UNIT(m)->id, strerror(-r));
mount_enter_mounted(m, MOUNT_FAILURE_RESOURCES);
}
@ -1021,7 +1039,9 @@ static void mount_enter_mounting(Mount *m) {
return;
fail:
log_warning("%s failed to run 'mount' task: %s", UNIT(m)->id, strerror(-r));
log_warning_unit(UNIT(m)->id,
"%s failed to run 'mount' task: %s",
UNIT(m)->id, strerror(-r));
mount_enter_dead(m, MOUNT_FAILURE_RESOURCES);
}
@ -1079,7 +1099,9 @@ static void mount_enter_remounting(Mount *m) {
return;
fail:
log_warning("%s failed to run 'remount' task: %s", UNIT(m)->id, strerror(-r));
log_warning_unit(UNIT(m)->id,
"%s failed to run 'remount' task: %s",
UNIT(m)->id, strerror(-r));
m->reload_result = MOUNT_FAILURE_RESOURCES;
mount_enter_mounted(m, MOUNT_SUCCESS);
}
@ -1181,7 +1203,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_debug("Failed to parse state value %s", value);
log_debug_unit(u->id, "Failed to parse state value %s", value);
else
m->deserialized_state = state;
} else if (streq(key, "result")) {
@ -1189,7 +1211,8 @@ static int mount_deserialize_item(Unit *u, const char *key, const char *value, F
f = mount_result_from_string(value);
if (f < 0)
log_debug("Failed to parse result value %s", value);
log_debug_unit(UNIT(m)->id,
"Failed to parse result value %s", value);
else if (f != MOUNT_SUCCESS)
m->result = f;
@ -1198,7 +1221,8 @@ static int mount_deserialize_item(Unit *u, const char *key, const char *value, F
f = mount_result_from_string(value);
if (f < 0)
log_debug("Failed to parse reload result value %s", value);
log_debug_unit(UNIT(m)->id,
"Failed to parse reload result value %s", value);
else if (f != MOUNT_SUCCESS)
m->reload_result = f;
@ -1206,21 +1230,24 @@ static int mount_deserialize_item(Unit *u, const char *key, const char *value, F
pid_t pid;
if (parse_pid(value, &pid) < 0)
log_debug("Failed to parse control-pid value %s", value);
log_debug_unit(UNIT(m)->id,
"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_debug("Failed to parse exec-command value %s", value);
log_debug_unit(UNIT(m)->id,
"Failed to parse exec-command value %s", value);
else {
m->control_command_id = id;
m->control_command = m->exec_command + id;
}
} else
log_debug("Unknown serialization key '%s'", key);
log_debug_unit(UNIT(m)->id,
"Unknown serialization key '%s'", key);
return 0;
}
@ -1278,8 +1305,9 @@ static void mount_sigchld_event(Unit *u, pid_t pid, int code, int status) {
m->control_command_id = _MOUNT_EXEC_COMMAND_INVALID;
}
log_full(f == MOUNT_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
"%s mount process exited, code=%s status=%i", u->id, sigchld_code_to_string(code), status);
log_full_unit(f == MOUNT_SUCCESS ? LOG_DEBUG : LOG_NOTICE, u->id,
"%s mount process exited, code=%s status=%i",
u->id, 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
@ -1346,27 +1374,33 @@ static void mount_timer_event(Unit *u, uint64_t elapsed, Watch *w) {
case MOUNT_MOUNTING:
case MOUNT_MOUNTING_DONE:
log_warning("%s mounting timed out. Stopping.", u->id);
log_warning_unit(u->id,
"%s mounting timed out. Stopping.", u->id);
mount_enter_signal(m, MOUNT_MOUNTING_SIGTERM, MOUNT_FAILURE_TIMEOUT);
break;
case MOUNT_REMOUNTING:
log_warning("%s remounting timed out. Stopping.", u->id);
log_warning_unit(u->id,
"%s remounting timed out. Stopping.", u->id);
m->reload_result = MOUNT_FAILURE_TIMEOUT;
mount_enter_mounted(m, MOUNT_SUCCESS);
break;
case MOUNT_UNMOUNTING:
log_warning("%s unmounting timed out. Stopping.", u->id);
log_warning_unit(u->id,
"%s unmounting timed out. Stopping.", u->id);
mount_enter_signal(m, MOUNT_UNMOUNTING_SIGTERM, MOUNT_FAILURE_TIMEOUT);
break;
case MOUNT_MOUNTING_SIGTERM:
if (m->kill_context.send_sigkill) {
log_warning("%s mounting timed out. Killing.", u->id);
log_warning_unit(u->id,
"%s mounting timed out. Killing.", u->id);
mount_enter_signal(m, MOUNT_MOUNTING_SIGKILL, MOUNT_FAILURE_TIMEOUT);
} else {
log_warning("%s mounting timed out. Skipping SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s mounting timed out. Skipping SIGKILL. Ignoring.",
u->id);
if (m->from_proc_self_mountinfo)
mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT);
@ -1377,10 +1411,13 @@ static void mount_timer_event(Unit *u, uint64_t elapsed, Watch *w) {
case MOUNT_REMOUNTING_SIGTERM:
if (m->kill_context.send_sigkill) {
log_warning("%s remounting timed out. Killing.", u->id);
log_warning_unit(u->id,
"%s remounting timed out. Killing.", u->id);
mount_enter_signal(m, MOUNT_REMOUNTING_SIGKILL, MOUNT_FAILURE_TIMEOUT);
} else {
log_warning("%s remounting timed out. Skipping SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s remounting timed out. Skipping SIGKILL. Ignoring.",
u->id);
if (m->from_proc_self_mountinfo)
mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT);
@ -1391,10 +1428,13 @@ static void mount_timer_event(Unit *u, uint64_t elapsed, Watch *w) {
case MOUNT_UNMOUNTING_SIGTERM:
if (m->kill_context.send_sigkill) {
log_warning("%s unmounting timed out. Killing.", u->id);
log_warning_unit(u->id,
"%s unmounting timed out. Killing.", u->id);
mount_enter_signal(m, MOUNT_UNMOUNTING_SIGKILL, MOUNT_FAILURE_TIMEOUT);
} else {
log_warning("%s unmounting timed out. Skipping SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s unmounting timed out. Skipping SIGKILL. Ignoring.",
u->id);
if (m->from_proc_self_mountinfo)
mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT);
@ -1406,7 +1446,9 @@ static void mount_timer_event(Unit *u, uint64_t elapsed, Watch *w) {
case MOUNT_MOUNTING_SIGKILL:
case MOUNT_REMOUNTING_SIGKILL:
case MOUNT_UNMOUNTING_SIGKILL:
log_warning("%s mount process still around after SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s mount process still around after SIGKILL. Ignoring.",
u->id);
if (m->from_proc_self_mountinfo)
mount_enter_mounted(m, MOUNT_FAILURE_TIMEOUT);

3
src/core/path.c
View File

@ -307,7 +307,8 @@ static int path_verify(Path *p) {
return 0;
if (!p->specs) {
log_error("%s lacks path setting. Refusing.", UNIT(p)->id);
log_error_unit(UNIT(p)->id,
"%s lacks path setting. Refusing.", UNIT(p)->id);
return -EINVAL;
}

310
src/core/service.c
View File

@ -169,7 +169,8 @@ static void service_unwatch_pid_file(Service *s) {
if (!s->pid_file_pathspec)
return;
log_debug("Stopping watch for %s's PID file %s", UNIT(s)->id, s->pid_file_pathspec->path);
log_debug_unit(UNIT(s)->id, "Stopping watch for %s's PID file %s",
UNIT(s)->id, s->pid_file_pathspec->path);
path_spec_unwatch(s->pid_file_pathspec, UNIT(s));
path_spec_done(s->pid_file_pathspec);
free(s->pid_file_pathspec);
@ -191,8 +192,9 @@ 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_warning("%s: Supervising process %lu which is not our child. We'll most likely not notice when it exits.",
UNIT(s)->id, (unsigned long) pid);
log_warning_unit(UNIT(s)->id,
"%s: Supervising process %lu which is not our child. We'll most likely not notice when it exits.",
UNIT(s)->id, (unsigned long) pid);
s->main_pid_alien = true;
} else
@ -244,14 +246,16 @@ static void service_handle_watchdog(Service *s) {
offset = now(CLOCK_MONOTONIC) - s->watchdog_timestamp.monotonic;
if (offset >= s->watchdog_usec) {
log_error("%s watchdog timeout!", UNIT(s)->id);
log_error_unit(UNIT(s)->id, "%s watchdog timeout!", UNIT(s)->id);
service_enter_dead(s, SERVICE_FAILURE_WATCHDOG, true);
return;
}
r = unit_watch_timer(UNIT(s), CLOCK_MONOTONIC, true, s->watchdog_usec - offset, &s->watchdog_watch);
if (r < 0)
log_warning("%s failed to install watchdog timer: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to install watchdog timer: %s",
UNIT(s)->id, strerror(-r));
}
static void service_reset_watchdog(Service *s) {
@ -581,7 +585,9 @@ static int service_load_sysv_path(Service *s, const char *path) {
break;
r = -errno;
log_error("Failed to read configuration file '%s': %s", path, strerror(-r));
log_error_unit(u->id,
"Failed to read configuration file '%s': %s",
path, strerror(-r));
goto finish;
}
@ -634,7 +640,9 @@ static int service_load_sysv_path(Service *s, const char *path) {
runlevels,
&start_priority) != 2) {
log_warning("[%s:%u] Failed to parse chkconfig line. Ignoring.", path, line);
log_warning_unit(u->id,
"[%s:%u] Failed to parse chkconfig line. Ignoring.",
path, line);
continue;
}
@ -642,7 +650,9 @@ static int service_load_sysv_path(Service *s, const char *path) {
* symlink farms is preferred over the
* data from the LSB header. */
if (start_priority < 0 || start_priority > 99)
log_warning("[%s:%u] Start priority out of range. Ignoring.", path, line);
log_warning_unit(u->id,
"[%s:%u] Start priority out of range. Ignoring.",
path, line);
else
s->sysv_start_priority = start_priority;
@ -691,7 +701,9 @@ static int service_load_sysv_path(Service *s, const char *path) {
fn = strstrip(t+8);
if (!path_is_absolute(fn)) {
log_warning("[%s:%u] PID file not absolute. Ignoring.", path, line);
log_warning_unit(u->id,
"[%s:%u] PID file not absolute. Ignoring.",
path, line);
continue;
}
@ -778,7 +790,9 @@ static int service_load_sysv_path(Service *s, const char *path) {
r = unit_add_two_dependencies_by_name(u, UNIT_BEFORE, UNIT_WANTS, m, NULL, true);
if (r < 0)
log_error("[%s:%u] Failed to add LSB Provides name %s, ignoring: %s", path, line, m, strerror(-r));
log_error_unit(u->id,
"[%s:%u] Failed to add LSB Provides name %s, ignoring: %s",
path, line, m, strerror(-r));
free(m);
}
@ -803,7 +817,9 @@ static int service_load_sysv_path(Service *s, const char *path) {
r = sysv_translate_facility(n, path_get_file_name(path), &m);
if (r < 0) {
log_error("[%s:%u] Failed to translate LSB dependency %s, ignoring: %s", path, line, n, strerror(-r));
log_error_unit(u->id,
"[%s:%u] Failed to translate LSB dependency %s, ignoring: %s",
path, line, n, strerror(-r));
free(n);
continue;
}
@ -816,7 +832,8 @@ static int service_load_sysv_path(Service *s, const char *path) {
r = unit_add_dependency_by_name(u, startswith_no_case(t, "X-Start-Before:") ? UNIT_BEFORE : UNIT_AFTER, m, NULL, true);
if (r < 0)
log_error("[%s:%u] Failed to add dependency on %s, ignoring: %s", path, line, m, strerror(-r));
log_error_unit(u->id, "[%s:%u] Failed to add dependency on %s, ignoring: %s",
path, line, m, strerror(-r));
free(m);
}
@ -1105,26 +1122,31 @@ static int service_verify(Service *s) {
return 0;
if (!s->exec_command[SERVICE_EXEC_START]) {
log_error("%s lacks ExecStart setting. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s lacks ExecStart setting. Refusing.", UNIT(s)->id);
return -EINVAL;
}
if (s->type != SERVICE_ONESHOT &&
s->exec_command[SERVICE_EXEC_START]->command_next) {
log_error("%s has more than one ExecStart setting, which is only allowed for Type=oneshot services. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s has more than one ExecStart setting, which is only allowed for Type=oneshot services. Refusing.", UNIT(s)->id);
return -EINVAL;
}
if (s->type == SERVICE_DBUS && !s->bus_name) {
log_error("%s is of type D-Bus but no D-Bus service name has been specified. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s is of type D-Bus but no D-Bus service name has been specified. Refusing.", UNIT(s)->id);
return -EINVAL;
}
if (s->bus_name && s->type != SERVICE_DBUS)
log_warning("%s has a D-Bus service name specified, but is not of type dbus. Ignoring.", UNIT(s)->id);
log_warning_unit(UNIT(s)->id,
"%s has a D-Bus service name specified, but is not of type dbus. Ignoring.", UNIT(s)->id);
if (s->exec_context.pam_name && s->kill_context.kill_mode != KILL_CONTROL_GROUP) {
log_error("%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing.", UNIT(s)->id);
return -EINVAL;
}
@ -1366,8 +1388,9 @@ static int service_load_pid_file(Service *s, bool may_warn) {
if ((r = read_one_line_file(s->pid_file, &k)) < 0) {
if (may_warn)
log_info("PID file %s not readable (yet?) after %s.",
s->pid_file, service_state_to_string(s->state));
log_info_unit(UNIT(s)->id,
"PID file %s not readable (yet?) after %s.",
s->pid_file, service_state_to_string(s->state));
return r;
}
@ -1379,8 +1402,9 @@ static int service_load_pid_file(Service *s, bool may_warn) {
if (kill(pid, 0) < 0 && errno != EPERM) {
if (may_warn)
log_info("PID %lu read from file %s does not exist.",
(unsigned long) pid, s->pid_file);
log_info_unit(UNIT(s)->id,
"PID %lu read from file %s does not exist.",
(unsigned long) pid, s->pid_file);
return -ESRCH;
}
@ -1388,12 +1412,14 @@ static int service_load_pid_file(Service *s, bool may_warn) {
if (pid == s->main_pid)
return 0;
log_debug("Main PID changing: %lu -> %lu",
(unsigned long) s->main_pid, (unsigned long) pid);
log_debug_unit(UNIT(s)->id,
"Main PID changing: %lu -> %lu",
(unsigned long) s->main_pid, (unsigned long) pid);
service_unwatch_main_pid(s);
s->main_pid_known = false;
} else
log_debug("Main PID loaded: %lu", (unsigned long) pid);
log_debug_unit(UNIT(s)->id,
"Main PID loaded: %lu", (unsigned long) pid);
if ((r = service_set_main_pid(s, pid)) < 0)
return r;
@ -1424,7 +1450,8 @@ static int service_search_main_pid(Service *s) {
if ((pid = cgroup_bonding_search_main_pid_list(UNIT(s)->cgroup_bondings)) <= 0)
return -ENOENT;
log_debug("Main PID guessed: %lu", (unsigned long) pid);
log_debug_unit(UNIT(s)->id,
"Main PID guessed: %lu", (unsigned long) pid);
if ((r = service_set_main_pid(s, pid)) < 0)
return r;
@ -1540,12 +1567,10 @@ static void service_set_state(Service *s, ServiceState state) {
cgroup_bonding_trim_list(UNIT(s)->cgroup_bondings, true);
if (old_state != state)
log_struct(LOG_DEBUG,
"UNIT=%s", UNIT(s)->id,
"MESSAGE=%s changed %s -> %s", UNIT(s)->id,
service_state_to_string(old_state),
service_state_to_string(state),
NULL);
log_debug_unit(UNIT(s)->id,
"%s changed %s -> %s", UNIT(s)->id,
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;
@ -1889,7 +1914,9 @@ static void service_enter_dead(Service *s, ServiceResult f, bool allow_restart)
return;
fail:
log_warning("%s failed to run install restart timer: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run install restart timer: %s",
UNIT(s)->id, strerror(-r));
service_enter_dead(s, SERVICE_FAILURE_RESOURCES, false);
}
@ -1928,7 +1955,9 @@ static void service_enter_stop_post(Service *s, ServiceResult f) {
return;
fail:
log_warning("%s failed to run 'stop-post' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'stop-post' task: %s",
UNIT(s)->id, strerror(-r));
service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_RESOURCES);
}
@ -1947,14 +1976,16 @@ static void service_enter_signal(Service *s, ServiceState state, ServiceResult f
if (s->main_pid > 0) {
if (kill_and_sigcont(s->main_pid, sig) < 0 && errno != ESRCH)
log_warning("Failed to kill main process %li: %m", (long) s->main_pid);
log_warning_unit(UNIT(s)->id,
"Failed to kill main process %li: %m", (long) s->main_pid);
else
wait_for_exit = !s->main_pid_alien;
}
if (s->control_pid > 0) {
if (kill_and_sigcont(s->control_pid, sig) < 0 && errno != ESRCH)
log_warning("Failed to kill control process %li: %m", (long) s->control_pid);
log_warning_unit(UNIT(s)->id,
"Failed to kill control process %li: %m", (long) s->control_pid);
else
wait_for_exit = true;
}
@ -1979,7 +2010,8 @@ static void service_enter_signal(Service *s, ServiceState state, ServiceResult f
r = cgroup_bonding_kill_list(UNIT(s)->cgroup_bondings, sig, true, false, pid_set, NULL);
if (r < 0) {
if (r != -EAGAIN && r != -ESRCH && r != -ENOENT)
log_warning("Failed to kill control group: %s", strerror(-r));
log_warning_unit(UNIT(s)->id,
"Failed to kill control group: %s", strerror(-r));
} else if (r > 0)
wait_for_exit = true;
@ -2004,7 +2036,8 @@ static void service_enter_signal(Service *s, ServiceState state, ServiceResult f
return;
fail:
log_warning("%s failed to kill processes: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to kill processes: %s", UNIT(s)->id, strerror(-r));
if (state == SERVICE_STOP_SIGTERM || state == SERVICE_STOP_SIGKILL)
service_enter_stop_post(s, SERVICE_FAILURE_RESOURCES);
@ -2048,7 +2081,8 @@ static void service_enter_stop(Service *s, ServiceResult f) {
return;
fail:
log_warning("%s failed to run 'stop' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'stop' task: %s", UNIT(s)->id, strerror(-r));
service_enter_signal(s, SERVICE_STOP_SIGTERM, SERVICE_FAILURE_RESOURCES);
}
@ -2103,7 +2137,8 @@ static void service_enter_start_post(Service *s) {
return;
fail:
log_warning("%s failed to run 'start-post' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'start-post' task: %s", UNIT(s)->id, strerror(-r));
service_enter_stop(s, SERVICE_FAILURE_RESOURCES);
}
@ -2186,7 +2221,8 @@ static void service_enter_start(Service *s) {
return;
fail:
log_warning("%s failed to run 'start' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'start' task: %s", UNIT(s)->id, strerror(-r));
service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_RESOURCES);
}
@ -2225,7 +2261,8 @@ static void service_enter_start_pre(Service *s) {
return;
fail:
log_warning("%s failed to run 'start-pre' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'start-pre' task: %s", UNIT(s)->id, strerror(-r));
service_enter_dead(s, SERVICE_FAILURE_RESOURCES, true);
}
@ -2238,7 +2275,8 @@ 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_info("Stop job pending for unit, delaying automatic restart.");
log_info_unit(UNIT(s)->id,
"Stop job pending for unit, delaying automatic restart.");
r = unit_watch_timer(UNIT(s), CLOCK_MONOTONIC, true, s->restart_usec, &s->timer_watch);
if (r < 0)
@ -2259,11 +2297,14 @@ 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_debug("%s scheduled restart job.", UNIT(s)->id);
log_debug_unit(UNIT(s)->id,
"%s scheduled restart job.", UNIT(s)->id);
return;
fail:
log_warning("%s failed to schedule restart job: %s", UNIT(s)->id, bus_error(&error, -r));
log_warning_unit(UNIT(s)->id,
"%s failed to schedule restart job: %s",
UNIT(s)->id, bus_error(&error, -r));
service_enter_dead(s, SERVICE_FAILURE_RESOURCES, false);
dbus_error_free(&error);
@ -2299,7 +2340,9 @@ static void service_enter_reload(Service *s) {
return;
fail:
log_warning("%s failed to run 'reload' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'reload' task: %s",
UNIT(s)->id, strerror(-r));
s->reload_result = SERVICE_FAILURE_RESOURCES;
service_enter_running(s, SERVICE_SUCCESS);
}
@ -2333,7 +2376,9 @@ static void service_run_next_control(Service *s) {
return;
fail:
log_warning("%s failed to run next control task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run next control task: %s",
UNIT(s)->id, strerror(-r));
if (s->state == SERVICE_START_PRE)
service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_RESOURCES);
@ -2378,7 +2423,8 @@ static void service_run_next_main(Service *s) {
return;
fail:
log_warning("%s failed to run next main task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run next main task: %s", UNIT(s)->id, strerror(-r));
service_enter_stop(s, SERVICE_FAILURE_RESOURCES);
}
@ -2391,7 +2437,9 @@ static int service_start_limit_test(Service *s) {
switch (s->start_limit_action) {
case SERVICE_START_LIMIT_NONE:
log_warning("%s start request repeated too quickly, refusing to start.", UNIT(s)->id);
log_warning_unit(UNIT(s)->id,
"%s start request repeated too quickly, refusing to start.",
UNIT(s)->id);
break;
case SERVICE_START_LIMIT_REBOOT: {
@ -2400,11 +2448,13 @@ static int service_start_limit_test(Service *s) {
dbus_error_init(&error);
log_warning("%s start request repeated too quickly, rebooting.", UNIT(s)->id);
log_warning_unit(UNIT(s)->id,
"%s start request repeated too quickly, rebooting.", UNIT(s)->id);
r = manager_add_job_by_name(UNIT(s)->manager, JOB_START, SPECIAL_REBOOT_TARGET, JOB_REPLACE, true, &error, NULL);
if (r < 0) {
log_error("Failed to reboot: %s.", bus_error(&error, r));
log_error_unit(UNIT(s)->id,
"Failed to reboot: %s.", bus_error(&error, r));
dbus_error_free(&error);
}
@ -2412,18 +2462,21 @@ static int service_start_limit_test(Service *s) {
}
case SERVICE_START_LIMIT_REBOOT_FORCE:
log_warning("%s start request repeated too quickly, forcibly rebooting.", UNIT(s)->id);
log_warning_unit(UNIT(s)->id,
"%s start request repeated too quickly, forcibly rebooting.", UNIT(s)->id);
UNIT(s)->manager->exit_code = MANAGER_REBOOT;
break;
case SERVICE_START_LIMIT_REBOOT_IMMEDIATE:
log_warning("%s start request repeated too quickly, rebooting immediately.", UNIT(s)->id);
log_warning_unit(UNIT(s)->id,
"%s start request repeated too quickly, rebooting immediately.", UNIT(s)->id);
sync();
reboot(RB_AUTOBOOT);
break;
default:
log_error("start limit action=%i", s->start_limit_action);
log_error_unit(UNIT(s)->id,
"start limit action=%i", s->start_limit_action);
assert_not_reached("Unknown StartLimitAction.");
}
@ -2605,7 +2658,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value,
ServiceState state;
if ((state = service_state_from_string(value)) < 0)
log_debug("Failed to parse state value %s", value);
log_debug_unit(u->id, "Failed to parse state value %s", value);
else
s->deserialized_state = state;
} else if (streq(key, "result")) {
@ -2613,7 +2666,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value,
f = service_result_from_string(value);
if (f < 0)
log_debug("Failed to parse result value %s", value);
log_debug_unit(u->id, "Failed to parse result value %s", value);
else if (f != SERVICE_SUCCESS)
s->result = f;
@ -2622,7 +2675,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value,
f = service_result_from_string(value);
if (f < 0)
log_debug("Failed to parse reload result value %s", value);
log_debug_unit(u->id, "Failed to parse reload result value %s", value);
else if (f != SERVICE_SUCCESS)
s->reload_result = f;
@ -2630,21 +2683,21 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value,
pid_t pid;
if (parse_pid(value, &pid) < 0)
log_debug("Failed to parse control-pid value %s", value);
log_debug_unit(u->id, "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_debug("Failed to parse main-pid value %s", value);
log_debug_unit(u->id, "Failed to parse main-pid value %s", value);
else
service_set_main_pid(s, (pid_t) pid);
} else if (streq(key, "main-pid-known")) {
int b;
if ((b = parse_boolean(value)) < 0)
log_debug("Failed to parse main-pid-known value %s", value);
log_debug_unit(u->id, "Failed to parse main-pid-known value %s", value);
else
s->main_pid_known = b;
} else if (streq(key, "status-text")) {
@ -2659,7 +2712,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value,
ServiceExecCommand id;
if ((id = service_exec_command_from_string(value)) < 0)
log_debug("Failed to parse exec-command value %s", value);
log_debug_unit(u->id, "Failed to parse exec-command value %s", value);
else {
s->control_command_id = id;
s->control_command = s->exec_command[id];
@ -2668,7 +2721,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_debug("Failed to parse socket-fd value %s", value);
log_debug_unit(u->id, "Failed to parse socket-fd value %s", value);
else {
if (s->socket_fd >= 0)
@ -2679,21 +2732,21 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value,
pid_t pid;
if (parse_pid(value, &pid) < 0)
log_debug("Failed to parse main-exec-status-pid value %s", value);
log_debug_unit(u->id, "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_debug("Failed to parse main-exec-status-code value %s", value);
log_debug_unit(u->id, "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_debug("Failed to parse main-exec-status-status value %s", value);
log_debug_unit(u->id, "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"))
@ -2703,7 +2756,7 @@ static int service_deserialize_item(Unit *u, const char *key, const char *value,
else if (streq(key, "watchdog-timestamp"))
dual_timestamp_deserialize(value, &s->watchdog_timestamp);
else
log_debug("Unknown serialization key '%s'", key);
log_debug_unit(u->id, "Unknown serialization key '%s'", key);
return 0;
}
@ -2771,7 +2824,9 @@ static int service_retry_pid_file(Service *s) {
static int service_watch_pid_file(Service *s) {
int r;
log_debug("Setting watch for %s's PID file %s", UNIT(s)->id, s->pid_file_pathspec->path);
log_debug_unit(UNIT(s)->id,
"Setting watch for %s's PID file %s",
UNIT(s)->id, s->pid_file_pathspec->path);
r = path_spec_watch(s->pid_file_pathspec, UNIT(s));
if (r < 0)
goto fail;
@ -2781,8 +2836,9 @@ static int service_watch_pid_file(Service *s) {
return 0;
fail:
log_error("Failed to set a watch for %s's PID file %s: %s",
UNIT(s)->id, s->pid_file_pathspec->path, strerror(-r));
log_error_unit(UNIT(s)->id,
"Failed to set a watch for %s's PID file %s: %s",
UNIT(s)->id, s->pid_file_pathspec->path, strerror(-r));
service_unwatch_pid_file(s);
return r;
}
@ -2824,7 +2880,7 @@ static void service_fd_event(Unit *u, int fd, uint32_t events, Watch *w) {
assert(s->pid_file_pathspec);
assert(path_spec_owns_inotify_fd(s->pid_file_pathspec, fd));
log_debug("inotify event for %s", u->id);
log_debug_unit(u->id, "inotify event for %s", u->id);
if (path_spec_fd_event(s->pid_file_pathspec, events) < 0)
goto fail;
@ -2902,7 +2958,9 @@ 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_debug("%s running next main command for state %s", u->id, service_state_to_string(s->state));
log_debug_unit(u->id,
"%s running next main command for state %s",
u->id, service_state_to_string(s->state));
service_run_next_main(s);
} else {
@ -2961,8 +3019,9 @@ static void service_sigchld_event(Unit *u, pid_t pid, int code, int status) {
f = SERVICE_SUCCESS;
}
log_full(f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
"%s: control process exited, code=%s status=%i", u->id, sigchld_code_to_string(code), status);
log_full_unit(f == SERVICE_SUCCESS ? LOG_DEBUG : LOG_NOTICE, u->id,
"%s: control process exited, code=%s status=%i",
u->id, sigchld_code_to_string(code), status);
if (f != SERVICE_SUCCESS)
s->result = f;
@ -2979,7 +3038,9 @@ 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_debug("%s running next control command for state %s", u->id, service_state_to_string(s->state));
log_debug_unit(u->id,
"%s running next control command for state %s",
u->id, service_state_to_string(s->state));
service_run_next_control(s);
} else {
@ -2989,7 +3050,9 @@ 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_debug("%s got final SIGCHLD for state %s", u->id, service_state_to_string(s->state));
log_debug_unit(u->id,
"%s got final SIGCHLD for state %s",
u->id, service_state_to_string(s->state));
switch (s->state) {
@ -3111,32 +3174,38 @@ static void service_timer_event(Unit *u, uint64_t elapsed, Watch* w) {
case SERVICE_START_PRE:
case SERVICE_START:
log_warning("%s operation timed out. Terminating.", u->id);
log_warning_unit(u->id,
"%s operation timed out. Terminating.", u->id);
service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_TIMEOUT);
break;
case SERVICE_START_POST:
log_warning("%s operation timed out. Stopping.", u->id);
log_warning_unit(u->id,
"%s operation timed out. Stopping.", u->id);
service_enter_stop(s, SERVICE_FAILURE_TIMEOUT);
break;
case SERVICE_RELOAD:
log_warning("%s operation timed out. Stopping.", u->id);
log_warning_unit(u->id,
"%s operation timed out. Stopping.", u->id);
s->reload_result = SERVICE_FAILURE_TIMEOUT;
service_enter_running(s, SERVICE_SUCCESS);
break;
case SERVICE_STOP:
log_warning("%s stopping timed out. Terminating.", u->id);
log_warning_unit(u->id,
"%s stopping timed out. Terminating.", u->id);
service_enter_signal(s, SERVICE_STOP_SIGTERM, SERVICE_FAILURE_TIMEOUT);
break;
case SERVICE_STOP_SIGTERM:
if (s->kill_context.send_sigkill) {
log_warning("%s stopping timed out. Killing.", u->id);
log_warning_unit(u->id,
"%s stopping timed out. Killing.", u->id);
service_enter_signal(s, SERVICE_STOP_SIGKILL, SERVICE_FAILURE_TIMEOUT);
} else {
log_warning("%s stopping timed out. Skipping SIGKILL.", u->id);
log_warning_unit(u->id,
"%s stopping timed out. Skipping SIGKILL.", u->id);
service_enter_stop_post(s, SERVICE_FAILURE_TIMEOUT);
}
@ -3147,33 +3216,40 @@ static void service_timer_event(Unit *u, uint64_t elapsed, Watch* w) {
* Must be something we cannot kill, so let's just be
* weirded out and continue */
log_warning("%s still around after SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s still around after SIGKILL. Ignoring.", u->id);
service_enter_stop_post(s, SERVICE_FAILURE_TIMEOUT);
break;
case SERVICE_STOP_POST:
log_warning("%s stopping timed out (2). Terminating.", u->id);
log_warning_unit(u->id,
"%s stopping timed out (2). Terminating.", u->id);
service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_TIMEOUT);
break;
case SERVICE_FINAL_SIGTERM:
if (s->kill_context.send_sigkill) {
log_warning("%s stopping timed out (2). Killing.", u->id);
log_warning_unit(u->id,
"%s stopping timed out (2). Killing.", u->id);
service_enter_signal(s, SERVICE_FINAL_SIGKILL, SERVICE_FAILURE_TIMEOUT);
} else {
log_warning("%s stopping timed out (2). Skipping SIGKILL. Entering failed mode.", u->id);
log_warning_unit(u->id,
"%s stopping timed out (2). Skipping SIGKILL. Entering failed mode.",
u->id);
service_enter_dead(s, SERVICE_FAILURE_TIMEOUT, false);
}
break;
case SERVICE_FINAL_SIGKILL:
log_warning("%s still around after SIGKILL (2). Entering failed mode.", u->id);
log_warning_unit(u->id,
"%s still around after SIGKILL (2). Entering failed mode.", u->id);
service_enter_dead(s, SERVICE_FAILURE_TIMEOUT, true);
break;
case SERVICE_AUTO_RESTART:
log_info("%s holdoff time over, scheduling restart.", u->id);
log_info_unit(u->id,
"%s holdoff time over, scheduling restart.", u->id);
service_enter_restart(s);
break;
@ -3187,7 +3263,8 @@ static void service_cgroup_notify_event(Unit *u) {
assert(u);
log_debug("%s: cgroup is empty", u->id);
log_debug_unit(u->id,
"%s: cgroup is empty", u->id);
switch (s->state) {
@ -3202,7 +3279,8 @@ static void service_cgroup_notify_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_warning("%s never wrote its PID file. Failing.", UNIT(s)->id);
log_warning_unit(u->id,
"%s never wrote its PID file. Failing.", UNIT(s)->id);
service_unwatch_pid_file(s);
if (s->state == SERVICE_START)
service_enter_signal(s, SERVICE_FINAL_SIGTERM, SERVICE_FAILURE_RESOURCES);
@ -3243,18 +3321,21 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags) {
assert(u);
if (s->notify_access == NOTIFY_NONE) {
log_warning("%s: Got notification message from PID %lu, but reception is disabled.",
u->id, (unsigned long) pid);
log_warning_unit(u->id,
"%s: Got notification message from PID %lu, but reception is disabled.",
u->id, (unsigned long) pid);
return;
}
if (s->notify_access == NOTIFY_MAIN && pid != s->main_pid) {
log_warning("%s: Got notification message from PID %lu, but reception only permitted for PID %lu",
u->id, (unsigned long) pid, (unsigned long) s->main_pid);
log_warning_unit(u->id,
"%s: Got notification message from PID %lu, but reception only permitted for PID %lu",
u->id, (unsigned long) pid, (unsigned long) s->main_pid);
return;
}
log_debug("%s: Got message", u->id);
log_debug_unit(u->id,
"%s: Got message", u->id);
/* Interpret MAINPID= */
if ((e = strv_find_prefix(tags, "MAINPID=")) &&
@ -3264,9 +3345,11 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags) {
s->state == SERVICE_RELOAD)) {
if (parse_pid(e + 8, &pid) < 0)
log_warning("Failed to parse notification message %s", e);
log_warning_unit(u->id,
"Failed to parse notification message %s", e);
else {
log_debug("%s: got %s", u->id, e);
log_debug_unit(u->id,
"%s: got %s", u->id, e);
service_set_main_pid(s, pid);
}
}
@ -3275,7 +3358,8 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags) {
if (s->type == SERVICE_NOTIFY &&
s->state == SERVICE_START &&
strv_find(tags, "READY=1")) {
log_debug("%s: got READY=1", u->id);
log_debug_unit(u->id,
"%s: got READY=1", u->id);
service_enter_start_post(s);
}
@ -3288,17 +3372,20 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags) {
if (e[7]) {
if (!utf8_is_valid(e+7)) {
log_warning("Status message in notification is not UTF-8 clean.");
log_warning_unit(u->id,
"Status message in notification is not UTF-8 clean.");
return;
}
t = strdup(e+7);
if (!t) {
log_error("Failed to allocate string.");
log_error_unit(u->id,
"Failed to allocate string.");
return;
}
log_debug("%s: got %s", u->id, e);
log_debug_unit(u->id,
"%s: got %s", u->id, e);
free(s->status_text);
s->status_text = t;
@ -3309,7 +3396,8 @@ static void service_notify_message(Unit *u, pid_t pid, char **tags) {
}
if (strv_find(tags, "WATCHDOG=1")) {
log_debug("%s: got WATCHDOG=1", u->id);
log_debug_unit(u->id,
"%s: got WATCHDOG=1", u->id);
service_reset_watchdog(s);
}
@ -3396,7 +3484,8 @@ static int service_enumerate(Manager *m) {
goto finish;
}
if ((r = manager_load_unit_prepare(m, name, NULL, NULL, &service)) < 0) {
r = manager_load_unit_prepare(m, name, NULL, NULL, &service);
if (r < 0) {
log_warning("Failed to prepare unit %s: %s", name, strerror(-r));
continue;
}
@ -3495,11 +3584,17 @@ static void service_bus_name_owner_change(
assert(old_owner || new_owner);
if (old_owner && new_owner)
log_debug("%s's D-Bus name %s changed owner from %s to %s", u->id, name, old_owner, new_owner);
log_debug_unit(u->id,
"%s's D-Bus name %s changed owner from %s to %s",
u->id, name, old_owner, new_owner);
else if (old_owner)
log_debug("%s's D-Bus name %s no longer registered by %s", u->id, name, old_owner);
log_debug_unit(u->id,
"%s's D-Bus name %s no longer registered by %s",
u->id, name, old_owner);
else
log_debug("%s's D-Bus name %s now registered by %s", u->id, name, new_owner);
log_debug_unit(u->id,
"%s's D-Bus name %s now registered by %s",
u->id, name, new_owner);
s->bus_name_good = !!new_owner;
@ -3520,7 +3615,8 @@ static void service_bus_name_owner_change(
s->state == SERVICE_RELOAD)) {
/* Try to acquire PID from bus service */
log_debug("Trying to acquire PID from D-Bus name...");
log_debug_unit(u->id,
"Trying to acquire PID from D-Bus name...");
bus_query_pid(u->manager, name);
}
@ -3536,7 +3632,9 @@ static void service_bus_query_pid_done(
assert(s);
assert(name);
log_debug("%s's D-Bus name %s is now owned by process %u", u->id, name, (unsigned) pid);
log_debug_unit(u->id,
"%s's D-Bus name %s is now owned by process %u",
u->id, name, (unsigned) pid);
if (s->main_pid <= 0 &&
(s->state == SERVICE_START ||

233
src/core/socket.c
View File

@ -213,27 +213,35 @@ static int socket_verify(Socket *s) {
return 0;
if (!s->ports) {
log_error("%s lacks Listen setting. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s lacks Listen setting. Refusing.", UNIT(s)->id);
return -EINVAL;
}
if (s->accept && have_non_accept_socket(s)) {
log_error("%s configured for accepting sockets, but sockets are non-accepting. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s configured for accepting sockets, but sockets are non-accepting. Refusing.",
UNIT(s)->id);
return -EINVAL;
}
if (s->accept && s->max_connections <= 0) {
log_error("%s's MaxConnection setting too small. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s's MaxConnection setting too small. Refusing.", UNIT(s)->id);
return -EINVAL;
}
if (s->accept && UNIT_DEREF(s->service)) {
log_error("Explicit service configuration for accepting sockets not supported on %s. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"Explicit service configuration for accepting sockets not supported on %s. Refusing.",
UNIT(s)->id);
return -EINVAL;
}
if (s->exec_context.pam_name && s->kill_context.kill_mode != KILL_CONTROL_GROUP) {
log_error("%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing.",
UNIT(s)->id);
return -EINVAL;
}
@ -700,30 +708,30 @@ 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_warning("SO_KEEPALIVE failed: %m");
log_warning_unit(UNIT(s)->id, "SO_KEEPALIVE failed: %m");
}
if (s->broadcast) {
int one = 1;
if (setsockopt(fd, SOL_SOCKET, SO_BROADCAST, &one, sizeof(one)) < 0)
log_warning("SO_BROADCAST failed: %m");
log_warning_unit(UNIT(s)->id, "SO_BROADCAST failed: %m");
}
if (s->pass_cred) {
int one = 1;
if (setsockopt(fd, SOL_SOCKET, SO_PASSCRED, &one, sizeof(one)) < 0)
log_warning("SO_PASSCRED failed: %m");
log_warning_unit(UNIT(s)->id, "SO_PASSCRED failed: %m");
}
if (s->pass_sec) {
int one = 1;
if (setsockopt(fd, SOL_SOCKET, SO_PASSSEC, &one, sizeof(one)) < 0)
log_warning("SO_PASSSEC failed: %m");
log_warning_unit(UNIT(s)->id, "SO_PASSSEC failed: %m");
}
if (s->priority >= 0)
if (setsockopt(fd, SOL_SOCKET, SO_PRIORITY, &s->priority, sizeof(s->priority)) < 0)
log_warning("SO_PRIORITY failed: %m");
log_warning_unit(UNIT(s)->id, "SO_PRIORITY failed: %m");
if (s->receive_buffer > 0) {
int value = (int) s->receive_buffer;
@ -732,23 +740,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_warning("SO_RCVBUF failed: %m");
log_warning_unit(UNIT(s)->id, "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_warning("SO_SNDBUF failed: %m");
log_warning_unit(UNIT(s)->id, "SO_SNDBUF failed: %m");
}
if (s->mark >= 0)
if (setsockopt(fd, SOL_SOCKET, SO_MARK, &s->mark, sizeof(s->mark)) < 0)
log_warning("SO_MARK failed: %m");
log_warning_unit(UNIT(s)->id, "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_warning("IP_TOS failed: %m");
log_warning_unit(UNIT(s)->id, "IP_TOS failed: %m");
if (s->ip_ttl >= 0) {
int r, x;
@ -763,21 +771,24 @@ static void socket_apply_socket_options(Socket *s, int fd) {
}
if (r < 0 && x < 0)
log_warning("IP_TTL/IPV6_UNICAST_HOPS failed: %m");
log_warning_unit(UNIT(s)->id,
"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_warning("TCP_CONGESTION failed: %m");
log_warning_unit(UNIT(s)->id, "TCP_CONGESTION failed: %m");
#ifdef HAVE_ATTR_XATTR_H
if (s->smack_ip_in)
if (fsetxattr(fd, "security.SMACK64IPIN", s->smack_ip_in, strlen(s->smack_ip_in), 0) < 0)
log_error("fsetxattr(\"security.SMACK64IPIN\"): %m");
log_error_unit(UNIT(s)->id,
"fsetxattr(\"security.SMACK64IPIN\"): %m");
if (s->smack_ip_out)
if (fsetxattr(fd, "security.SMACK64IPOUT", s->smack_ip_out, strlen(s->smack_ip_out), 0) < 0)
log_error("fsetxattr(\"security.SMACK64IPOUT\"): %m");
log_error_unit(UNIT(s)->id,
"fsetxattr(\"security.SMACK64IPOUT\"): %m");
#endif
}
@ -787,12 +798,14 @@ 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_warning("F_SETPIPE_SZ: %m");
log_warning_unit(UNIT(s)->id,
"F_SETPIPE_SZ: %m");
#ifdef HAVE_ATTR_XATTR_H
if (s->smack)
if (fsetxattr(fd, "security.SMACK64", s->smack, strlen(s->smack), 0) < 0)
log_error("fsetxattr(\"security.SMACK64\"): %m");
log_error_unit(UNIT(s)->id,
"fsetxattr(\"security.SMACK64\"): %m");
#endif
}
@ -1117,10 +1130,10 @@ static void socket_set_state(Socket *s, SocketState state) {
socket_close_fds(s);
if (state != old_state)
log_debug("%s changed %s -> %s",
UNIT(s)->id,
socket_state_to_string(old_state),
socket_state_to_string(state));
log_debug_unit(UNIT(s)->id,
"%s changed %s -> %s", UNIT(s)->id,
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);
}
@ -1260,7 +1273,9 @@ static void socket_enter_stop_post(Socket *s, SocketResult f) {
return;
fail:
log_warning("%s failed to run 'stop-post' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'stop-post' task: %s",
UNIT(s)->id, strerror(-r));
socket_enter_signal(s, SOCKET_FINAL_SIGTERM, SOCKET_FAILURE_RESOURCES);
}
@ -1280,7 +1295,9 @@ static void socket_enter_signal(Socket *s, SocketState state, SocketResult f) {
if (s->control_pid > 0) {
if (kill_and_sigcont(s->control_pid, sig) < 0 && errno != ESRCH)
log_warning("Failed to kill control process %li: %m", (long) s->control_pid);
log_warning_unit(UNIT(s)->id,
"Failed to kill control process %li: %m",
(long) s->control_pid);
else
wait_for_exit = true;
}
@ -1300,7 +1317,9 @@ static void socket_enter_signal(Socket *s, SocketState state, SocketResult f) {
r = cgroup_bonding_kill_list(UNIT(s)->cgroup_bondings, sig, true, false, pid_set, NULL);
if (r < 0) {
if (r != -EAGAIN && r != -ESRCH && r != -ENOENT)
log_warning("Failed to kill control group: %s", strerror(-r));
log_warning_unit(UNIT(s)->id,
"Failed to kill control group: %s",
strerror(-r));
} else if (r > 0)
wait_for_exit = true;
@ -1323,7 +1342,9 @@ static void socket_enter_signal(Socket *s, SocketState state, SocketResult f) {
return;
fail:
log_warning("%s failed to kill processes: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to kill processes: %s",
UNIT(s)->id, strerror(-r));
if (state == SOCKET_STOP_PRE_SIGTERM || state == SOCKET_STOP_PRE_SIGKILL)
socket_enter_stop_post(s, SOCKET_FAILURE_RESOURCES);
@ -1356,7 +1377,9 @@ static void socket_enter_stop_pre(Socket *s, SocketResult f) {
return;
fail:
log_warning("%s failed to run 'stop-pre' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'stop-pre' task: %s",
UNIT(s)->id, strerror(-r));
socket_enter_stop_post(s, SOCKET_FAILURE_RESOURCES);
}
@ -1366,7 +1389,9 @@ static void socket_enter_listening(Socket *s) {
r = socket_watch_fds(s);
if (r < 0) {
log_warning("%s failed to watch sockets: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to watch sockets: %s",
UNIT(s)->id, strerror(-r));
goto fail;
}
@ -1383,7 +1408,9 @@ static void socket_enter_start_post(Socket *s) {
r = socket_open_fds(s);
if (r < 0) {
log_warning("%s failed to listen on sockets: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to listen on sockets: %s",
UNIT(s)->id, strerror(-r));
goto fail;
}
@ -1394,7 +1421,9 @@ static void socket_enter_start_post(Socket *s) {
if ((s->control_command = s->exec_command[SOCKET_EXEC_START_POST])) {
r = socket_spawn(s, s->control_command, &s->control_pid);
if (r < 0) {
log_warning("%s failed to run 'start-post' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'start-post' task: %s",
UNIT(s)->id, strerror(-r));
goto fail;
}
@ -1427,7 +1456,9 @@ static void socket_enter_start_pre(Socket *s) {
return;
fail:
log_warning("%s failed to run 'start-pre' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'start-pre' task: %s",
UNIT(s)->id, strerror(-r));
socket_enter_dead(s, SOCKET_FAILURE_RESOURCES);
}
@ -1441,7 +1472,9 @@ static void socket_enter_running(Socket *s, int cfd) {
/* We don't take connections anymore if we are supposed to
* shut down anyway */
if (unit_pending_inactive(UNIT(s))) {
log_debug("Suppressing connection request on %s since unit stop is scheduled.", UNIT(s)->id);
log_debug_unit(UNIT(s)->id,
"Suppressing connection request on %s since unit stop is scheduled.",
UNIT(s)->id);
if (cfd >= 0)
close_nointr_nofail(cfd);
@ -1451,7 +1484,9 @@ static void socket_enter_running(Socket *s, int cfd) {
r = socket_watch_fds(s);
if (r < 0) {
log_warning("%s failed to watch sockets: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to watch sockets: %s",
UNIT(s)->id, strerror(-r));
socket_enter_stop_pre(s, SOCKET_FAILURE_RESOURCES);
}
}
@ -1484,7 +1519,9 @@ static void socket_enter_running(Socket *s, int cfd) {
Service *service;
if (s->n_connections >= s->max_connections) {
log_warning("%s: Too many incoming connections (%u)", UNIT(s)->id, s->n_connections);
log_warning_unit(UNIT(s)->id,
"%s: Too many incoming connections (%u)",
UNIT(s)->id, s->n_connections);
close_nointr_nofail(cfd);
return;
}
@ -1553,7 +1590,11 @@ static void socket_enter_running(Socket *s, int cfd) {
return;
fail:
log_warning("%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", bus_error(&error, r));
log_warning_unit(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",
bus_error(&error, r));
socket_enter_stop_pre(s, SOCKET_FAILURE_RESOURCES);
if (cfd >= 0)
@ -1579,7 +1620,9 @@ static void socket_run_next(Socket *s) {
return;
fail:
log_warning("%s failed to run next task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run next task: %s",
UNIT(s)->id, strerror(-r));
if (s->state == SOCKET_START_POST)
socket_enter_stop_pre(s, SOCKET_FAILURE_RESOURCES);
@ -1615,7 +1658,9 @@ static int socket_start(Unit *u) {
service = SERVICE(UNIT_DEREF(s->service));
if (UNIT(service)->load_state != UNIT_LOADED) {
log_error("Socket service %s not loaded, refusing.", UNIT(service)->id);
log_error_unit(UNIT(service)->id,
"Socket service %s not loaded, refusing.",
UNIT(service)->id);
return -ENOENT;
}
@ -1624,13 +1669,16 @@ static int socket_start(Unit *u) {
if (service->state != SERVICE_DEAD &&
service->state != SERVICE_FAILED &&
service->state != SERVICE_AUTO_RESTART) {
log_error("Socket service %s already active, refusing.", UNIT(service)->id);
log_error_unit(UNIT(service)->id,
"Socket service %s already active, refusing.",
UNIT(service)->id);
return -EBUSY;
}
#ifdef HAVE_SYSV_COMPAT
if (service->is_sysv) {
log_error("Using SysV services for socket activation is not supported. Refusing.");
log_error_unit(UNIT(s)->id,
"Using SysV services for socket activation is not supported. Refusing.");
return -ENOENT;
}
#endif
@ -1737,7 +1785,8 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value,
state = socket_state_from_string(value);
if (state < 0)
log_debug("Failed to parse state value %s", value);
log_debug_unit(u->id,
"Failed to parse state value %s", value);
else
s->deserialized_state = state;
} else if (streq(key, "result")) {
@ -1745,7 +1794,8 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value,
f = socket_result_from_string(value);
if (f < 0)
log_debug("Failed to parse result value %s", value);
log_debug_unit(u->id,
"Failed to parse result value %s", value);
else if (f != SOCKET_SUCCESS)
s->result = f;
@ -1753,21 +1803,25 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value,
unsigned k;
if (safe_atou(value, &k) < 0)
log_debug("Failed to parse n-accepted value %s", value);
log_debug_unit(u->id,
"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_debug("Failed to parse control-pid value %s", value);
log_debug_unit(u->id,
"Failed to parse control-pid value %s", value);
else
s->control_pid = pid;
} else if (streq(key, "control-command")) {
SocketExecCommand id;
if ((id = socket_exec_command_from_string(value)) < 0)
log_debug("Failed to parse exec-command value %s", value);
id = socket_exec_command_from_string(value);
if (id < 0)
log_debug_unit(u->id,
"Failed to parse exec-command value %s", value);
else {
s->control_command_id = id;
s->control_command = s->exec_command[id];
@ -1777,7 +1831,8 @@ 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_debug("Failed to parse fifo value %s", value);
log_debug_unit(u->id,
"Failed to parse fifo value %s", value);
else {
LIST_FOREACH(port, p, s->ports)
@ -1797,7 +1852,8 @@ 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_debug("Failed to parse special value %s", value);
log_debug_unit(u->id,
"Failed to parse special value %s", value);
else {
LIST_FOREACH(port, p, s->ports)
@ -1817,7 +1873,8 @@ 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_debug("Failed to parse mqueue value %s", value);
log_debug_unit(u->id,
"Failed to parse mqueue value %s", value);
else {
LIST_FOREACH(port, p, s->ports)
@ -1837,7 +1894,8 @@ 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_debug("Failed to parse socket value %s", value);
log_debug_unit(u->id,
"Failed to parse socket value %s", value);
else {
LIST_FOREACH(port, p, s->ports)
@ -1856,7 +1914,8 @@ 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_debug("Failed to parse socket value %s", value);
log_debug_unit(u->id,
"Failed to parse socket value %s", value);
else {
LIST_FOREACH(port, p, s->ports)
@ -1871,7 +1930,8 @@ static int socket_deserialize_item(Unit *u, const char *key, const char *value,
}
} else
log_debug("Unknown serialization key '%s'", key);
log_debug_unit(UNIT(s)->id,
"Unknown serialization key '%s'", key);
return 0;
}
@ -1934,14 +1994,18 @@ static void socket_fd_event(Unit *u, int fd, uint32_t events, Watch *w) {
if (s->state != SOCKET_LISTENING)
return;
log_debug("Incoming traffic on %s", u->id);
log_debug_unit(u->id, "Incoming traffic on %s", u->id);
if (events != EPOLLIN) {
if (events & EPOLLHUP)
log_error("%s: Got POLLHUP on a listening socket. The service probably invoked shutdown() on it, and should better not do that.", u->id);
log_error_unit(u->id,
"%s: Got POLLHUP on a listening socket. The service probably invoked shutdown() on it, and should better not do that.",
u->id);
else
log_error("%s: Got unexpected poll event (0x%x) on socket.", u->id, events);
log_error_unit(u->id,
"%s: Got unexpected poll event (0x%x) on socket.",
u->id, events);
goto fail;
}
@ -1955,7 +2019,8 @@ static void socket_fd_event(Unit *u, int fd, uint32_t events, Watch *w) {
if (errno == EINTR)
continue;
log_error("Failed to accept socket: %m");
log_error_unit(u->id,
"Failed to accept socket: %m");
goto fail;
}
@ -2002,8 +2067,10 @@ static void socket_sigchld_event(Unit *u, pid_t pid, int code, int status) {
f = SOCKET_SUCCESS;
}
log_full(f == SOCKET_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
"%s control process exited, code=%s status=%i", u->id, sigchld_code_to_string(code), status);
log_full_unit(f == SOCKET_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
u->id,
"%s control process exited, code=%s status=%i",
u->id, sigchld_code_to_string(code), status);
if (f != SOCKET_SUCCESS)
s->result = f;
@ -2012,7 +2079,9 @@ static void socket_sigchld_event(Unit *u, pid_t pid, int code, int status) {
s->control_command->command_next &&
f == SOCKET_SUCCESS) {
log_debug("%s running next command for state %s", u->id, socket_state_to_string(s->state));
log_debug_unit(u->id,
"%s running next command for state %s",
u->id, socket_state_to_string(s->state));
socket_run_next(s);
} else {
s->control_command = NULL;
@ -2021,7 +2090,9 @@ 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_debug("%s got final SIGCHLD for state %s", u->id, socket_state_to_string(s->state));
log_debug_unit(u->id,
"%s got final SIGCHLD for state %s",
u->id, socket_state_to_string(s->state));
switch (s->state) {
@ -2070,52 +2141,65 @@ static void socket_timer_event(Unit *u, uint64_t elapsed, Watch *w) {
switch (s->state) {
case SOCKET_START_PRE:
log_warning("%s starting timed out. Terminating.", u->id);
log_warning_unit(u->id,
"%s starting timed out. Terminating.", u->id);
socket_enter_signal(s, SOCKET_FINAL_SIGTERM, SOCKET_FAILURE_TIMEOUT);
break;
case SOCKET_START_POST:
log_warning("%s starting timed out. Stopping.", u->id);
log_warning_unit(u->id,
"%s starting timed out. Stopping.", u->id);
socket_enter_stop_pre(s, SOCKET_FAILURE_TIMEOUT);
break;
case SOCKET_STOP_PRE:
log_warning("%s stopping timed out. Terminating.", u->id);
log_warning_unit(u->id,
"%s stopping timed out. Terminating.", u->id);
socket_enter_signal(s, SOCKET_STOP_PRE_SIGTERM, SOCKET_FAILURE_TIMEOUT);
break;
case SOCKET_STOP_PRE_SIGTERM:
if (s->kill_context.send_sigkill) {
log_warning("%s stopping timed out. Killing.", u->id);
log_warning_unit(u->id,
"%s stopping timed out. Killing.", u->id);
socket_enter_signal(s, SOCKET_STOP_PRE_SIGKILL, SOCKET_FAILURE_TIMEOUT);
} else {
log_warning("%s stopping timed out. Skipping SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s stopping timed out. Skipping SIGKILL. Ignoring.",
u->id);
socket_enter_stop_post(s, SOCKET_FAILURE_TIMEOUT);
}
break;
case SOCKET_STOP_PRE_SIGKILL:
log_warning("%s still around after SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s still around after SIGKILL. Ignoring.", u->id);
socket_enter_stop_post(s, SOCKET_FAILURE_TIMEOUT);
break;
case SOCKET_STOP_POST:
log_warning("%s stopping timed out (2). Terminating.", u->id);
log_warning_unit(u->id,
"%s stopping timed out (2). Terminating.", u->id);
socket_enter_signal(s, SOCKET_FINAL_SIGTERM, SOCKET_FAILURE_TIMEOUT);
break;
case SOCKET_FINAL_SIGTERM:
if (s->kill_context.send_sigkill) {
log_warning("%s stopping timed out (2). Killing.", u->id);
log_warning_unit(u->id,
"%s stopping timed out (2). Killing.", u->id);
socket_enter_signal(s, SOCKET_FINAL_SIGKILL, SOCKET_FAILURE_TIMEOUT);
} else {
log_warning("%s stopping timed out (2). Skipping SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id,
"%s stopping timed out (2). Skipping SIGKILL. Ignoring.",
u->id);
socket_enter_dead(s, SOCKET_FAILURE_TIMEOUT);
}
break;
case SOCKET_FINAL_SIGKILL:
log_warning("%s still around after SIGKILL (2). Entering failed mode.", u->id);
log_warning_unit(u->id,
"%s still around after SIGKILL (2). Entering failed mode.",
u->id);
socket_enter_dead(s, SOCKET_FAILURE_TIMEOUT);
break;
@ -2171,7 +2255,9 @@ void socket_notify_service_dead(Socket *s, bool failed_permanent) {
* services. */
if (s->state == SOCKET_RUNNING) {
log_debug("%s got notified about service death (failed permanently: %s)", UNIT(s)->id, yes_no(failed_permanent));
log_debug_unit(UNIT(s)->id,
"%s got notified about service death (failed permanently: %s)",
UNIT(s)->id, yes_no(failed_permanent));
if (failed_permanent)
socket_enter_stop_pre(s, SOCKET_FAILURE_SERVICE_FAILED_PERMANENT);
else
@ -2190,7 +2276,8 @@ void socket_connection_unref(Socket *s) {
assert(s->n_connections > 0);
s->n_connections--;
log_debug("%s: One connection closed, %u left.", UNIT(s)->id, s->n_connections);
log_debug_unit(UNIT(s)->id,
"%s: One connection closed, %u left.", UNIT(s)->id, s->n_connections);
}
static void socket_reset_failed(Unit *u) {

67
src/core/swap.c
View File

@ -225,12 +225,16 @@ static int swap_verify(Swap *s) {
b = unit_has_name(UNIT(s), e);
if (!b) {
log_error("%s: Value of \"What\" and unit name do not match, not loading.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s: Value of \"What\" and unit name do not match, not loading.",
UNIT(s)->id);
return -EINVAL;
}
if (s->exec_context.pam_name && s->kill_context.kill_mode != KILL_CONTROL_GROUP) {
log_error("%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing to load.", UNIT(s)->id);
log_error_unit(UNIT(s)->id,
"%s has PAM enabled. Kill mode must be set to 'control-group'. Refusing to load.",
UNIT(s)->id);
return -EINVAL;
}
@ -398,7 +402,7 @@ static int swap_add_one(
return 0;
fail:
log_warning("Failed to load swap unit: %s", strerror(-r));
log_warning_unit(e, "Failed to load swap unit: %s", strerror(-r));
free(wp);
@ -483,10 +487,11 @@ static void swap_set_state(Swap *s, SwapState state) {
}
if (state != old_state)
log_debug("%s changed %s -> %s",
UNIT(s)->id,
swap_state_to_string(old_state),
swap_state_to_string(state));
log_debug_unit(UNIT(s)->id,
"%s changed %s -> %s",
UNIT(s)->id,
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);
@ -656,7 +661,9 @@ static void swap_enter_signal(Swap *s, SwapState state, SwapResult f) {
if (s->control_pid > 0) {
if (kill_and_sigcont(s->control_pid, sig) < 0 && errno != ESRCH)
log_warning("Failed to kill control process %li: %m", (long) s->control_pid);
log_warning_unit(UNIT(s)->id,
"Failed to kill control process %li: %m",
(long) s->control_pid);
else
wait_for_exit = true;
}
@ -679,7 +686,8 @@ static void swap_enter_signal(Swap *s, SwapState state, SwapResult f) {
r = cgroup_bonding_kill_list(UNIT(s)->cgroup_bondings, sig, true, false, pid_set, NULL);
if (r < 0) {
if (r != -EAGAIN && r != -ESRCH && r != -ENOENT)
log_warning("Failed to kill control group: %s", strerror(-r));
log_warning_unit(UNIT(s)->id,
"Failed to kill control group: %s", strerror(-r));
} else if (r > 0)
wait_for_exit = true;
@ -700,7 +708,8 @@ static void swap_enter_signal(Swap *s, SwapState state, SwapResult f) {
return;
fail:
log_warning("%s failed to kill processes: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to kill processes: %s", UNIT(s)->id, strerror(-r));
swap_enter_dead(s, SWAP_FAILURE_RESOURCES);
@ -755,7 +764,9 @@ static void swap_enter_activating(Swap *s) {
return;
fail:
log_warning("%s failed to run 'swapon' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'swapon' task: %s",
UNIT(s)->id, strerror(-r));
swap_enter_dead(s, SWAP_FAILURE_RESOURCES);
}
@ -785,7 +796,9 @@ static void swap_enter_deactivating(Swap *s) {
return;
fail:
log_warning("%s failed to run 'swapoff' task: %s", UNIT(s)->id, strerror(-r));
log_warning_unit(UNIT(s)->id,
"%s failed to run 'swapoff' task: %s",
UNIT(s)->id, strerror(-r));
swap_enter_active(s, SWAP_FAILURE_RESOURCES);
}
@ -869,7 +882,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_debug("Failed to parse state value %s", value);
log_debug_unit(u->id, "Failed to parse state value %s", value);
else
s->deserialized_state = state;
} else if (streq(key, "result")) {
@ -877,14 +890,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_debug("Failed to parse result value %s", value);
log_debug_unit(u->id, "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_debug("Failed to parse control-pid value %s", value);
log_debug_unit(u->id, "Failed to parse control-pid value %s", value);
else
s->control_pid = pid;
@ -893,14 +906,14 @@ 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_debug("Failed to parse exec-command value %s", value);
log_debug_unit(u->id, "Failed to parse exec-command value %s", value);
else {
s->control_command_id = id;
s->control_command = s->exec_command + id;
}
} else
log_debug("Unknown serialization key '%s'", key);
log_debug_unit(u->id, "Unknown serialization key '%s'", key);
return 0;
}
@ -958,8 +971,10 @@ static void swap_sigchld_event(Unit *u, pid_t pid, int code, int status) {
s->control_command_id = _SWAP_EXEC_COMMAND_INVALID;
}
log_full(f == SWAP_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
"%s swap process exited, code=%s status=%i", u->id, sigchld_code_to_string(code), status);
log_full_unit(f == SWAP_SUCCESS ? LOG_DEBUG : LOG_NOTICE,
u->id,
"%s swap process exited, code=%s status=%i",
u->id, sigchld_code_to_string(code), status);
switch (s->state) {
@ -1005,38 +1020,38 @@ static void swap_timer_event(Unit *u, uint64_t elapsed, Watch *w) {
switch (s->state) {
case SWAP_ACTIVATING:
log_warning("%s activation timed out. Stopping.", u->id);
log_warning_unit(u->id, "%s activation timed out. Stopping.", u->id);
swap_enter_signal(s, SWAP_ACTIVATING_SIGTERM, SWAP_FAILURE_TIMEOUT);
break;
case SWAP_DEACTIVATING:
log_warning("%s deactivation timed out. Stopping.", u->id);
log_warning_unit(u->id, "%s deactivation timed out. Stopping.", u->id);
swap_enter_signal(s, SWAP_DEACTIVATING_SIGTERM, SWAP_FAILURE_TIMEOUT);
break;
case SWAP_ACTIVATING_SIGTERM:
if (s->kill_context.send_sigkill) {
log_warning("%s activation timed out. Killing.", u->id);
log_warning_unit(u->id, "%s activation timed out. Killing.", u->id);
swap_enter_signal(s, SWAP_ACTIVATING_SIGKILL, SWAP_FAILURE_TIMEOUT);
} else {
log_warning("%s activation timed out. Skipping SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id, "%s activation timed out. Skipping SIGKILL. Ignoring.", u->id);
swap_enter_dead(s, SWAP_FAILURE_TIMEOUT);
}
break;
case SWAP_DEACTIVATING_SIGTERM:
if (s->kill_context.send_sigkill) {
log_warning("%s deactivation timed out. Killing.", u->id);
log_warning_unit(u->id, "%s deactivation timed out. Killing.", u->id);
swap_enter_signal(s, SWAP_DEACTIVATING_SIGKILL, SWAP_FAILURE_TIMEOUT);
} else {
log_warning("%s deactivation timed out. Skipping SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id, "%s deactivation timed out. Skipping SIGKILL. Ignoring.", u->id);
swap_enter_dead(s, SWAP_FAILURE_TIMEOUT);
}
break;
case SWAP_ACTIVATING_SIGKILL:
case SWAP_DEACTIVATING_SIGKILL:
log_warning("%s swap process still around after SIGKILL. Ignoring.", u->id);
log_warning_unit(u->id, "%s swap process still around after SIGKILL. Ignoring.", u->id);
swap_enter_dead(s, SWAP_FAILURE_TIMEOUT);
break;

46
src/core/timer.c
View File

@ -76,7 +76,8 @@ static int timer_verify(Timer *t) {
return 0;
if (!t->values) {
log_error("%s lacks value setting. Refusing.", UNIT(t)->id);
log_error_unit(UNIT(t)->id,
"%s lacks value setting. Refusing.", UNIT(t)->id);
return -EINVAL;
}
@ -187,10 +188,10 @@ static void timer_set_state(Timer *t, TimerState state) {
}
if (state != old_state)
log_debug("%s changed %s -> %s",
UNIT(t)->id,
timer_state_to_string(old_state),
timer_state_to_string(state));
log_debug_unit(UNIT(t)->id,
"%s changed %s -> %s", UNIT(t)->id,
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);
}
@ -312,14 +313,17 @@ static void timer_enter_waiting(Timer *t, bool initial) {
}
if (!found_monotonic && !found_realtime) {
log_debug("%s: Timer is elapsed.", UNIT(t)->id);
log_debug_unit(UNIT(t)->id, "%s: Timer is elapsed.", UNIT(t)->id);
timer_set_state(t, TIMER_ELAPSED);
return;
}
if (found_monotonic) {
char buf[FORMAT_TIMESPAN_MAX];
log_debug("%s: Monotonic timer elapses in %s the next time.", UNIT(t)->id, format_timespan(buf, sizeof(buf), t->next_elapse_monotonic - ts.monotonic));
log_debug_unit(UNIT(t)->id,
"%s: Monotonic timer elapses in %s the next time.",
UNIT(t)->id,
format_timespan(buf, sizeof(buf), t->next_elapse_monotonic - ts.monotonic));
r = unit_watch_timer(UNIT(t), CLOCK_MONOTONIC, false, t->next_elapse_monotonic, &t->monotonic_watch);
if (r < 0)
@ -329,7 +333,10 @@ static void timer_enter_waiting(Timer *t, bool initial) {
if (found_realtime) {
char buf[FORMAT_TIMESTAMP_MAX];
log_debug("%s: Realtime timer elapses at %s the next time.", UNIT(t)->id, format_timestamp(buf, sizeof(buf), t->next_elapse_realtime));
log_debug_unit(UNIT(t)->id,
"%s: Realtime timer elapses at %s the next time.",
UNIT(t)->id,
format_timestamp(buf, sizeof(buf), t->next_elapse_realtime));
r = unit_watch_timer(UNIT(t), CLOCK_REALTIME, false, t->next_elapse_realtime, &t->realtime_watch);
if (r < 0)
@ -341,7 +348,9 @@ static void timer_enter_waiting(Timer *t, bool initial) {
return;
fail:
log_warning("%s failed to enter waiting state: %s", UNIT(t)->id, strerror(-r));
log_warning_unit(UNIT(t)->id,
"%s failed to enter waiting state: %s",
UNIT(t)->id, strerror(-r));
timer_enter_dead(t, TIMER_FAILURE_RESOURCES);
}
@ -364,7 +373,9 @@ static void timer_enter_running(Timer *t) {
return;
fail:
log_warning("%s failed to queue unit startup job: %s", UNIT(t)->id, bus_error(&error, r));
log_warning_unit(UNIT(t)->id,
"%s failed to queue unit startup job: %s",
UNIT(t)->id, bus_error(&error, r));
timer_enter_dead(t, TIMER_FAILURE_RESOURCES);
dbus_error_free(&error);
@ -420,7 +431,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_debug("Failed to parse state value %s", value);
log_debug_unit(u->id, "Failed to parse state value %s", value);
else
t->deserialized_state = state;
} else if (streq(key, "result")) {
@ -428,12 +439,12 @@ static int timer_deserialize_item(Unit *u, const char *key, const char *value, F
f = timer_result_from_string(value);
if (f < 0)
log_debug("Failed to parse result value %s", value);
log_debug_unit(u->id, "Failed to parse result value %s", value);
else if (f != TIMER_SUCCESS)
t->result = f;
} else
log_debug("Unknown serialization key '%s'", key);
log_debug_unit(u->id, "Unknown serialization key '%s'", key);
return 0;
}
@ -459,7 +470,7 @@ static void timer_timer_event(Unit *u, uint64_t elapsed, Watch *w) {
if (t->state != TIMER_WAITING)
return;
log_debug("Timer elapsed on %s", u->id);
log_debug_unit(u->id, "Timer elapsed on %s", u->id);
timer_enter_running(t);
}
@ -500,7 +511,9 @@ void timer_unit_notify(Unit *u, UnitActiveState new_state) {
case TIMER_RUNNING:
if (UNIT_IS_INACTIVE_OR_FAILED(new_state)) {
log_debug("%s got notified about unit deactivation.", UNIT(t)->id);
log_debug_unit(UNIT(t)->id,
"%s got notified about unit deactivation.",
UNIT(t)->id);
timer_enter_waiting(t, false);
}
@ -535,7 +548,8 @@ static void timer_time_change(Unit *u) {
if (t->state != TIMER_WAITING)
return;
log_info("%s: time change, recalculating next elapse.", u->id);
log_info_unit(u->id,
"%s: time change, recalculating next elapse.", u->id);
timer_enter_waiting(t, false);
}

88
src/core/transaction.c
View File

@ -186,8 +186,14 @@ static int delete_one_unmergeable_job(Transaction *tr, Job *j) {
* another unit in which case we
* rather remove the start. */
log_debug("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_debug("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)));
log_debug_unit(j->unit->id,
"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_debug_unit(k->unit->id,
"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)));
if (j->type == JOB_STOP) {
@ -213,7 +219,9 @@ static int delete_one_unmergeable_job(Transaction *tr, Job *j) {
return -ENOEXEC;
/* Ok, we can drop one, so let's do so. */
log_debug("Fixing conflicting jobs by deleting job %s/%s", d->unit->id, job_type_to_string(d->type));
log_debug_unit(d->unit->id,
"Fixing conflicting jobs by deleting job %s/%s",
d->unit->id, job_type_to_string(d->type));
transaction_delete_job(tr, d, true);
return 0;
}
@ -352,12 +360,17 @@ 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_warning("Found ordering cycle on %s/%s", j->unit->id, job_type_to_string(j->type));
log_warning_unit(j->unit->id,
"Found ordering cycle on %s/%s",
j->unit->id, job_type_to_string(j->type));
delete = NULL;
for (k = from; k; k = ((k->generation == generation && k->marker != k) ? k->marker : NULL)) {
log_info("Walked on cycle path to %s/%s", k->unit->id, job_type_to_string(k->type));
/* logging for j not k here here to provide consistent narrative */
log_info_unit(j->unit->id,
"Walked on cycle path to %s/%s",
k->unit->id, job_type_to_string(k->type));
if (!delete &&
!unit_matters_to_anchor(k->unit, k)) {
@ -374,15 +387,24 @@ static int transaction_verify_order_one(Transaction *tr, Job *j, Job *from, unsi
if (delete) {
log_error("Breaking ordering cycle by deleting job %s/%s", delete->unit->id, job_type_to_string(delete->type));
status_printf(ANSI_HIGHLIGHT_RED_ON " SKIP " ANSI_HIGHLIGHT_OFF, true, "Ordering cycle found, skip %s", unit_description(delete->unit));
/* logging for j not k here here to provide consistent narrative */
log_warning_unit(j->unit->id,
"Breaking ordering cycle by deleting job %s/%s",
delete->unit->id, job_type_to_string(delete->type));
log_error_unit(delete->unit->id,
"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));
status_printf(ANSI_HIGHLIGHT_RED_ON " SKIP " ANSI_HIGHLIGHT_OFF, true,
"Ordering cycle found, skipping %s", unit_description(delete->unit));
transaction_delete_unit(tr, delete->unit);
return -EAGAIN;
}
log_error("Unable to break cycle");
dbus_set_error(e, BUS_ERROR_TRANSACTION_ORDER_IS_CYCLIC, "Transaction order is cyclic. See system logs for details.");
dbus_set_error(e, BUS_ERROR_TRANSACTION_ORDER_IS_CYCLIC,
"Transaction order is cyclic. See system logs for details.");
return -ENOEXEC;
}
@ -525,13 +547,19 @@ rescan:
continue;
if (stops_running_service)
log_debug("%s/%s would stop a running service.", j->unit->id, job_type_to_string(j->type));
log_debug_unit(j->unit->id,
"%s/%s would stop a running service.",
j->unit->id, job_type_to_string(j->type));
if (changes_existing_job)
log_debug("%s/%s would change existing job.", j->unit->id, job_type_to_string(j->type));
log_debug_unit(j->unit->id,
"%s/%s would change existing job.",
j->unit->id, job_type_to_string(j->type));
/* Ok, let's get rid of this */
log_debug("Deleting %s/%s to minimize impact.", j->unit->id, job_type_to_string(j->type));
log_debug_unit(j->unit->id,
"Deleting %s/%s to minimize impact.",
j->unit->id, job_type_to_string(j->type));
transaction_delete_job(tr, j, true);
goto rescan;
@ -783,9 +811,10 @@ static void transaction_unlink_job(Transaction *tr, Job *j, bool delete_dependen
job_dependency_free(j->object_list);
if (other && delete_dependencies) {
log_debug("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));
log_debug_unit(other->unit->id,
"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));
transaction_delete_job(tr, other, delete_dependencies);
}
}
@ -871,7 +900,9 @@ 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_warning("Cannot add dependency job for unit %s, ignoring: %s", dep->id, bus_error(e, r));
log_warning_unit(dep->id,
"Cannot add dependency job for unit %s, ignoring: %s",
dep->id, bus_error(e, r));
if (e)
dbus_error_free(e);
@ -908,8 +939,9 @@ 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_full(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING,
"Cannot add dependency job for unit %s, ignoring: %s", dep->id, bus_error(e, r));
log_full_unit(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, dep->id,
"Cannot add dependency job for unit %s, ignoring: %s",
dep->id, bus_error(e, r));
if (e)
dbus_error_free(e);
@ -919,8 +951,9 @@ 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_full(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING,
"Cannot add dependency job for unit %s, ignoring: %s", dep->id, bus_error(e, r));
log_full_unit(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, dep->id,
"Cannot add dependency job for unit %s, ignoring: %s",
dep->id, bus_error(e, r));
if (e)
dbus_error_free(e);
@ -941,8 +974,9 @@ 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_full(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING,
"Cannot add dependency job for unit %s, ignoring: %s", dep->id, bus_error(e, r));
log_full_unit(r == -EADDRNOTAVAIL ? LOG_DEBUG : LOG_WARNING, dep->id,
"Cannot add dependency job for unit %s, ignoring: %s",
dep->id, bus_error(e, r));
if (e)
dbus_error_free(e);
@ -963,7 +997,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_warning("Cannot add dependency job for unit %s, ignoring: %s", dep->id, bus_error(e, r));
log_warning_unit(dep->id,
"Cannot add dependency job for unit %s, ignoring: %s",
dep->id, bus_error(e, r));
if (e)
dbus_error_free(e);
@ -1014,7 +1050,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_warning("Cannot add dependency reload job for unit %s, ignoring: %s", dep->id, bus_error(e, r));
log_warning_unit(dep->id,
"Cannot add dependency reload job for unit %s, ignoring: %s",
dep->id, bus_error(e, r));
if (e)
dbus_error_free(e);
@ -1059,7 +1097,9 @@ 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_warning("Cannot add isolate job for unit %s, ignoring: %s", u->id, strerror(-r));
log_warning_unit(u->id,
"Cannot add isolate job for unit %s, ignoring: %s",
u->id, strerror(-r));
}
return 0;