Bug 1420505
| Summary: | Using "systemd.log_level=debug systemd.log_target=kmsg" causes systemd to send "Executing: ..." message to remote clients. | |||
|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | Bryan Mason <bmason> | |
| Component: | systemd | Assignee: | Jan Synacek <jsynacek> | |
| Status: | CLOSED ERRATA | QA Contact: | Frantisek Sumsal <fsumsal> | |
| Severity: | high | Docs Contact: | ||
| Priority: | unspecified | |||
| Version: | 7.3 | CC: | fsumsal, james.hofmeister, jsynacek, ktordeur, kwalker, michael.chisholm, sursingh, systemd-maint-list | |
| Target Milestone: | rc | |||
| Target Release: | --- | |||
| Hardware: | All | |||
| OS: | Linux | |||
| Whiteboard: | ||||
| Fixed In Version: | systemd-219-44.el7 | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | ||
| Clone Of: | ||||
| : | 1420515 (view as bug list) | Environment: | ||
| Last Closed: | 2018-04-10 11:19:30 UTC | Type: | Bug | |
| Regression: | --- | Mount Type: | --- | |
| Documentation: | --- | CRM: | ||
| Verified Versions: | Category: | --- | ||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | ||
| Cloudforms Team: | --- | Target Upstream Version: | ||
| Embargoed: | ||||
| Bug Depends On: | ||||
| Bug Blocks: | 1298243, 1420515, 1420851, 1466365 | |||
This issue occurs because exec_child() sets its UID to the User specified in the unit file. With LogTarget=kmsg set . . .
if (_unlikely_(log_get_max_level() >= LOG_DEBUG)) {
_cleanup_free_ char *line;
line = exec_command_line(final_argv);
if (line) {
log_open();
. . . the call to log_open() ends up calling log_open_kmsg() which fails because the user "lp" doesn't have the privilege to open /dev/kmsg. As a result, log_open_console() is called, and because are not PID 1, console_fd is set to STDERR_FILENO, which is the socket_fd.
log_unit_struct(params->unit_id,
LOG_DEBUG,
"EXECUTABLE=%s", command->path,
LOG_MESSAGE("Executing: %s", line),
NULL);
As a result, log_unit_struct() ends up sending the message to the socket_fd, which is connected to our remote client, which isn't expecting this.
static int log_open_console(void) {
if (console_fd >= 0)
return 0;
if (getpid() == 1) {
console_fd = open_terminal("/dev/console",
O_WRONLY|O_NOCTTY|O_CLOEXEC);
if (console_fd < 0)
return console_fd;
} else
console_fd = STDERR_FILENO;
return 0;
}
static int log_open_kmsg(void) {
if (kmsg_fd >= 0)
return 0;
kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC);
if (kmsg_fd < 0)
return -errno;
return 0;
}
int log_open(void) {
if ((log_target != LOG_TARGET_AUTO && log_target != LOG_TARGET_SAFE) ||
getpid() == 1 ||
isatty(STDERR_FILENO) <= 0) {
if (log_target == LOG_TARGET_AUTO ||
log_target == LOG_TARGET_SAFE ||
log_target == LOG_TARGET_JOURNAL_OR_KMSG ||
log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
log_target == LOG_TARGET_KMSG) {
r = log_open_kmsg();
if (r >= 0) {
log_close_journal();
log_close_syslog();
log_close_console();
return r;
}
}
}
log_close_journal();
log_close_syslog();
return log_open_console();
}
Could we do this in log_open_console() to avoid this:
static int log_open_console(void) {
if (console_fd >= 0)
return 0;
if (getpid() == 1) {
console_fd = open_terminal("/dev/console",
O_WRONLY|O_NOCTTY|O_CLOEXEC);
if (console_fd < 0)
return console_fd;
} else {
struct stderr_stat;
fstat(STDERR_FILENO, &stderr_stat);
if ( (stderr_stat.st_mode & S_IFMT) == S_IFSOCK )
return -1; // or some appropriate error code
else
console_fd = STDERR_FILENO;
}
return 0;
}
Adding
StandardError=journal
to /usr/lib/systemd/system/cups-lpd.socket also works around the problem. Although if the journal isn't running, the message will got to the socket as before.
(In reply to Bryan Mason from comment #3) > Adding > > StandardError=journal > > to /usr/lib/systemd/system/cups-lpd.socket also works around the problem. > Although if the journal isn't running, the message will got to the socket as > before. The file being modified is, of course /usr/lib/systemd/system/cups-lpd@.service, not cups-lpd.socket. This has been fixed in systemd release 233. A backport may be appropriate. (In reply to Suraj Jitindar Singh from comment #5) > This has been fixed in systemd release 233. A backport may be appropriate. Where? Upstream: www.freedesktop.org/wiki/Software/systemd Well, no. Since you wrote that this has been fixed, you should back it up with a link to the patch or pull request in which it was fixed. That's what I meant by "Where?", sorry, I should have made it clear. Whoops. I never linked this to the upstream issue I opened: https://github.com/systemd/systemd/issues/5401 And here's the commit that closed that issue: https://github.com/systemd/systemd/commit/48a601f fix merged to upstream staging branch -> https://github.com/lnykryn/systemd-rhel/pull/132 -> post Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2018:0711 The needinfo request[s] on this closed bug have been removed as they have been unresolved for 500 days |
Description of problem: When LogLevel=debug and LogTarget=kmsg, systemd will send the message "Executing: /path/to/exececutable" to the socket that is connected to the remote client in a socket-based activation unit. Version-Release number of selected component (if applicable): systemd-219-30.el7_3.6 How reproducible: 100% Steps to Reproduce: 1. Set LogLevel=debug and LogTarget=kmsg, either through system.conf file or the kernel command-line (as described in https://freedesktop.org/wiki/Software/systemd/Debugging/) 2. Enable a socket-based service, like cups-lpd. 3. Use telnet to connect to the socket based service. Actual results: # telnet 127.0.0.1 515 Trying 127.0.0.1... Connected to 127.0.0.1. Escape character is '^]'. Executing: /usr/lib/cups/daemon/cups-lpd Expected results: The "Executing: /usr/lib/cups/daemon/cups-lpd" message should not be displayed. Additional info: This is causing a real-world problem with remote LPD clients connecting to RHEL. The "Executing..." message violates the LPD protocol as described in RFC 1179.