[Bug 986183] Re: Broken timedate handling for failed hook runs

Steve Langasek steve.langasek at canonical.com
Tue Jun 5 21:33:11 UTC 2012 

I've verified this bugfix using the test case added to the bug
description.

** Description changed:

+ [Test Case]
+ 1. As root, run:
+ cat > /usr/share/package-data-downloads/test-failure
+ Url: http://doesnotexist.example.com/
+ Sha256: b732d5a4f4b122efb676d7bcb564fad58b0ca0bb22d9da18089d847c17533537
+ 
+ Script: /bin/true
+ ^D
+ 2. Run 'sudo /usr/lib/update-notifier/package-data-downloader'
+ 3. Confirm that the file /var/lib/update-notifier/package-data-downloads/test-failure.failed has been created.
+ 4. Run 'sudo date -d "now + 4 days" to set the clock in the future
+ 5. Run 'sudo /usr/lib/update-notifier/package-data-downloader' again
+ 6. Confirm that /var/lib/update-notifier/package-data-downloads/test-failure.failed still exists, and has not been replaced with /var/lib/update-notifier/package-data-downloads/test-failure.permanent-failure
+ 7. Install the update-notifier-common package from precise-proposed
+ 8. Repeat steps 4 and 5
+ 9. Confirm that /var/lib/update-notifier/package-data-downloads/test-failure.permanent-failure now exists, and /var/lib/update-notifier/package-data-downloads/test-failure.failed no longer exists.
+ 10. run 'sudo service ntp stop; sudo ntpdate 0.ubuntu.pool.ntp.org; sudo service ntp start' to set your clock back to the correct time, and 'sudo rm /usr/share/package-data-downloads/test-failure /var/lib/update-notifier/package-data-downloads/test-failure*' to clean up the test files. 
+ 
  Hi,
  
  After some recent updates in precise, I've started receiving cron emails
  such as:
  
  Date: Tue, 17 Apr 2012 11:49:02 +0200 (CEST)
  Subject: Anacron job 'cron.daily' on bee
  
  /etc/cron.daily/update-notifier-common:
  flashplugin-installer: downloading
  http://archive.canonical.com/pool/partner/a/adobe-flashplugin/adobe-flashplugin_
  11.2.202.228.orig.tar.gz
  Installing from local file /tmp/tmppRl5Rq.gz
  Flash Plugin installed.
  
  Then the next day:
  Date: Wed, 18 Apr 2012 11:25:36 +0200 (CEST)
  Subject: Anacron job 'cron.daily' on bee
  
  /etc/cron.daily/update-notifier-common:
  flashplugin-installer: downloading
  http://archive.canonical.com/pool/partner/a/adobe-flashplugin/adobe-flashplugin_
  11.2.202.228.orig.tar.gz
  Installing from local file /tmp/tmpTeTtwA.gz
  Flash Plugin installed.
  
  Then after a day of silence:
  Date: Fri, 20 Apr 2012 07:38:09 +0200 (CEST)
  Subject: Anacron job 'cron.daily' on bee
  
  /etc/cron.daily/update-notifier-common:
  flashplugin-installer: downloading
  http://archive.canonical.com/pool/partner/a/adobe-flashplugin/adobe-flashplugin_
  11.2.202.233.orig.tar.gz
  Installing from local file /tmp/tmpZsCTV4.gz
  Flash Plugin installed.
  
  There were indeed some flashplugin updates that I applied in the last
  days, but notethat the first two emails are for the *same* version.  My
  laptop was probably in sleep over one night which might explain the day
  of silence.
  
  /usr/share/package-data-downloads/flashplugin-installer dates of the
  18th of April around midnight and /var/lib/update-notifier/package-data-
  downloads/flashplugin-installer of the 20th of April.
  
  So I don't see why this should have run on the 20th.
  
  But while checking the code, I believe I've actually found a bug in the handling of failed updates:
  def hook_aged_out(hook_name):
-         """Check if this hook has been failing consistently for >= 3 days"""
+         """Check if this hook has been failing consistently for >= 3 days"""
  
-         failure_file = os.path.join(STAMPDIR, hook_name + '.failed')
-         try:
-                 hook_date = os.stat(failure_file).st_ctime
-                 cur_time = os.times()[4]
-                 d = timedelta(microseconds=cur_time-hook_date)
-                 if d.days >= 3:
-                         return True
-         except OSError:
-                 pass
-         except Exception:
-                 traceback.print_exc(file=sys.stderr)
-         return False
+         failure_file = os.path.join(STAMPDIR, hook_name + '.failed')
+         try:
+                 hook_date = os.stat(failure_file).st_ctime
+                 cur_time = os.times()[4]
+                 d = timedelta(microseconds=cur_time-hook_date)
+                 if d.days >= 3:
+                         return True
+         except OSError:
+                 pass
+         except Exception:
+                 traceback.print_exc(file=sys.stderr)
+         return False
  
  os.times()[4] seems a completely bogus value for checking age:
  python -c 'from datetime import timedelta; import os; hook_date = os.stat("/var/lib/update-notifier/package-data-downloads/flashplugin-installer").st_ctime; cur_time = os.times()[4]; microseconds = cur_time - hook_date; d= timedelta(microseconds=microseconds); print d.days; print microseconds; print cur_time; print hook_date'
  -1
  -1315376334.45
  19523955.25
  1334900289.7
  
  (I used the successful stamp file rather than a failed stamp file, but
  it's the same problem.)
  
  I believe you want:
  python -c 'from datetime import datetime; import os; hook_date = datetime.fromtimestamp(os.stat("/var/lib/update-notifier/package-data-downloads/flashplugin-installer").st_ctime); cur_time = datetime.now(); d=cur_time - hook_date; print d.days; print cur_time; print hook_date'
  
  Cheers,
  
  ProblemType: Bug
  DistroRelease: Ubuntu 12.04
  Package: update-notifier-common 0.119ubuntu8
  ProcVersionSignature: Ubuntu 3.2.0-18.28-generic 3.2.9
  Uname: Linux 3.2.0-18-generic x86_64
  ApportVersion: 2.0.1-0ubuntu5
  Architecture: amd64
  Date: Fri Apr 20 15:02:17 2012
  PackageArchitecture: all
  ProcEnviron:
-  LANGUAGE=fr_FR:fr:en_GB:en
-  TERM=xterm
-  PATH=(custom, user)
-  LANG=fr_FR.UTF-8
-  SHELL=/bin/zsh
+  LANGUAGE=fr_FR:fr:en_GB:en
+  TERM=xterm
+  PATH=(custom, user)
+  LANG=fr_FR.UTF-8
+  SHELL=/bin/zsh
  SourcePackage: update-notifier
  UpgradeStatus: Upgraded to precise on 2009-12-07 (864 days ago)

** Tags removed: verification-needed
** Tags added: verification-done

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to update-notifier in Ubuntu.
https://bugs.launchpad.net/bugs/986183

Title:
  Broken timedate handling for failed hook runs

Status in “update-notifier” package in Ubuntu:
  Fix Released
Status in “update-notifier” source package in Precise:
  Fix Committed
Status in “update-notifier” source package in Quantal:
  Fix Released

Bug description:
  [Test Case]
  1. As root, run:
  cat > /usr/share/package-data-downloads/test-failure
  Url: http://doesnotexist.example.com/
  Sha256: b732d5a4f4b122efb676d7bcb564fad58b0ca0bb22d9da18089d847c17533537

  Script: /bin/true
  ^D
  2. Run 'sudo /usr/lib/update-notifier/package-data-downloader'
  3. Confirm that the file /var/lib/update-notifier/package-data-downloads/test-failure.failed has been created.
  4. Run 'sudo date -d "now + 4 days" to set the clock in the future
  5. Run 'sudo /usr/lib/update-notifier/package-data-downloader' again
  6. Confirm that /var/lib/update-notifier/package-data-downloads/test-failure.failed still exists, and has not been replaced with /var/lib/update-notifier/package-data-downloads/test-failure.permanent-failure
  7. Install the update-notifier-common package from precise-proposed
  8. Repeat steps 4 and 5
  9. Confirm that /var/lib/update-notifier/package-data-downloads/test-failure.permanent-failure now exists, and /var/lib/update-notifier/package-data-downloads/test-failure.failed no longer exists.
  10. run 'sudo service ntp stop; sudo ntpdate 0.ubuntu.pool.ntp.org; sudo service ntp start' to set your clock back to the correct time, and 'sudo rm /usr/share/package-data-downloads/test-failure /var/lib/update-notifier/package-data-downloads/test-failure*' to clean up the test files. 

  Hi,

  After some recent updates in precise, I've started receiving cron
  emails such as:

  Date: Tue, 17 Apr 2012 11:49:02 +0200 (CEST)
  Subject: Anacron job 'cron.daily' on bee

  /etc/cron.daily/update-notifier-common:
  flashplugin-installer: downloading
  http://archive.canonical.com/pool/partner/a/adobe-flashplugin/adobe-flashplugin_
  11.2.202.228.orig.tar.gz
  Installing from local file /tmp/tmppRl5Rq.gz
  Flash Plugin installed.

  Then the next day:
  Date: Wed, 18 Apr 2012 11:25:36 +0200 (CEST)
  Subject: Anacron job 'cron.daily' on bee

  /etc/cron.daily/update-notifier-common:
  flashplugin-installer: downloading
  http://archive.canonical.com/pool/partner/a/adobe-flashplugin/adobe-flashplugin_
  11.2.202.228.orig.tar.gz
  Installing from local file /tmp/tmpTeTtwA.gz
  Flash Plugin installed.

  Then after a day of silence:
  Date: Fri, 20 Apr 2012 07:38:09 +0200 (CEST)
  Subject: Anacron job 'cron.daily' on bee

  /etc/cron.daily/update-notifier-common:
  flashplugin-installer: downloading
  http://archive.canonical.com/pool/partner/a/adobe-flashplugin/adobe-flashplugin_
  11.2.202.233.orig.tar.gz
  Installing from local file /tmp/tmpZsCTV4.gz
  Flash Plugin installed.

  There were indeed some flashplugin updates that I applied in the last
  days, but notethat the first two emails are for the *same* version.
  My laptop was probably in sleep over one night which might explain the
  day of silence.

  /usr/share/package-data-downloads/flashplugin-installer dates of the
  18th of April around midnight and /var/lib/update-notifier/package-
  data-downloads/flashplugin-installer of the 20th of April.

  So I don't see why this should have run on the 20th.

  But while checking the code, I believe I've actually found a bug in the handling of failed updates:
  def hook_aged_out(hook_name):
          """Check if this hook has been failing consistently for >= 3 days"""

          failure_file = os.path.join(STAMPDIR, hook_name + '.failed')
          try:
                  hook_date = os.stat(failure_file).st_ctime
                  cur_time = os.times()[4]
                  d = timedelta(microseconds=cur_time-hook_date)
                  if d.days >= 3:
                          return True
          except OSError:
                  pass
          except Exception:
                  traceback.print_exc(file=sys.stderr)
          return False

  os.times()[4] seems a completely bogus value for checking age:
  python -c 'from datetime import timedelta; import os; hook_date = os.stat("/var/lib/update-notifier/package-data-downloads/flashplugin-installer").st_ctime; cur_time = os.times()[4]; microseconds = cur_time - hook_date; d= timedelta(microseconds=microseconds); print d.days; print microseconds; print cur_time; print hook_date'
  -1
  -1315376334.45
  19523955.25
  1334900289.7

  (I used the successful stamp file rather than a failed stamp file, but
  it's the same problem.)

  I believe you want:
  python -c 'from datetime import datetime; import os; hook_date = datetime.fromtimestamp(os.stat("/var/lib/update-notifier/package-data-downloads/flashplugin-installer").st_ctime); cur_time = datetime.now(); d=cur_time - hook_date; print d.days; print cur_time; print hook_date'

  Cheers,

  ProblemType: Bug
  DistroRelease: Ubuntu 12.04
  Package: update-notifier-common 0.119ubuntu8
  ProcVersionSignature: Ubuntu 3.2.0-18.28-generic 3.2.9
  Uname: Linux 3.2.0-18-generic x86_64
  ApportVersion: 2.0.1-0ubuntu5
  Architecture: amd64
  Date: Fri Apr 20 15:02:17 2012
  PackageArchitecture: all
  ProcEnviron:
   LANGUAGE=fr_FR:fr:en_GB:en
   TERM=xterm
   PATH=(custom, user)
   LANG=fr_FR.UTF-8
   SHELL=/bin/zsh
  SourcePackage: update-notifier
  UpgradeStatus: Upgraded to precise on 2009-12-07 (864 days ago)

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/update-notifier/+bug/986183/+subscriptions

More information about the foundations-bugs mailing list