Broken timedate handling for failed hook runs

[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)