Bugzilla will be upgraded to version 5.0. The upgrade date is tentatively scheduled for 2 December 2018, pending final testing and feedback.
Bug 1420505 - Using "systemd.log_level=debug systemd.log_target=kmsg" causes systemd to send "Executing: ..." message to remote clients. [NEEDINFO]
Using "systemd.log_level=debug systemd.log_target=kmsg" causes systemd to sen...
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: systemd (Show other bugs)
7.3
All Linux
unspecified Severity high
: rc
: ---
Assigned To: Jan Synacek
Frantisek Sumsal
:
Depends On:
Blocks: 1298243 1420851 1466365 1420515
  Show dependency treegraph
 
Reported: 2017-02-08 15:37 EST by Bryan Mason
Modified: 2018-04-10 07:20 EDT (History)
8 users (show)

See Also:
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 07:19:30 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---
jsynacek: needinfo? (sursingh)


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Knowledge Base (Solution) 2895521 None None None 2017-02-20 15:25 EST
Red Hat Product Errata RHBA-2018:0711 None None None 2018-04-10 07:20 EDT

  None (edit)
Description Bryan Mason 2017-02-08 15:37:00 EST
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.
Comment 1 Bryan Mason 2017-02-16 18:36:58 EST
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();
}
Comment 2 Bryan Mason 2017-02-16 18:49:32 EST
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;
}
Comment 3 Bryan Mason 2017-02-20 13:50:33 EST
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.
Comment 4 Bryan Mason 2017-02-20 15:10:40 EST
(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.
Comment 5 Suraj Jitindar Singh 2017-05-24 20:58:37 EDT
This has been fixed in systemd release 233. A backport may be appropriate.
Comment 6 Jan Synacek 2017-05-25 04:26:28 EDT
(In reply to Suraj Jitindar Singh from comment #5)
> This has been fixed in systemd release 233. A backport may be appropriate.

Where?
Comment 7 Suraj Jitindar Singh 2017-05-26 02:02:02 EDT
Upstream: www.freedesktop.org/wiki/Software/systemd
Comment 8 Jan Synacek 2017-05-29 01:18:09 EDT
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.
Comment 11 Bryan Mason 2017-08-17 13:30:00 EDT
Whoops.  I never linked this to the upstream issue I opened:

https://github.com/systemd/systemd/issues/5401
Comment 12 Bryan Mason 2017-08-17 13:31:50 EDT
And here's the commit that closed that issue:

https://github.com/systemd/systemd/commit/48a601f
Comment 13 Jan Synacek 2017-08-18 04:47:42 EDT
https://github.com/lnykryn/systemd-rhel/pull/132
Comment 15 Lukáš Nykrýn 2017-09-07 09:52:56 EDT
fix merged to upstream staging branch -> https://github.com/lnykryn/systemd-rhel/pull/132 -> post
Comment 21 errata-xmlrpc 2018-04-10 07:19:30 EDT
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

Note You need to log in before you can comment on or make changes to this bug.