"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).
[...]
> Bug description:
> "ssh localhost exit"
>
> takes edges on lucid
[...]
Ouch, sorry. I meant "ages" above.
--
Stephane