armhf/ppc64el tests might use earlier binary packages than britney sees

Bug #1490899 reported by Martin Pitt on 2015-09-01
10
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Auto Package Testing
High
Martin Pitt

Bug Description

Steve and Matthias reported that in some cases autopkgtests got triggered too early:

 - armhf was triggered although the armhf build was not in the archive yet
 - ppc64el build was triggered after it was built/published, but the corresponding amd64 (arch: all) was still missing

Martin Pitt (pitti) on 2015-09-01
Changed in auto-package-testing:
status: New → Incomplete
importance: Undecided → High
Martin Pitt (pitti) wrote :
Download full text (3.9 KiB)

I think the matching britney run is http://people.canonical.com/~ubuntu-archive/proposed-migration/log/wily/2015-08-31/23:03:26.log

I: [Mon Aug 31 23:06:20 2015] - test cantor/4:15.08.0-0ubuntu1/amd64 for cantor/4:15.08.0-0ubuntu1 is already pending, not queueing
I: [Mon Aug 31 23:06:20 2015] - test cantor/4:15.08.0-0ubuntu1/i386 for cantor/4:15.08.0-0ubuntu1 is already pending, not queueing
I: [Mon Aug 31 23:06:20 2015] - test cantor/4:15.08.0-0ubuntu1/armhf for cantor/4:15.08.0-0ubuntu1 is already pending, not queueing
I: [Mon Aug 31 23:06:20 2015] - test cantor/4:15.08.0-0ubuntu1/ppc64el for cantor/4:15.08.0-0ubuntu1 is already pending, not queueing
[...]
I: [Mon Aug 31 23:06:23 2015] - Fetched test result for cantor/4:15.08.0-0ubuntu1/ppc64el 20150831_230109@: pass
I: [Mon Aug 31 23:06:23 2015] - -> matches pending request for triggers {('octave', '4.0.0-3ubuntu4'), ('cantor', '4:15.08.0-0ubuntu1')}
I: [Mon Aug 31 23:06:23 2015] - -> matches pending request for triggers {('octave', '4.0.0-3ubuntu4')}
I: [Mon Aug 31 23:06:23 2015] - Fetched test result for cantor/4:15.08.0-0ubuntu1/ppc64el 20150831_230336@: pass
E: [Mon Aug 31 23:06:23 2015] - -> does not match any pending request!
E: [Mon Aug 31 23:06:23 2015] - -> does not match any pending request!
I: [Mon Aug 31 23:06:23 2015] - Fetched test result for cantor/4:15.08.0-0ubuntu1/i386 20150831_225328@: pass
I: [Mon Aug 31 23:06:23 2015] - -> matches pending request for triggers {('octave', '4.0.0-3ubuntu4'), ('cantor', '4:15.08.0-0ubuntu1')}
I: [Mon Aug 31 23:06:23 2015] - -> matches pending request for triggers {('octave', '4.0.0-3ubuntu4')}
I: [Mon Aug 31 23:06:23 2015] - Fetched test result for cantor/4:15.08.0-0ubuntu1/i386 20150831_230134@: pass
E: [Mon Aug 31 23:06:23 2015] - -> does not match any pending request!
E: [Mon Aug 31 23:06:23 2015] - -> does not match any pending request!
I: [Mon Aug 31 23:06:23 2015] - Fetched test result for cantor/4:15.08.0-0ubuntu1/amd64 20150831_225106@: pass
I: [Mon Aug 31 23:06:23 2015] - -> matches pending request for triggers {('octave', '4.0.0-3ubuntu4'), ('cantor', '4:15.08.0-0ubuntu1')}
I: [Mon Aug 31 23:06:23 2015] - -> matches pending request for triggers {('octave', '4.0.0-3ubuntu4')}
I: [Mon Aug 31 23:06:23 2015] - Fetched test result for cantor/4:15.08.0-0ubuntu1/amd64 20150831_230308@: pass
E: [Mon Aug 31 23:06:23 2015] - -> does not match any pending request!
E: [Mon Aug 31 23:06:23 2015] - -> does not match any pending request!
I: [Mon Aug 31 23:06:23 2015] - Fetched test result for cantor/4:15.08.0-0ubuntu1/armhf 20150831_230602@: pass
I: [Mon Aug 31 23:06:23 2015] - -> matches pending request for triggers {('octave', '4.0.0-3ubuntu4'), ('cantor', '4:15.08.0-0ubuntu1')}
E: [Mon Aug 31 23:06:23 2015] - -> does not match any pending request!
[...]
trying: cantor
accepted: cantor
   ori: 259+0: a-72:a-46:a-35:i-38:p-35:p-33
   pre: 259+0: a-72:a-46:a-35:i-38:p-35:p-33
   now: 257+0: a-72:a-46:a-34:i-38:p-34:p-33
   all: cantor

and in the corresponding http://people.canonical.com/~ubuntu-archive/proposed-migration/update_excuses/wily/2015-08-31/23:03:26.html.gz (attention: it's double gzip'ed) it says

cantor (4:15.04.2-0ubuntu4 to 4:...

Read more...

Martin Pitt (pitti) wrote :

The first time cantor/4:15.08.0-0ubuntu1 hit britney was in http://people.canonical.com/~ubuntu-archive/proposed-migration/log/wily/2015-08-31/22:35:47.log :

I: [Mon Aug 31 22:39:06 2015] - Requesting cantor/4:15.08.0-0ubuntu1/ppc64el autopkgtest to verify octave/4.0.0-3ubuntu4, cantor/4:15.08.0-0ubuntu1
I: [Mon Aug 31 22:39:06 2015] - Requesting cantor/4:15.08.0-0ubuntu1/i386 autopkgtest to verify octave/4.0.0-3ubuntu4, cantor/4:15.08.0-0ubuntu1
I: [Mon Aug 31 22:39:06 2015] - Requesting cantor/4:15.08.0-0ubuntu1/amd64 autopkgtest to verify octave/4.0.0-3ubuntu4, cantor/4:15.08.0-0ubuntu1
I: [Mon Aug 31 22:39:06 2015] - Requesting cantor/4:15.08.0-0ubuntu1/armhf autopkgtest to verify octave/4.0.0-3ubuntu4, cantor/4:15.08.0-0ubuntu1

http://people.canonical.com/~ubuntu-archive/proposed-migration/update_excuses/wily/2015-08-31/22:35:47.html.gz said

cantor (4:15.04.2-0ubuntu4 to 4:15.08.0-0ubuntu1)

    Maintainer: Debian/Kubuntu Qt/KDE Maintainers
    Section: universe/math
    0 days old
    autopkgtest for cantor 4:15.08.0-0ubuntu1: amd64: Test in progress, armhf: Test in progress, i386: Test in progress, ppc64el: Test in progress
    Not considered

i. e. it was allegedly built at that time already. The armhf build log has "Finished at 20150831-2212", which leaves 27 minutes for the publisher in between, which is at least plausible. This then triggered the already linked test log above.

So I'm afraid I don't yet have information about what went wrong. I'll create some tests for this.

Martin Pitt (pitti) wrote :

And I regularly see that britney does wait for the last build to finish, and packages to become installable before it triggers tests. E. g. right now

systemd (224-2ubuntu2 to 225-1ubuntu1)

    Maintainer: Ubuntu Developers
    0 days old
    missing build on armhf: libnss-myhostname, libnss-mymachines, libpam-systemd, libsystemd-daemon-dev, libsystemd-dev, libsystemd-login-dev, libsystemd0, libudev-dev, libudev1, libudev1-udeb, systemd, systemd-container, systemd-dbg, systemd-sysv, udev, udev-udeb (from 224-2ubuntu2)
    Not considered

nvidia-settings-legacy-304xx (- to 304.123-2)

    Maintainer: Debian NVIDIA Maintainers
    Section: multiverse/misc
    311 days old
    nvidia-settings-legacy-304xx/amd64 unsatisfiable Depends: nvidia-installer-cleanup
    nvidia-settings-legacy-304xx/amd64 unsatisfiable Depends: nvidia-legacy-304xx-alternative
    nvidia-settings-legacy-304xx/i386 unsatisfiable Depends: nvidia-installer-cleanup
    nvidia-settings-legacy-304xx/i386 unsatisfiable Depends: nvidia-legacy-304xx-alternative
    Not considered

So, Matthias/Steve, can you please point to some specific examples where this went wrong? Thanks!

On Tue, Sep 01, 2015 at 02:56:44PM -0000, Martin Pitt wrote:
> So, Matthias/Steve, can you please point to some specific examples where
> this went wrong? Thanks!

This is the failing cantor test run:

https://objectstorage.prodstack4-5.canonical.com/v1/AUTH_77e2ada1e7a84929a74ba3b87153c0ac/autopkgtest-wily/wily/armhf/c/cantor/20150831_211127@/log.gz

That's with cantor 4:15.07.90-0ubuntu2, not 4:15.08.0-0ubuntu1.

We're speculating as to the cause of the failure, because the error message
is opaque: "Test dependencies are unsatisfiable" doesn't tell us what is
unsatisfiable. Logging could be improved.

Ah, thanks. That run was indeed triggerd by the previous version https://launchpad.net/ubuntu/+source/cantor/4:15.07.90-0ubuntu2 (http://people.canonical.com/~ubuntu-archive/proposed-migration/log/wily/2015-08-31/21:04:31.log); at that time the archive already had the new source package, but that's something we have to live with right now -- it could always happen that a source package gets uploaded multiple times in succession and a test run sees a later version than britney. This is why britney accepts test results >= the requested one, not just a strict =.

> "Test dependencies are unsatisfiable" doesn't tell us what is unsatisfiable.

It actually does, further up; that's apt-get's Debug::pkgProblemResolver=true, and it is indeed hard to deciper, but it's as verbose as apt can be made:

Investigating (0) cantor-backend-octave [ armhf ] < none -> 4:15.07.90-0ubuntu2 > ( universe/math )
Broken cantor-backend-octave:armhf Depends on octave [ armhf ] < none -> 4.0.0-3ubuntu3 > ( universe/math )
  Considering octave:armhf 1 as a solution to cantor-backend-octave:armhf 0
  Holding Back cantor-backend-octave:armhf rather than change octave:armhf

So I think this was mostly just confusion due to uploading cantor twice within a few hours, but I think this mostly worked out as it should have.

he main thing that's left here as a potential trap AFAICS is the mirror delay between ftpmaster.internal (what britney uses) and ports.ubuntu.com (or whichever other mirror we are using). I'll fix the armhf/ppc64 test boxes to use ftpmaster.internal.

summary: - britney might trigger tests before builds are complete
+ armhf/ppc64el tests might use earlier binary packages than britney sees
Changed in auto-package-testing:
status: Incomplete → In Progress
assignee: nobody → Martin Pitt (pitti)
Martin Pitt (pitti) wrote :

The armhf and ppc64el runners now use ftpmaster.internal. The ppc64el nodes don't have direct access to it, so I have to use squid.internal as a proxy, but that's (hopefully) still be better than the mirror delay.

Changed in auto-package-testing:
status: In Progress → Fix Released
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers