gnutls api breakage in 3.5.6

Case is reproducible on buidllog
https://launchpadlibrarian.net/293397748/buildlog_ubuntu-zesty-amd64.libvirt_2.1.0-1ubuntu10_BUILDING.txt.gz

Issues around that were racy in the past https://www.redhat.com/archives/libvir-list/2013-August/msg00393.html

Yet this should be fixed since a long time.

The part of "libvirt: XML-RPC error : authentication failed: Failed to verify peer's certificate" should not confuse too much - that seems to be rather a warning but goes on ok.

E.g. in the working autopkgtest zesty env I can get this when setting verbose and running the test:
$ VIR_TEST_VERBOSE=1 ./virnettlssessiontest
TEST: virnettlssessiontest
 1) TLS Session servercertreq.filename + clientcertreq.filename ... OK
 2) TLS Session servercertreq.filename + clientcertaltreq.filename ... libvirt: XML-RPC error : authentication failed: Failed to verify peer's certificate
OK
 3) TLS Session servercertalt1req.filename + clientcertreq.filename ... OK
 4) TLS Session servercertalt1req.filename + clientcertreq.filename ... OK
 5) TLS Session servercertalt1req.filename + clientcertreq.filename ... libvirt: XML-RPC error : authentication failed: Failed to verify peer's certificate
OK
 6) TLS Session servercertalt2req.filename + clientcertreq.filename ... libvirt: XML-RPC error : authentication failed: Failed to verify peer's certificate
OK
 7) TLS Session servercertalt2req.filename + clientcertreq.filename ... OK
 8) TLS Session servercertalt2req.filename + clientcertreq.filename ... OK
 9) TLS Session servercertreq.filename + clientcertreq.filename ... libvirt: XML-RPC error : authentication failed: Failed to verify peer's certificate
OK
10) TLS Session servercertreq.filename + clientcertreq.filename ... OK
11) TLS Session servercertreq.filename + clientcertreq.filename ... OK
12) TLS Session servercertreq.filename + clientcertreq.filename ... libvirt: XML-RPC error : authentication failed: Failed to verify peer's certificate
OK
13) TLS Session servercertreq.filename + clientcertreq.filename ... OK
14) TLS Session servercertreq.filename + clientcertreq.filename ... OK
15) TLS Session servercertlevel3areq.filename + clientcertlevel2breq.filename ... OK

Although it is less of these than on the LP buildlog

So the real issues are:
10) TLS Session servercertreq.filename + clientcertreq.filename ... FAILED
11) TLS Session servercertreq.filename + clientcertreq.filename ... FAILED
13) TLS Session servercertreq.filename + clientcertreq.filename ... FAILED
14) TLS Session servercertreq.filename + clientcertreq.filename ... FAILED

Unfortunately is isn't very verbose even with verbose and debug enabled and the lack of local reproducibility doesn't help either.

Trying to be closer to the LP infrastructure I was running the same on a serverstack instance.
But there as well things built and tested just fine.

Since it is close to EOD for now I'm gonna wait a day in the slight hope that something in LP infra resolves e.g. packages being updated until tomorrow.

I was able once (1!) to reproduce outside of launchpad by using the following steps to become more like launchpad:

# Prep needed packages
  $ sudo apt-get install sbuild ubuntu-dev-tools

# misuse a mk-sbuild to set up all around that might be needed (despite throwing most away afterwards)
  $ SID=LP-zesty-repro
  $ mk-sbuild zesty --arch amd64 --name=${SID}
# replace content with the tarball from launchpad
  $ sudo rm -rf /var/lib/schroot/chroots/${SID}-amd64/*
# launchpad tells you where to get the original chroot used by LP (https://api.launchpad.net/devel/ubuntu/zesty/amd64)
# get it and replace the local chroot content with it
  $ wget http://launchpadlibrarian.net/289945545/chroot-ubuntu-zesty-amd64.tar.bz2
  $ sudo tar --directory /var/lib/schroot/chroots/${SID}-amd64/ -xzf ~/Downloads/chroot-ubuntu-zesty-amd64.tar.bz2
  $ sudo mv /var/lib/schroot/chroots/${SID}-amd64/chroot-autobuild/* /var/lib/schroot/chroots/${SID}-amd64/
  $ sudo rmdir /var/lib/schroot/chroots/${SID}-amd64/chroot-autobuild
# Update to all packages and proposed as build env would
  $ printf "deb http://archive.ubuntu.com/ubuntu zesty main universe\ndeb http://archive.ubuntu.com/ubuntu zesty-security main universe\ndeb http://archive.ubuntu.com/ubu
  $ sudo sbuild-update -udcar ${SID}-amd64
# build as usual (this env sticks around so feel free to reuse)
  $ DEB_BUILD_OPTIONS="parallel=4" sbuild -Ad${SID}-amd64 libvirt_2.1.0-1ubuntu10.dsc

Unfortunately that only triggered once, and retrying is hard as it either takes quite a while (full build) or behaves slightly differently when e.g. only running all tests but not rebuilding in the schroot.

The only good thing to be learned so far - the test is not generally broken as it "sadly" runs fine most of the time.

Note fast iteration - about a few hundred worked already
     $ sudo schroot -c chroot:LP-zesty-repro-amd64
     $ apt-get build-dep libvirt
     # into my failed sbuild dir
     $ cd /build/libvirt-APpd92/libvirt-2.1.0/debian/build/tests
     $ while ./virnettlssessiontest; do echo still working; done

Considering the facts so far:
- it seems racy
- works mostly even in LP chroot based build envs
- fails ?almost? always on LP
- in the past it had an issue with concurrency
- I had some (very limited) success to crash it similarly (not the same) by running more tests at once

=> consider it might be concurrency on the tests.
Currently we have:
 dh_auto_test -O--builddirectory=/<<PKGBUILDDIR>>/debian/build
[...]
 make -j4 check VERBOSE=1

Lets shrink that on the tests to be non concurrent and see again on LP if it works there reliably.

Evaluated on a ppa and I got 4/4 successful builds:

https://launchpad.net/~paelzer/+archive/ubuntu/libvirt-bug-1633207/+build/11203972/+files/buildlog_ubuntu-zesty-amd64.libvirt_2.1.0-1ubuntu11~ppa1_BUILDING.txt.gz
https://launchpad.net/~paelzer/+archive/ubuntu/libvirt-bug-1633207/+build/11203973/+files/buildlog_ubuntu-zesty-i386.libvirt_2.1.0-1ubuntu11~ppa1_BUILDING.txt.gz
https://launchpad.net/~paelzer/+archive/ubuntu/libvirt-bug-1633207/+build/11204090/+files/buildlog_ubuntu-zesty-amd64.libvirt_2.1.0-1ubuntu11~ppa2_BUILDING.txt.gz
https://launchpad.net/~paelzer/+archive/ubuntu/libvirt-bug-1633207/+build/11204091/+files/buildlog_ubuntu-zesty-i386.libvirt_2.1.0-1ubuntu11~ppa2_BUILDING.txt.gz

In these logs one can also see that the build itself works just fine with many cpus
make -j4
but later on the test is called via dh_auto_test with
make -j1

So that works in 4/4 cases, ready to upload as FTBFS fix and cross fingers that it works in this upload as tested on the ppa and not staying the recreation nightmare it was so far.

I start to hate this, but it is really failing on the actual upload.
That must be so very specific to something on LP that I might need some advice.

Failing now (with the non concurrent fix that helped 4/4 on the ppa):
https://launchpad.net/ubuntu/+source/libvirt/2.1.0-1ubuntu11
https://launchpadlibrarian.net/293533099/buildlog_ubuntu-zesty-amd64.libvirt_2.1.0-1ubuntu11_BUILDING.txt.gz
https://launchpadlibrarian.net/293533653/buildlog_ubuntu-zesty-i386.libvirt_2.1.0-1ubuntu11_BUILDING.txt.gz

Hmm, one of the remaining differences between LP:ppa and LP:main builds are that the LP:main builds have proposed enabled as it should be but the ppa's have not.

I knew that but didn't realize due to the raciness in general that it might be important.
Remember that even with proposed enabled on the LP based chroot I only got it reproduced once.

I compared the buildlogs and found that between good and bad (with proposed).
That list looks promising in regard to the issue I have, especially since there is gnuttls in it.

  Different:
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 linux-libc-dev amd64 4.8.0-27.29 [856 kB]

  On-Top:
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 libgnutls30 amd64 3.5.6-4ubuntu1 [626 kB]
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 libsasl2-modules-db amd64 2.1.27~72-g88d82a3+dfsg-1 [15.1 kB]
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 libsasl2-2 amd64 2.1.27~72-g88d82a3+dfsg-1 [48.8 kB]
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 libgssapi-krb5-2 amd64 1.15~beta1-1 [120 kB]
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 libkrb5-3 amd64 1.15~beta1-1 [274 kB]
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 libkrb5support0 amd64 1.15~beta1-1 [31.8 kB]
  Get: http://ftpmaster.internal/ubuntu zesty-proposed/main amd64 libk5crypto3 amd64 1.15~beta1-1 [83.9 kB]

This might also be a false assumption based on the bad reproducibility out of the main LP upload - but worth a check.
So I changed the ppa dependencies and pushed another upload to the ppa to confirm.

That is weird now, enabling proposed there worked but it still builds fine in the ppa.
https://launchpadlibrarian.net/293547273/buildlog_ubuntu-zesty-amd64.libvirt_2.1.0-1ubuntu11~ppa3_BUILDING.txt.gz

I see that there is one difference left - which is just libgnutls30.
Just this one is not fetched even on the proposed enabled zesty ppa.

libgnutls28-dev_3.5.3-5ubuntu1
vs
libgnutls28-dev_3.5.6-4ubuntu1

Why is that - to be clarified?

This was updated on zesty just these days, so that could still be it.
Need to check Debian if they needed to adapt anything.
Otherwise I'll ask Martin who uploaded gnutls yesterday if he knows known impacts.

So since it migrated now a quite normal "sudo sbuild-update -udcar zesty-amd64" gave me:
Get:10 http://archive.ubuntu.com/ubuntu zesty/main amd64 libgnutls30 amd64 3.5.6-4ubuntu1 [626 kB]

So I checked if that will "help" to reproduce locally and it does.
It seems we were just in the worst spot of the trigger depending on a package that was just in migration.

With that properly migrated it now fails in local VM as well as on PPA builds - yeah?!

Debian seems to build against that new gnutls version fine.
But there are no new patches to the tests upstream that are in Debian but not in the current Ubuntu.
Also while there were general changes to tls code in the meantime upstream none seems to affect this - only one build fix but referring to a commit that is not in libvirt 2.1.

Depending on how debugging goes we might "just" have to do the libvirt merge now to fix the FTBFS.
Since the merge should contain more cleanup I'd like to avoid it for now, but lets see.

Debuggable without the libtool wrapper via:
gdb -directory ../../../src/test ./.libs/lt-virnettlssessiontest

So those are all testing the same connection/certificates, but using different wildcards

work fail
wildcards1 wildcards2
wildcards4 wildcards3
              wildcards4
              wildcards5
Defined as:
    const char *const wildcards1[] = {
        "C=UK,CN=dogfood",
        NULL,
    };
    const char *const wildcards2[] = {
        "C=UK,CN=libvirt",
        NULL,
    };
    const char *const wildcards3[] = {
        "C=UK,CN=dogfood",
        "C=UK,CN=libvirt",
        NULL,
    };
    const char *const wildcards4[] = {
        "C=UK,CN=libvirtstuff",
        NULL,
    };
    const char *const wildcards5[] = {
        "C=UK,CN=libvirt*",
        NULL,
    };
    const char *const wildcards6[] = {
        "C=UK,CN=*virt*",
        NULL,
    };

The failing ones seem to be all wildcards that match.

I found that Debian fails that Test as well but goes on:

https://buildd.debian.org/status/fetch.php?pkg=libvirt&arch=amd64&ver=2.4.0-2&stamp=1479241026

So it might be an upstream issue in general against recent gnutls.

And Debian has the same issue but they fail not fatally on that - which they should actually IMHO.

Testing upstream build in zesty container to report there if appropriate.

Neither gnutls upgrade announce to change anything around this:
https://lists.gnupg.org/pipermail/gnutls-devel/2016-October/008194.html
https://lists.gnupg.org/pipermail/gnutls-devel/2016-November/008221.html

Interestingly the tests are the follwing way:
expect-srvfail expect-clientfail result
true, false, ok
false, false, fail
false, false, fail
true, false, ok
false, false, fail
false, false, fail

Given that pattern it is possible that server verification now just ALWAYS fails.
That would still give exactly the pattern we see.

after init is done and vars can be checked
b virnettlssessiontest.c:95
Then it initializes server and client context without checks intentionally
to detect problems via the TLS session validation stage.
 virNetTLSContextNewServer
 virNetTLSContextNewClient
Both work (wildcard is used on Server Context creation)
Then it creates sessions via
  virNetTLSSessionNew
also working.
Callbacks on the socket pair are registered (testWrite/testRead)
  virNetTLSSessionSetIOCallbacks
Then it is looping until a handshake completes or fails.
  virNetTLSSessionHandshake
The handshake completes and then the validation is called for server and client
  virNetTLSContextCheckCertificate

Do note that as outlined before the "libvirt: XML-RPC error : authentication failed:
Failed to verify peer's certificate" can be ok as it is also checking for "expected to fail" certificates.

Actually a lot of good vir DEBUG/WARN in there - set env accordingly.
LIBVIRT_DEBUG=1 VIR_TEST_DEBUG=1 VIR_TEST_VERBOSE=1 ./.libs/lt-virnettlssessiontest

  debug : virNetTLSSessionHandshake:1342 : Handshake is complete
  debug : virNetTLSContextValidCertificate:1063 : Peer DN is CN=libvirt,C=UK
  debug : virNetTLSContextCheckCertDNWhitelist:387 : Failed whitelist check for client DN 'CN=libvirt,C=UK'
  info : virNetTLSContextValidCertificate:1105 : RPC_TLS_CONTEXT_SESSION_DENY: ctxt=0x55fe2c5673b0 sess=0x55fe2c572d70 dname=CN=libvirt,C=UK
  warning : virNetTLSContextCheckCertificate:1125 : Certificate check failed Client's Distinguished Name is not on the list of allowed clients (tls_allowed_dn_list). Use 'certtool -i --infile clientcert.pem' to view the Distinguished Name field in the client certificate, or run this daemon with --verbose option.
  warning : testTLSSessionInit:192 : Unexpected server cert check fail

The actual check is made in virNetTLSContextValidCertificate which does various gnutls calls

next go for a good and bad case check with upstream code - as it seems likely this needs to be fixed there.

Taking Yakkety and Zesty being one with and one without the new gnutls.

# Try most basic build as reasonable for debug and a report upstream
$ apt-get install -y ubuntu-dev-tools gdb
$ apt-get -y build-dep libvirt
$ git clone git://libvirt.org/libvirt.git
$ cd libvirt
$ export CFLAGS="-g -O0"
$ CFLAGS="-g -O0" ./autogen.sh
$ CFLAGS="-g -O0" make -j4 V=1
$ CFLAGS="-g -O0" make -j4 check V=1

That confirmed the issue being valid upstream in libvirt.
To bolster that theory I upgraded just gnutls and libtasn1 (for dependency) to the newer version.

# get newer versions and extract locally
$ cd ~
$ wget http://launchpadlibrarian.net/293384593/libgnutls30_3.5.6-4ubuntu1_amd64.deb
$ wget http://launchpadlibrarian.net/278823831/libtasn1-6_4.9-4_amd64.deb
$ mkdir newertls
$ dpkg -x libgnutls30_3.5.6-4ubuntu1_amd64.deb newertls
$ dpkg -x libtasn1-6_4.9-4_amd64.deb newertls

# check newer libs are loaded via LD_LIBRARY_PATH
ldd ./tests/.libs/lt-virnettlssessiontest | grep tls
        libgnutls.so.30 => /usr/lib/x86_64-linux-gnu/libgnutls.so.30 (0x00007f5aa1458000)
        libcurl-gnutls.so.4 => /usr/lib/x86_64-linux-gnu/libcurl-gnutls.so.4 (0x00007f5a9ec39000)
LD_LIBRARY_PATH="/root/newertls/usr/lib/x86_64-linux-gnu/" ldd ./tests/.libs/lt-virnettlssessiontest | grep tls
        libgnutls.so.30 => /root/newertls/usr/lib/x86_64-linux-gnu/libgnutls.so.30 (0x00007fc42930d000)
        libtasn1.so.6 => /root/newertls/usr/lib/x86_64-linux-gnu/libtasn1.so.6 (0x00007fc4290fa000)
        libcurl-gnutls.so.4 => /usr/lib/x86_64-linux-gnu/libcurl-gnutls.so.4 (0x00007fc426ae4000)

Testing with those on the so far always working Yakkety environment:
$ ./tests/.libs/lt-virnettlssessiontest
TEST: virnettlssessiontest
      ............... 15 OK
$ LD_LIBRARY_PATH="/root/newertls/usr/lib/x86_64-linux-gnu/" ./tests/.libs/lt-virnettlssessiontest
TEST: virnettlssessiontest
      .........!!.!!. 15 FAIL

That is it, so confirmed upstream libvirt issue due to gnutls upgrade to latest bugfix release.
Looking into it with GDB now if I can find a fix or just have to report for now.

FYI - reported the lack of an FTBFS in Debian as debbug 844511
Not linking this bug here as it is not about "this" issue, but the question why it wasn't an FTBFS for Debian.

# reusing the path in gdb
set env LD_LIBRARY_PATH /root/newertls/usr/lib/x86_64-linux-gnu/
# that brought me to wonder that in the bad case the following break did not catch anything
b virNetTLSContextCheckCertDN if strcmp(dname, "C=UK,CN=libvirt") == 0
# I realized that they were different
GOOD: $1 = 0x7fffffffe1d0 "C=UK,CN=libvirt"
BAD: $1 = 0x7fffffffe180 "CN=libvirt,C=UK"

# So something must have been reordering these AND something breaks on the different order

The value is set by gnutls_x509_crt_get_dn(cert, dname, &dnamesize)
That unearths the conflicting issue / pach in gnutls which is:
https://gitlab.com/gnutls/gnutls/issues/111
https://gitlab.com/gnutls/gnutls/commit/b1b025fcac6fc2258eeb4e527226ba0c2aff2f59

Then on that virNetTLSContextCheckCertDNWhitelist breaks as the strings no more match.

The brute force fix is rather easy - which is to change the order of the wildcards in the tests.
That works, but:
- that fails with older gnutls then (so not good for upstream and backports)
- there might be more to change in libvirt I don't know of

This is a v1 of a fix that will fix the testcase.

I'll apply that to packaging to get things building again in zesty for now.

I'll also submit that upstream to libvirt as it could be the case that libvirt in general needs more changes that I can't think of to fully follow the changes of the gnutls change.

Build worked but my assumption of "other" changes became true, yet in a different way than I thought.
See this thread on libvirt which made me aware of gnutls actually taking back some of the changes:
https://www.redhat.com/archives/libvir-list/2016-November/msg00815.html

So it turns out that was identified an unallowed abi change in gnutls - not released.
commit 70bf8475bb0ab178fe36ee4c601a6cfec8e70a3f
Author: Nikos Mavrogiannopoulos <email address hidden>
Date: Fri Nov 11 16:20:01 2016 +0100

    Introduced new functions to allow multiple DN parsing modes

    The old DN parsing functions are changed to return the original
    non-fully compliant with RFC4514 string format, while the new
    ones return the compliant string by default. This allows applications
    which relied on the previous format to continue functioning without
    changes.

So in turn we need to update gnutls and then libvirt (back to where we started).

Also we have broken nova-compute dep8 tests (https://objectstorage.prodstack4-5.canonical.com/v1/AUTH_77e2ada1e7a84929a74ba3b87153c0ac/autopkgtest-zesty/zesty/i386/n/nova/20161116_153913_48850@/log.gz) on the recent uploads, which might (or not) be related to this overall thing - only willing to spend more time once the gnutls/libvirt changes are back to where they should be.

I created a ppa where I try to build a fixed gnutls (backporting the upstream fixes) together with a reverted libvirt.
=> https://launchpad.net/~paelzer/+archive/ubuntu/bug-1641615-gnutls-api-break-hits-libvirt

Not sure if it works, but the plan for now is:
1. check new gnutls + reverted libvirt in my ppa
2. provide a debdiff for gnutls for review and sponsoring
3. after new gnutls is in zesty archive upload the re-fixed libvirt.
4. check on any nova issues if any are left.

2/3 could be combined via Bileto to save some turnaround given proper permissions - not sure if we want/should do so.

Ok, gnutls backport "complete" although we should jump on gnutls 3.5.7 whenever it gets released IMHO.

I prepped the gnutls fix as debdiff and the backpedal on libvirt which takes back our tries to get around the issue.
Attaching both now.

FYI - both packages built fine together in the ppa at https://launchpad.net/~paelzer/+archive/ubuntu/bug-1641615-gnutls-api-break-hits-libvirt/

Thanks Martin, I also uploaded the libvirt part with the build depends as discussed.
Touching all kind of wood hoping things finally built&migrate completely on this.

This bug was fixed in the package gnutls28 - 3.5.6-4ubuntu2

---------------
gnutls28 (3.5.6-4ubuntu2) zesty; urgency=medium

  * d/p/dname-api-*.patch fix gnutls api breakage on dname order in
    gnutls 3.5.6 (LP: #1641615)
    - d/libgnutls30.symbols add new symbols added by the upstream fix

 -- Christian Ehrhardt <email address hidden> Thu, 17 Nov 2016 08:39:43 +0100

This bug was fixed in the package libvirt - 2.1.0-1ubuntu13

---------------
libvirt (2.1.0-1ubuntu13) zesty; urgency=medium

  * drop d/p/ubuntu/fix-ftbfs-for-gnutls-3-5-6.patch as the offending change
    in gnutls has been reverted (LP: #1641615)
  * Build depend on gnutls >= 3.5.6-4ubuntu2 to build after the gnutls fix
    migrated

 -- Christian Ehrhardt <email address hidden> Thu, 17 Nov 2016 08:43:10 +0100

Nova is good as well - zul was fixing that up (was unrelated) setting to invalid.