apt-check hangs, preventing login via SSH

Bug #525674 reported by Martin-Éric Racine
60
This bug affects 9 people
Affects Status Importance Assigned to Milestone
update-notifier (Ubuntu)
Fix Released
Medium
Unassigned
Nominated for Trusty by Mathew Hodson
Declined for Vivid by Martin Pitt
Nominated for Wily by Mathew Hodson

Bug Description

Binary package hint: update-notifier

While investigating protracted hangs in the remote login process, I noticed that apt-check is called to update the list of available updates and print the number of updatable packages in the MOTD. As it so happens, apt-check often hangs in mid-update, which effectively prevents remote login via SSH from taking place.

Related bugs:
 * bug 525674: apt-check hangs, preventing login via SSH
 * bug 1527710: apt-get update triggers asynchronous task
 * bug 1533243: preseeded installation fails on critical question: partman/unmount_active DISKS /dev/vda

ProblemType: Bug
Architecture: i386
Date: Mon Feb 22 12:20:16 2010
DistroRelease: Ubuntu 10.04
Package: update-notifier-common 0.96
PackageArchitecture: all
ProcEnviron:
 LANGUAGE=fi_FI.UTF-8
 PATH=(custom, user)
 LANG=fi_FI.UTF-8
 SHELL=/bin/bash
ProcVersionSignature: Ubuntu 2.6.32-14.20-generic
SourcePackage: update-notifier
Uname: Linux 2.6.32-14-generic i686

Related branches

Revision history for this message
Martin-Éric Racine (q-funk) wrote :
Revision history for this message
Martin-Éric Racine (q-funk) wrote :

Subscribed Ubuntu Server Team as this is an issue that prevents remote servicing of Lucid hosts.

Revision history for this message
Scott Moser (smoser) wrote :

I was about to file this bug, so I'll confirm it. I have not seen the apt-check hang entirely, but it is very slow to run, and blocks initial.

Note, you may have seen what appeared to be a hang due to the very bad performance of security.ubuntu.com in the past few days. That performance was due to it being slammed by openoffice.org security update.

This is quite an annoyance on a newly booted ec2 instance.

Changed in update-notifier (Ubuntu):
importance: Undecided → Medium
status: New → Confirmed
tags: added: ec2-images uec-images
Revision history for this message
danmb (danmbox) wrote :

What connects loging in to running update-notifier? I'd like to disable that (especially for SSH logins) without removing update-notifier completely.

Revision history for this message
danmb (danmbox) wrote :

To answer self, there are pam_motd references in /etc/pam.d/{login,ssh} (!). 'Cause hey, you never know when you need that important ssh session or CONSOLE login delayed for a while...

And since the very same friendly developers will be in charge of the next release (and the next one after that), there's no telling how many more pleasant surprises like this one we will have the next time we upgrade. Of course they never tell you how to disable these "surprises" in the RELEASE NOTES -- that would spoil the fun. They like you spending time treasure-hunting the goodies they hide in various dark corners of the distro.

Revision history for this message
RichardNeill (ubuntu-richardneill) wrote :

This is really painful - although I don't experience complete hangs, I do experience 12-second+ delays while
the script "90-updates-available" grinds slowly though. So login via SSH is unpleasantly slow. Furthermore, bash completion for tab completion on scp commands is also very slow.

The workaround is: chmod -x /etc/update-motd.d/*

However, it seems to me that this should be a cron-job which runs once an hour (and @reboot). There's no need for it to happen at the precise moment where I log in.

Revision history for this message
RichardNeill (ubuntu-richardneill) wrote :

(P.S. Even worse is connecting via a stack of SSH tunnels, eg behind a firewall. It takes almost 30 seconds to get a prompt, and ssh -vvv doesn't help identify the issue).

Revision history for this message
RichardNeill (ubuntu-richardneill) wrote :

Interestingly, 14.04 seems to be much better at this than 12.04, takling around 1.5 sec rather than 12.
However, it's interesting how much faster it can still be without this.

Here is a measurement I made. This is 14.04 server on the LAN, with ssh-key authentication, and I repeated serveral times:
   time ssh server_on_lan true

With the /etc/update-motd.d/* files unaltered, this takes ~ 1.13 sec
After chmod -x, this takes ~ 0.15 sec.

I hope that helps,

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Other MOTD plugins use caching, for example /usr/lib/update-notifier/update-motd-reboot-required does:
if [ -f /var/run/reboot-required ]; then
        cat /var/run/reboot-required
fi

Actually /usr/lib/update-notifier/update-motd-updates-available already uses "caching" like the others.
It stores its result in:
  /var/lib/update-notifier/updates-available
This is what the call to "/usr/lib/update-notifier/apt-check --human-readable" writes into

But it executes slow commands like find apt-check synchronously.
Yes a cron job might be nice, but it is rather "invasive" in changing the general behaviour maybe more than required.

Why not just executing the "slow parts" like find and apt-check asynchronously.
One can still evolve that approach later on an move (instead or additionally) the async part into a cron job if required.

It comes at "the risk" of having one outdated info on login.
But since updates don't change every second anyway it is probably better than waiting on each login.
Especially with all the examples made like scp tabbing, slow network and so on.

The atomicity issue with updating the temporary file already exists in todays code with regards to concurrent logins. But we can improve that as well by using a temporary file and mv.

The following are suggestions to fix it in trusty, vivid, wily and upstream.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :
Revision history for this message
Christian Ehrhardt  (paelzer) wrote :
Revision history for this message
Ubuntu Foundations Team Bug Bot (crichton) wrote :

The attachment "Fix for trusty" seems to be a debdiff. The ubuntu-sponsors team has been subscribed to the bug report so that they can review and hopefully sponsor the debdiff. If the attachment isn't a patch, please remove the "patch" flag from the attachment, remove the "patch" tag, and if you are member of the ~ubuntu-sponsors, unsubscribe the team.

[This is an automated message performed by a Launchpad user owned by ~brian-murray, for any issue please contact him.]

tags: added: patch
Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

FYI - After a discussion I'll likely revamp the patches for wily and upstream the next days.
Until then we will also decide if this is worth SRUs for trusty/vivid.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Here the bigger, but more architecturally complete solution for wily&upstream (which is actually identical at this time).

Summary:
- move the actual updating part out of the pam based trigger completely (avoids slowdown)
- pam based motd now only prints the cached info (if existing)
- hook into apt with APT::Update::Post-Invoke-Success to update the cached file (thanks mvo and pitti for that good IRC discussion)
- removed one level of indirection (apt hook -> stamp file -> on pam login check stamp -> update) to the more separate
  (apt hook -> update cached info) (on pam login -> print cached info)
- while the chance of a concurrent update is now (almost) impossible it keeps the atomic cache update and cleanup to be sure

It was working find in all my builds and tests on wily.
Attaching for review ...

Revision history for this message
Martin Pitt (pitti) wrote :

Thanks Christian! Some remarks:

 - The introduction of data/get-motd-updates-available seems like an unnecessary indirection to me. Instead of checking the executability of that and run it, debian/90-updates-available could just directly do

  cat /var/lib/update-notifier/updates-available 2>/dev/null || true

or

  [ ! -r /var/lib/update-notifier/updates-available ] || cat /var/lib/update-notifier/updates-available

if you prefer that. This would be simpler IMHO.

 - changelog should point out that data/update-motd-updates-available now runs in the background, to avoid blocking "apt-get update" unnecessarily long.

These are just nitpicks, this looks fine by and large. Thanks for working on this!

Revision history for this message
Michael Vogt (mvo) wrote :

Thanks for working on this! Diff looks good (pitti pointed some minor things out already).

One more thing, please keep the part:
  "DPkg::Post-Invoke {"if [ -d /var/lib/update-notifier ]; then touch /var/lib/update-notifier/dpkg-run-stamp; fi; "
the part of update-notifier that displays a icon (used in xfce iirc) will depend on this file, it uses inotify to know reliable when apt was finished.

Revision history for this message
Scott Moser (smoser) wrote :

hey. saw this in my inbox, and very happy! thank you for working on this.

one note, in update-notifier-3.164/data/update-motd-updates-available

+ trap cleanup EXIT
+ tmpfile=$(mktemp)

if tmpfile was set in the environment prior to this program running, and you exited for some reason between those two, then you'd rm the previously set 'tmpfile'.

the easy fix is to just declare 'tmpfile=' before trapping cleanup.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Martin:
- I already removed one indirection with my former patch and love to remove one more.
  Simple code = good code - thanks for the good hint.
- I changed it slightly to use the existing variable so people recognize from which code
  it came and to avoid issues if one ever changes only one occurrence of that file name.
- changelog now contains the original intention (no stall to logins) and the avoidance of
  stalling apt-get update along with all other minor fixes that came up along the way

Michael:
- Good catch, I didn't realize that this were two totally independent pieces.

Scott:
- Another good catch, of a potentially rare but nasty to track down issue

Overall I want to thank all reviewers a lot - I highly appreciate this real community feeling.
The patch got way better and smaller at once.
Thank You!

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :
Revision history for this message
Scott Moser (smoser) wrote :

looks good to me.

Revision history for this message
Martin Pitt (pitti) wrote :

Thank you! Uploaded.

Changed in update-notifier (Ubuntu):
status: Confirmed → Fix Committed
Revision history for this message
Launchpad Janitor (janitor) wrote :

This bug was fixed in the package update-notifier - 3.164

---------------
update-notifier (3.164) xenial; urgency=medium

  * debian/90-updates-available
    - Now directly prints the cached info if available
      => avoid login stalls due to motd updates (LP: #525674)
    - Also fixes a former potential issue of existing but not readable cached
      info by changing the test from -e to -r
  * debian/99update-notifier:
    - Now additionally triggers the an asynchronous background update of the
      cached info via update-motd-updates-available hooking into
      APT::Update::Post-Invoke-Success.
  * data/update-motd-updates-available:
    - This now only contains the slow part of actually 'updating the cached
      info'.
    - It executes asynchronously to avoid stalling apt-get update.
    - The file is no more called by pam to avoid login stalls.
    - It also fixes an issue with concurrent updates clobbering the
      cached file via mv being atomic

 -- Christian Ehrhardt <email address hidden> Fri, 13 Nov 2015 12:28:25 +0100

Changed in update-notifier (Ubuntu):
status: Fix Committed → Fix Released
Scott Moser (smoser)
description: updated
Scott Moser (smoser)
description: updated
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.