update-motd executed even in non-interactive sessions

Bug #587858 reported by Stephane Chazelas
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
mountall (Ubuntu)
Low
Dustin Kirkland 
openssh (Ubuntu)
Medium
Unassigned

Bug Description

"ssh localhost exit"

takes edges on lucid

(ii libpam-modules 1.1.1-2ubuntu2 Pluggable Authentication Modules for PAM
ii openssh-server 1:5.3p1-3ubuntu3 secure shell (SSH) server, for secure access from remote machines
)

Because /etc/motd is updated even though it is not displayed as we're running a command non-interactively.

Example timing for running "ssh localhost 'exit 3'" (using strace -tt -fe execve):

11089 10:50:23.149350 execve("/usr/sbin/sshd", ["/usr/sbin/sshd", "-R"], [/* 4 vars */]) = 0
11091 10:50:23.525659 execve("/bin/sh", ["sh", "-c", "run-parts --lsbsysinit /etc/upda"...], [/* 4 vars */]) = 0
11092 10:50:23.548468 execve("/bin/run-parts", ["run-parts", "--lsbsysinit", "/etc/update-motd.d"], [/* 5 vars */]) = 0
11093 10:50:23.564947 execve("/etc/update-motd.d/00-header", ["/etc/update-motd.d/00-header"], [/* 5 vars */]) = 0
11094 10:50:23.571854 execve("/bin/uname", ["uname", "-a"], [/* 5 vars */]) = 0
11095 10:50:23.589084 execve("/usr/bin/lsb_release", ["lsb_release", "-s", "-d"], [/* 5 vars */]) = 0
11097 10:50:24.077419 execve("/etc/update-motd.d/10-help-text", ["/etc/update-motd.d/10-help-text"], [/* 5 vars */]) = 0
11098 10:50:24.097081 execve("/bin/uname", ["uname", "-r"], [/* 5 vars */]) = 0
11100 10:50:24.108702 execve("/bin/grep", ["grep", "-qs", "\\-server"], [/* 5 vars */]) = 0
11101 10:50:24.124869 execve("/etc/update-motd.d/20-cpu-checker", ["/etc/update-motd.d/20-cpu-checke"...], [/* 5 vars */]) = 0
11101 10:50:24.137645 execve("/usr/lib/update-notifier/update-motd-cpu-checker", ["/usr/lib/update-notifier/update-"...], [/* 5 vars */]) = 0
11102 10:50:24.158758 execve("/usr/bin/check-bios-nx", ["/usr/bin/check-bios-nx"], [/* 5 vars */]) = 0
11103 10:50:24.180763 execve("/usr/bin/getopt", ["getopt", "-o", "h", "--long", "verbose,help", "-n", "check-bios-nx", "--"], [/* 6 vars */]) = 0
11104 10:50:24.204348 execve("/usr/bin/awk", ["awk", "-f", "-", "/proc/cpuinfo"], [/* 7 vars */]) = 0
11106 10:50:24.231468 execve("/bin/sh", ["sh", "-c", "uname -m"], [/* 7 vars */]) = 0
11107 10:50:24.238869 execve("/bin/uname", ["uname", "-m"], [/* 7 vars */]) = 0
11108 10:50:24.254079 execve("/etc/update-motd.d/50-landscape-sysinfo", ["/etc/update-motd.d/50-landscape-"...], [/* 5 vars */]) = 0
11109 10:50:24.262037 execve("/bin/date", ["/bin/date"], [/* 5 vars */]) = 0
11110 10:50:24.285766 execve("/usr/bin/landscape-sysinfo", ["/usr/bin/landscape-sysinfo"], [/* 5 vars */]) = 0
11118 10:50:26.755870 execve("/usr/local/sbin/who", ["who", "-q"], [/* 5 vars */]) = -1 ENOENT (No such file or directory)
11118 10:50:26.756061 execve("/usr/local/bin/who", ["who", "-q"], [/* 5 vars */]) = -1 ENOENT (No such file or directory)
11118 10:50:26.756227 execve("/usr/bin/who", ["who", "-q"], [/* 5 vars */]) = 0
11120 10:50:26.847832 execve("/etc/update-motd.d/90-updates-available", ["/etc/update-motd.d/90-updates-av"...], [/* 5 vars */]) = 0
11120 10:50:26.853820 execve("/usr/lib/update-notifier/update-motd-updates-available", ["/usr/lib/update-notifier/update-"...], [/* 5 vars */]) = 0
11121 10:50:26.872259 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/update-notifier/updates"...], [/* 5 vars */]) = 0
11122 10:50:26.904240 execve("/usr/bin/apt-config", ["apt-config", "shell", "StateDir", "Dir::State"], [/* 5 vars */]) = 0
11123 10:50:26.961484 execve("/usr/bin/apt-config", ["apt-config", "shell", "ListDir", "Dir::State::Lists"], [/* 5 vars */]) = 0
11124 10:50:26.987301 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//_var_cache_"...], [/* 5 vars */]) = 0
11125 10:50:26.997297 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//xxxx"...], [/* 5 vars */]) = 0
11126 10:50:27.007091 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11127 10:50:27.017322 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11128 10:50:27.027804 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11129 10:50:27.046944 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11130 10:50:27.056748 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11131 10:50:27.066563 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11132 10:50:27.076351 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11133 10:50:27.086191 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11134 10:50:27.096436 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11135 10:50:27.106932 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11136 10:50:27.117383 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11137 10:50:27.127606 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11138 10:50:27.137525 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11139 10:50:27.147736 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11140 10:50:27.157878 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11141 10:50:27.167967 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11142 10:50:27.177737 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11143 10:50:27.188369 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11144 10:50:27.207926 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11145 10:50:27.217981 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11146 10:50:27.227792 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11147 10:50:27.237580 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11148 10:50:27.247394 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11149 10:50:27.257207 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//gb.archive."...], [/* 5 vars */]) = 0
11150 10:50:27.266990 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//lock"], [/* 5 vars */]) = 0
11151 10:50:27.276867 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11152 10:50:27.287062 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11153 10:50:27.297185 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11154 10:50:27.307305 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11155 10:50:27.317158 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11156 10:50:27.327563 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11157 10:50:27.337975 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11158 10:50:27.348311 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11159 10:50:27.359898 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11160 10:50:27.370357 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/var/lib/apt//lists//security.ub"...], [/* 5 vars */]) = 0
11161 10:50:27.389590 execve("/usr/bin/apt-config", ["apt-config", "shell", "EtcDir", "Dir::Etc"], [/* 5 vars */]) = 0
11162 10:50:27.410072 execve("/usr/bin/apt-config", ["apt-config", "shell", "SourceList", "Dir::Etc::sourcelist"], [/* 5 vars */]) = 0
11163 10:50:27.429973 execve("/usr/bin/stat", ["stat", "-c", "%Y", "/etc/apt//sources.list"], [/* 5 vars */]) = 0
11164 10:50:27.439375 execve("/bin/cat", ["cat", "/var/lib/update-notifier/updates"...], [/* 5 vars */]) = 0
11165 10:50:27.453952 execve("/etc/update-motd.d/98-reboot-required", ["/etc/update-motd.d/98-reboot-req"...], [/* 5 vars */]) = 0
11165 10:50:27.459519 execve("/usr/lib/update-notifier/update-motd-reboot-required", ["/usr/lib/update-notifier/update-"...], [/* 5 vars */]) = 0
11166 10:50:27.467000 execve("/bin/cat", ["cat", "/var/run/reboot-required"], [/* 5 vars */]) = 0
11167 10:50:27.473373 execve("/etc/update-motd.d/99-footer", ["/etc/update-motd.d/99-footer"], [/* 5 vars */]) = 0
11168 10:50:27.506644 execve("/bin/bash", ["bash", "-c", "exit 3"], [/* 9 vars */]) = 0

Over 4 seconds and 73 commands executed just to run a no-op.

Even when running ssh interactively (ssh localhost), that kind of delay feels a bit too much. The update-motd(5) man page recommends long-running commands to cache their output, I'm not under the impressions it is done. But that'd be another bug.

Another bug would be that finding out what and how is causing that is not straightforward.

It appears it's pam_motd (called from /etc/pam.d/sshd) that does that, and there's no reference to it in pam_motd(8).

Also note that with a ~/.hushlogin (meant to suppress the output of /etc/motd), update-motd is still performed.

A fix would be to only call pam_motd for interactive shell sessions. Maybe a fix in libpam-modules for it to only do the update-motd if the output goes to a terminal (or at least an option for it to behave like that).

Chuck Short (zulcss)
affects: openssh (Ubuntu) → update-motd (Ubuntu)
Revision history for this message
Stephane Chazelas (stephane-chazelas) wrote : Re: [Bug 587858] Re: update-motd executed even in non-interactive sessions

[...]
> Bug description:
> "ssh localhost exit"
>
> takes edges on lucid
[...]

Ouch, sorry. I meant "ages" above.

--
Stephane

Revision history for this message
Dustin Kirkland  (kirkland) wrote :

The update-motd package is no more. pam_motd is provided by pam now.

affects: update-motd (Ubuntu) → pam (Ubuntu)
Steve Langasek (vorlon)
Changed in pam (Ubuntu):
assignee: nobody → Dustin Kirkland (kirkland)
Changed in pam (Ubuntu):
importance: Undecided → High
status: New → In Progress
Changed in mountall (Ubuntu):
status: New → In Progress
importance: Undecided → Low
assignee: nobody → Dustin Kirkland (kirkland)
status: In Progress → Fix Committed
Revision history for this message
Dustin Kirkland  (kirkland) wrote :

Patch to pam developed, tested, and pushed to lp:~kirkland/+junk/587858. Awaiting a quick review by Steve before uploading to Maverick.

Revision history for this message
Stephane Chazelas (stephane-chazelas) wrote :

2010-07-22 17:28:48 -0000, Dustin Kirkland:
> Patch to pam developed, tested, and pushed to lp:~kirkland/+junk/587858.
> Awaiting a quick review by Steve before uploading to Maverick.
[...]

Note that though this fix would be an improvement, in my
opinion, it's a fix to another bug like "the result of
update-motd is not cached". This bug is about motd being
computed in non-interactive non-login ssh sessions where
motd is not even displayed.

Maybe a fix/wa could be implemented by doing a
pam_putenv("PAM_NONLOGINSESSION=") in sshd upon non-login
sessions or hushedlogin ones and have pam_motd skip the
update-motd in that case.

Or split into two services sshd-login and sshd with
/etc/pam.d/sshd-login including sshd and adding the pam_motd...

Cheers,
Stephane

Revision history for this message
Dustin Kirkland  (kirkland) wrote : Re: [Bug 587858] Re: update-motd executed even in non-interactive sessions

Stephane-

Understood, Steve Langasek and I discussed this.

The current design does "fix" PAM a bit differently than this bug
requests. However, the net effect accomplishes what I think this
report desires: that non-interactive login should not block on
updating the motd.

Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package mountall - 2.18

---------------
mountall (2.18) maverick; urgency=low

  [ Dustin Kirkland ]
  * conf/mounted-varrun.conf: seed /var/run/motd on boot, to ensure that
    initial logins are quick, LP: #587858

  [ Steve Langasek ]
  * Don't check /etc/environment for locale settings; this is an obsolete
    usage we transitioned away from years ago.
  * Add LC_ALL to the list of exported locale variables.

  [ Colin Watson ]
  * Flush standard output and error before daemonising, so that we don't get
    three copies of our early debug output.
  * If a mountpoint is a symlink to another mountpoint, add a dependency on
    the link target rather than trying to mount it again and failing
    (LP: #541512).
 -- Colin Watson <email address hidden> Fri, 24 Sep 2010 10:52:20 +0100

Changed in mountall (Ubuntu):
status: Fix Committed → Fix Released
Changed in pam (Ubuntu):
assignee: Dustin Kirkland (kirkland) → nobody
Steve Langasek (vorlon)
Changed in pam (Ubuntu):
status: In Progress → Triaged
Revision history for this message
Steve Langasek (vorlon) wrote :

I've looked into pam_motd, and found that it already has this code at the top of the call:

    if (flags & PAM_SILENT) {
        return retval;
    }

So I think this is an openssh issue - openssh ought to be setting PAM_SILENT in cases where it doesn't plan to show PAM_TEXT_INFO messages, so that the PAM modules don't waste their time.

affects: pam (Ubuntu) → openssh (Ubuntu)
Changed in openssh (Ubuntu):
importance: High → Medium
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers