SymbX/systemd
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge pull request #23351 from keszybz/logind-message

Browse Source 
logind: fix crash in logind on bad message string
This commit is contained in:
Yu Watanabe
2022-05-12 05:25:21 +09:00
committed by GitHub
parent 0cfb00d9da 011a03a3fa
commit 34f6ae24c5
19 changed files with 86 additions and 61 deletions
Download Patch File Download Diff File Expand all files Collapse all files
meson.build
+7
View File
@@ -33,6 +33,13 @@ conf.set_quoted('RELATIVE_SOURCE_PATH', relative_source_path)
conf.set10('BUILD_MODE_DEVELOPER', get_option('mode') == 'developer',
description : 'tailor build to development or release builds')
verification = get_option('log-message-verification')
if verification == 'auto'
verification = conf.get('BUILD_MODE_DEVELOPER') == 1
else
verification = verification == 'true'
endif
conf.set10('LOG_MESSAGE_VERIFICATION', verification)
want_ossfuzz = get_option('oss-fuzz')
want_libfuzzer = get_option('llvm-fuzz')
meson_options.txt
+2
View File
@@ -470,6 +470,8 @@ option('fuzz-tests', type : 'boolean', value : 'false',
description : 'run the fuzzer regression tests by default (with sanitizers)')
option('install-tests', type : 'boolean', value : 'false',
description : 'install test executables')
option('log-message-verification', type : 'combo', choices : ['auto', 'true', 'false'],
description : 'do fake printf() calls to verify format strings')
option('ok-color', type : 'combo',
choices : ['black', 'red', 'green', 'yellow', 'blue', 'magenta', 'cyan',
src/basic/log.c
+4
View File
@@ -67,6 +67,10 @@ static bool prohibit_ipc = false;
* use here. */
static char *log_abort_msg = NULL;
#if LOG_MESSAGE_VERIFICATION || defined(__COVERITY__)
bool _log_message_dummy = false; /* Always false */
#endif
/* An assert to use in logging functions that does not call recursively
* into our logging functions (since that might lead to a loop). */
#define assert_raw(expr) \
src/basic/log.h
+10 -2
View File
@@ -298,8 +298,16 @@ int log_emergency_level(void);
bool log_on_console(void) _pure_;
/* Helper to prepare various field for structured logging */
#define LOG_MESSAGE(fmt, ...) "MESSAGE=" fmt, ##__VA_ARGS__
/* Helper to wrap the main message in structured logging. The macro doesn't do much,
* except to provide visual grouping of the format string and its arguments. */
#if LOG_MESSAGE_VERIFICATION || defined(__COVERITY__)
/* Do a fake formatting of the message string to let the scanner verify the arguments against the format
* message. The variable will never be set to true, but we don't tell the compiler that :) */
extern bool _log_message_dummy;
# define LOG_MESSAGE(fmt, ...) "MESSAGE=%.0d" fmt, (_log_message_dummy && printf(fmt, ##__VA_ARGS__)), ##__VA_ARGS__
#else
# define LOG_MESSAGE(fmt, ...) "MESSAGE=" fmt, ##__VA_ARGS__
#endif
void log_received_signal(int level, const struct signalfd_siginfo *si);
src/basic/user-util.c
+1 -1
View File
@@ -794,7 +794,7 @@ bool valid_user_group_name(const char *u, ValidUserFlags flags) {
/* Compare with strict result and warn if result doesn't match */
if (FLAGS_SET(flags, VALID_USER_WARN) && !valid_user_group_name(u, 0))
log_struct(LOG_NOTICE,
"MESSAGE=Accepting user/group name '%s', which does not match strict user/group name rules.", u,
LOG_MESSAGE("Accepting user/group name '%s', which does not match strict user/group name rules.", u),
"USER_GROUP_NAME=%s", u,
"MESSAGE_ID=" SD_MESSAGE_UNSAFE_USER_NAME_STR);
src/core/device.c
+2 -1
View File
@@ -493,7 +493,8 @@ static int device_setup_unit(Manager *m, sd_device *dev, const char *path, bool
LOG_WARNING, r,
"MESSAGE_ID=" SD_MESSAGE_DEVICE_PATH_NOT_SUITABLE_STR,
"DEVICE=%s", path,
LOG_MESSAGE("Failed to generate valid unit name from device path '%s', ignoring device: %m", path));
LOG_MESSAGE("Failed to generate valid unit name from device path '%s', ignoring device: %m",
path));
u = manager_get_unit(m, e);
if (u) {
src/core/job.c
+7 -7
View File
@@ -716,8 +716,8 @@ static void job_emit_done_message(Unit *u, uint32_t job_id, JobType t, JobResult
log_unit_struct(
u,
job_done_messages[result].log_level,
"MESSAGE=%s was skipped because all trigger condition checks failed.",
ident,
LOG_MESSAGE("%s was skipped because all trigger condition checks failed.",
ident),
"JOB_ID=%" PRIu32, job_id,
"JOB_TYPE=%s", job_type_to_string(t),
"JOB_RESULT=%s", job_result_to_string(result),
@@ -727,11 +727,11 @@ static void job_emit_done_message(Unit *u, uint32_t job_id, JobType t, JobResult
log_unit_struct(
u,
job_done_messages[result].log_level,
"MESSAGE=%s was skipped because of a failed condition check (%s=%s%s).",
ident,
condition_type_to_string(c->type),
c->negate ? "!" : "",
c->parameter,
LOG_MESSAGE("%s was skipped because of a failed condition check (%s=%s%s).",
ident,
condition_type_to_string(c->type),
c->negate ? "!" : "",
c->parameter),
"JOB_ID=%" PRIu32, job_id,
"JOB_TYPE=%s", job_type_to_string(t),
"JOB_RESULT=%s", job_result_to_string(result),
src/core/service.c
+2 -1
View File
@@ -2365,7 +2365,8 @@ static void service_enter_restart(Service *s) {
log_unit_struct(UNIT(s), LOG_INFO,
"MESSAGE_ID=" SD_MESSAGE_UNIT_RESTART_SCHEDULED_STR,
LOG_UNIT_INVOCATION_ID(UNIT(s)),
LOG_UNIT_MESSAGE(UNIT(s), "Scheduled restart job, restart counter is at %u.", s->n_restarts),
LOG_UNIT_MESSAGE(UNIT(s),
"Scheduled restart job, restart counter is at %u.", s->n_restarts),
"N_RESTARTS=%u", s->n_restarts);
/* Notify clients about changed restart counter */
src/core/transaction.c
+10 -9
View File
@@ -390,19 +390,20 @@ static int transaction_verify_order_one(Transaction *tr, Job *j, Job *from, unsi
STRV_FOREACH_PAIR(unit_id, job_type, array)
/* logging for j not k here to provide a consistent narrative */
log_struct(LOG_WARNING,
"MESSAGE=%s: Found %s on %s/%s",
j->unit->id,
unit_id == array ? "ordering cycle" : "dependency",
*unit_id, *job_type,
LOG_UNIT_MESSAGE(j->unit,
"Found %s on %s/%s",
unit_id == array ? "ordering cycle" : "dependency",
*unit_id, *job_type),
"%s", unit_ids);
if (delete) {
const char *status;
/* logging for j not k here to provide a consistent narrative */
log_struct(LOG_ERR,
"MESSAGE=%s: Job %s/%s deleted to break ordering cycle starting with %s/%s",
j->unit->id, delete->unit->id, job_type_to_string(delete->type),
j->unit->id, job_type_to_string(j->type),
LOG_UNIT_MESSAGE(j->unit,
"Job %s/%s deleted to break ordering cycle starting with %s/%s",
delete->unit->id, job_type_to_string(delete->type),
j->unit->id, job_type_to_string(j->type)),
"%s", unit_ids);
if (log_get_show_color())
@@ -420,8 +421,8 @@ static int transaction_verify_order_one(Transaction *tr, Job *j, Job *from, unsi
}
log_struct(LOG_ERR,
"MESSAGE=%s: Unable to break cycle starting with %s/%s",
j->unit->id, j->unit->id, job_type_to_string(j->type),
LOG_UNIT_MESSAGE(j->unit, "Unable to break cycle starting with %s/%s",
j->unit->id, job_type_to_string(j->type)),
"%s", unit_ids);
return sd_bus_error_setf(e, BUS_ERROR_TRANSACTION_ORDER_IS_CYCLIC,
src/core/unit.h
+2 -1
View File
@@ -1046,7 +1046,8 @@ Condition *unit_find_failed_condition(Unit *u);
#define log_unit_struct_iovec(unit, level, iovec, n_iovec) log_unit_struct_iovec_errno(unit, level, 0, iovec, n_iovec)
#define LOG_UNIT_MESSAGE(unit, fmt, ...) "MESSAGE=%s: " fmt, (unit)->id, ##__VA_ARGS__
/* Like LOG_MESSAGE(), but with the unit name prefixed. */
#define LOG_UNIT_MESSAGE(unit, fmt, ...) LOG_MESSAGE("%s: " fmt, (unit)->id, ##__VA_ARGS__)
#define LOG_UNIT_ID(unit) (unit)->manager->unit_log_format_string, (unit)->id
#define LOG_UNIT_INVOCATION_ID(unit) (unit)->manager->invocation_log_format_string, (unit)->invocation_id_string
src/login/logind-action.c
+4 -4
View File
@@ -29,7 +29,7 @@ static const HandleActionData handle_action_data_table[_HANDLE_ACTION_MAX] = {
.sleep_operation = _SLEEP_OPERATION_INVALID,
.message_id = SD_MESSAGE_SHUTDOWN_STR,
.message = "System is powering down",
.log_message = "power-off",
.log_verb = "power-off",
},
[HANDLE_REBOOT] = {
.handle = HANDLE_REBOOT,
@@ -41,7 +41,7 @@ static const HandleActionData handle_action_data_table[_HANDLE_ACTION_MAX] = {
.sleep_operation = _SLEEP_OPERATION_INVALID,
.message_id = SD_MESSAGE_SHUTDOWN_STR,
.message = "System is rebooting",
.log_message = "reboot",
.log_verb = "reboot",
},
[HANDLE_HALT] = {
.handle = HANDLE_HALT,
@@ -53,7 +53,7 @@ static const HandleActionData handle_action_data_table[_HANDLE_ACTION_MAX] = {
.sleep_operation = _SLEEP_OPERATION_INVALID,
.message_id = SD_MESSAGE_SHUTDOWN_STR,
.message = "System is halting",
.log_message = "halt",
.log_verb = "halt",
},
[HANDLE_KEXEC] = {
.handle = HANDLE_KEXEC,
@@ -65,7 +65,7 @@ static const HandleActionData handle_action_data_table[_HANDLE_ACTION_MAX] = {
.sleep_operation = _SLEEP_OPERATION_INVALID,
.message_id = SD_MESSAGE_SHUTDOWN_STR,
.message = "System is rebooting with kexec",
.log_message = "kexec",
.log_verb = "kexec",
},
[HANDLE_SUSPEND] = {
.handle = HANDLE_SUSPEND,
src/login/logind-action.h
+1 -1
View File
@@ -39,7 +39,7 @@ struct HandleActionData {
SleepOperation sleep_operation;
const char* message_id;
const char* message;
const char* log_message;
const char* log_verb;
};
int manager_handle_action(
src/login/logind-button.c
+8 -4
View File
@@ -226,7 +226,8 @@ static int button_dispatch(sd_event_source *s, int fd, uint32_t revents, void *u
log_debug("Power key pressed. Further action depends on the key press duration.");
start_long_press(b->manager, &b->manager->power_key_long_press_event_source, long_press_of_power_key_handler);
} else {
log_struct(LOG_INFO, LOG_MESSAGE("Power key pressed short."),
log_struct(LOG_INFO,
LOG_MESSAGE("Power key pressed short."),
"MESSAGE_ID=" SD_MESSAGE_POWER_KEY_STR);
manager_handle_action(b->manager, INHIBIT_HANDLE_POWER_KEY, b->manager->handle_power_key, b->manager->power_key_ignore_inhibited, true);
}
@@ -242,7 +243,8 @@ static int button_dispatch(sd_event_source *s, int fd, uint32_t revents, void *u
log_debug("Reboot key pressed. Further action depends on the key press duration.");
start_long_press(b->manager, &b->manager->reboot_key_long_press_event_source, long_press_of_reboot_key_handler);
} else {
log_struct(LOG_INFO, LOG_MESSAGE("Reboot key pressed short."),
log_struct(LOG_INFO,
LOG_MESSAGE("Reboot key pressed short."),
"MESSAGE_ID=" SD_MESSAGE_REBOOT_KEY_STR);
manager_handle_action(b->manager, INHIBIT_HANDLE_REBOOT_KEY, b->manager->handle_reboot_key, b->manager->reboot_key_ignore_inhibited, true);
}
@@ -259,7 +261,8 @@ static int button_dispatch(sd_event_source *s, int fd, uint32_t revents, void *u
log_debug("Suspend key pressed. Further action depends on the key press duration.");
start_long_press(b->manager, &b->manager->suspend_key_long_press_event_source, long_press_of_suspend_key_handler);
} else {
log_struct(LOG_INFO, LOG_MESSAGE("Suspend key pressed short."),
log_struct(LOG_INFO,
LOG_MESSAGE("Suspend key pressed short."),
"MESSAGE_ID=" SD_MESSAGE_SUSPEND_KEY_STR);
manager_handle_action(b->manager, INHIBIT_HANDLE_SUSPEND_KEY, b->manager->handle_suspend_key, b->manager->suspend_key_ignore_inhibited, true);
}
@@ -270,7 +273,8 @@ static int button_dispatch(sd_event_source *s, int fd, uint32_t revents, void *u
log_debug("Hibernate key pressed. Further action depends on the key press duration.");
start_long_press(b->manager, &b->manager->hibernate_key_long_press_event_source, long_press_of_hibernate_key_handler);
} else {
log_struct(LOG_INFO, LOG_MESSAGE("Hibernate key pressed short."),
log_struct(LOG_INFO,
LOG_MESSAGE("Hibernate key pressed short."),
"MESSAGE_ID=" SD_MESSAGE_HIBERNATE_KEY_STR);
manager_handle_action(b->manager, INHIBIT_HANDLE_HIBERNATE_KEY, b->manager->handle_hibernate_key, b->manager->hibernate_key_ignore_inhibited, true);
}
src/login/logind-dbus.c
+9 -21
View File
@@ -1515,32 +1515,20 @@ static int have_multiple_sessions(
static int bus_manager_log_shutdown(
Manager *m,
const HandleActionData *a) {
const char *message, *log_message;
assert(m);
assert(a);
message = a->message;
log_message = a->log_message;
if (message)
message = strjoina("MESSAGE=", message);
else
message = "MESSAGE=System is shutting down";
if (isempty(m->wall_message))
message = strjoina(message, ".");
else
message = strjoina(message, " (", m->wall_message, ").");
if (log_message)
log_message = strjoina("SHUTDOWN=", log_message);
const char *message = a->message ?: "System is shutting down";
const char *log_verb = a->log_verb ? strjoina("SHUTDOWN=", a->log_verb) : NULL;
return log_struct(LOG_NOTICE,
"MESSAGE_ID=%s", a->message_id ? a->message_id : SD_MESSAGE_SHUTDOWN_STR,
message,
log_message);
"MESSAGE_ID=%s", a->message_id ?: SD_MESSAGE_SHUTDOWN_STR,
LOG_MESSAGE("%s%s%s%s.",
message,
m->wall_message ? " (" : "",
strempty(m->wall_message),
m->wall_message ? ")" : ""),
log_verb);
}
static int lid_switch_ignore_handler(sd_event_source *e, uint64_t usec, void *userdata) {
src/resolve/resolved-dns-server.c
+2 -1
View File
@@ -726,7 +726,8 @@ void dns_server_warn_downgrade(DnsServer *server) {
log_struct(LOG_NOTICE,
"MESSAGE_ID=" SD_MESSAGE_DNSSEC_DOWNGRADE_STR,
LOG_MESSAGE("Server %s does not support DNSSEC, downgrading to non-DNSSEC mode.", strna(dns_server_string_full(server))),
LOG_MESSAGE("Server %s does not support DNSSEC, downgrading to non-DNSSEC mode.",
strna(dns_server_string_full(server))),
"DNS_SERVER=%s", strna(dns_server_string_full(server)),
"DNS_SERVER_FEATURE_LEVEL=%s", dns_server_feature_level_to_string(server->possible_feature_level));
src/resolve/resolved-dns-transaction.c
+2 -1
View File
@@ -394,7 +394,8 @@ void dns_transaction_complete(DnsTransaction *t, DnsTransactionState state) {
log_struct(LOG_NOTICE,
"MESSAGE_ID=" SD_MESSAGE_DNSSEC_FAILURE_STR,
LOG_MESSAGE("DNSSEC validation failed for question %s: %s", key_str, dnssec_result_to_string(t->answer_dnssec_result)),
LOG_MESSAGE("DNSSEC validation failed for question %s: %s",
key_str, dnssec_result_to_string(t->answer_dnssec_result)),
"DNS_TRANSACTION=%" PRIu16, t->id,
"DNS_QUESTION=%s", key_str,
"DNSSEC_RESULT=%s", dnssec_result_to_string(t->answer_dnssec_result),
src/test/test-log.c
+10 -5
View File
@@ -31,16 +31,21 @@ static void test_log_struct(void) {
"MESSAGE=Waldo PID="PID_FMT" (no errno)", getpid_cached(),
"SERVICE=piepapo");
log_struct_errno(LOG_INFO, EILSEQ,
"MESSAGE=Waldo PID="PID_FMT": %m (normal)", getpid_cached(),
/* The same as above, just using LOG_MESSAGE(), which is generally recommended */
log_struct(LOG_INFO,
LOG_MESSAGE("Waldo PID="PID_FMT" (no errno)", getpid_cached()),
"SERVICE=piepapo");
log_struct_errno(LOG_INFO, EILSEQ,
LOG_MESSAGE("Waldo PID="PID_FMT": %m (normal)", getpid_cached()),
"SERVICE=piepapo");
log_struct_errno(LOG_INFO, SYNTHETIC_ERRNO(EILSEQ),
"MESSAGE=Waldo PID="PID_FMT": %m (synthetic)", getpid_cached(),
"SERVICE=piepapo");
LOG_MESSAGE("Waldo PID="PID_FMT": %m (synthetic)", getpid_cached()),
"SERVICE=piepapo");
log_struct(LOG_INFO,
"MESSAGE=Foobar PID="PID_FMT, getpid_cached(),
LOG_MESSAGE("Foobar PID="PID_FMT, getpid_cached()),
"FORMAT_STR_TEST=1=%i A=%c 2=%hi 3=%li 4=%lli 1=%p foo=%s 2.5=%g 3.5=%g 4.5=%Lg",
(int) 1, 'A', (short) 2, (long int) 3, (long long int) 4, (void*) 1, "foo", (float) 2.5f, (double) 3.5, (long double) 4.5,
"SUFFIX=GOT IT");
src/timesync/timesyncd-manager.c
+2 -1
View File
@@ -620,7 +620,8 @@ static int manager_receive_response(sd_event_source *source, int fd, uint32_t re
m->synchronized = true;
log_struct(LOG_INFO,
LOG_MESSAGE("Initial clock synchronization to %s.", FORMAT_TIMESTAMP_STYLE(dts.realtime, TIMESTAMP_US)),
LOG_MESSAGE("Initial clock synchronization to %s.",
FORMAT_TIMESTAMP_STYLE(dts.realtime, TIMESTAMP_US)),
"MESSAGE_ID=" SD_MESSAGE_TIME_SYNC_STR,
"MONOTONIC_USEC=" USEC_FMT, dts.monotonic,
"REALTIME_USEC=" USEC_FMT, dts.realtime,
src/udev/udevadm-settle.c
+1 -1
View File
@@ -150,7 +150,7 @@ static int emit_deprecation_warning(void) {
return -ENOMEM;
log_struct(LOG_NOTICE,
"MESSAGE=systemd-udev-settle.service is deprecated. Please fix %s not to pull it in.", t,
LOG_MESSAGE("systemd-udev-settle.service is deprecated. Please fix %s not to pull it in.", t),
"OFFENDING_UNITS=%s", t,
"MESSAGE_ID=" SD_MESSAGE_SYSTEMD_UDEV_SETTLE_DEPRECATED_STR);
}