upgrade to 1.17.0 fails

[Curtis Hovey]

The CI upgrade-juju from 1.16.3 to 1.17.0 failed on canonistack. The last successful test was against r2052. r2053 (https://code.launchpad.net/~wallyworld/juju-core/deprecated-tools-url-value/+merge/194965) fails.

We can see in the log that 1.17.0.1-precise-amd64 was selected, but the tool is not found.
We can see in the log that the tools-metadata-url is used and the path is correct /juju-dist/testing/tools
We also know that the config has an identical tools-url set
We can see in the logs that tools-url is empty (as is public-bucket-url)
We can see the bootstrap node searching for tools and it never uses /juju-dist/testing/tools.
We see juju looking in /juju-dist/tools from many locations.

Maybe the upgraded client sees the tools using the new config, and updates the jenv. The jenv is passed to the server agent. It cannot upgrade because it does not know about tools-metadata-url yet.

EXAMPLE LAST SUCCESS r2052
http://162.213.34.53:8080/job/upgrade-and-deploy-devel/132/console

EXAMPLE FAILURE r2053
http://162.213.34.53:8080/job/upgrade-and-deploy-devel/134/consoleFull#1815644190083d5bd4-65a9-42df-9c6d-48925132ae02

[John A Meinel (jameinel)]

The local config != the config that is in Mongodb. You can check that with "juju get-environment".
My guess is that you are setting a tools-metadata-url/tools-url locally, but *not* setting it inside mongo (juju set-environment tools-url=XXX").

I would have thought this wouldn't have been working for a lot longer. But perhaps you were bootstrapping with tools-url set before?

[John A Meinel (jameinel)]

Some comments about the testing success vs fail:

1) There are lot of extra moving parts here. The failing test is testing several more environments concurrently. While this is great for coverage, it makes it hard to just compare the files and see what bits are different.

One option would be to just run the old code with the new script.

2) Phase 1: Testing to canonistack.

After this appears to be a list of tool tarballs. However, the sort order appears to be mostly random. (maybe it is filesystem order?)
If I do just a "sort" on that section, the lines match up exactly, but otherwise it looks like there are different tools on each side.

3) The actual commit that seems to break things actually changed "tools-url" from Omit to "". So I wonder if it in juju-core r2052 we didn't send up anything, but in juju-core r2053 we are actually forcing tools-url to get updated to the *empty string*. (I didn't think upgrade-juju actually changed environ config, but if it *does* then this might be a hint.) ISTR Andrew saying that our EnvironConfig updating can only overwrite entries (it never deletes entries). Which means that if we don't send a field, then we preserve the old value. If we send an empty string, well that would break it.

4) There is a lot of spam about the deprecated warnings, that should get *better* in r2058. They'll still be there, but it should be only 1 for the environment a command is using, not 1 for every environment listed in environments.yaml.

5) In this overly verbose spam
WARNING Config attribute "tools-url" (http://10.0.3.1:8040/tools) is deprecated and will be ignored since
the new tools URL attribute "tools-metadata-url" has also been used.
The attribute tools-urlhould be removed from your configuration.
WARNING Config attribute "tools-url" (https://swift.canonistack.canonical.com/v1/AUTH_526ad877f3e3464589dc1145dfeaac60/juju-dist/testing/tools) is deprecated and will be ignored since
the new tools URL attribute "tools-metadata-url" has also been used.
The attribute tools-urlhould be removed from your configuration.
WARNING Config attribute "tools-url" (http://juju-dist.s3.amazonaws.com/testing/tools) is deprecated and will be ignored since
the new tools URL attribute "tools-metadata-url" has also been used.
The attribute tools-urlhould be removed from your configuration.
WARNING Config attribute "tools-url" (https://region-a.geo-1.objects.hpcloudsvc.com/v1/60502529753910/juju-dist/testing/tools) is deprecated and will be ignored since
the new tools URL attribute "tools-metadata-url" has also been used.
The attribute tools-urlhould be removed from your configuration.
WARNING Config attribute "tools-url" (https://jujutools.blob.core.windows.net/juju-tools/testing/tools) is deprecated and will be ignored since
the new tools URL attribute "tools-metadata-url" has also been used.
The attribute tools-urlhould be removed from your configuration.
WARNING Config attribute "tools-url" (https://swift.canonistack.canonical.com/v1/AUTH_526ad877f3e3464589dc1145dfeaac60/juju-dist/tools) is deprecated.
The location to find tools is now specified using the "tools-metadata-url" attribute.
Your configuration should be upddated to set "too...

[John A Meinel (jameinel)]

I see all-machine.log did get attached. I'll look into that now.

[John A Meinel (jameinel)]

Fortunately the logs get a lot better in 1.17 (we filter out Pings, we include the agent that is generating the request, etc).

I did track down where the agents start noticing they should be upgraded, and what version and what URL. So when it starts looking for 1.16.3 originally it does:
2013-11-13 16:13:06 DEBUG juju.environs.simplestreams simplestreams.go:436 read metadata index at "https://swift.canonistack.canonical.com/v1/AUTH_526ad877f3e3464589dc1145dfeaac60/juju-dist/testing/tools/streams/v1/index.json"
2013-11-13 16:13:06 DEBUG juju.environs.simplestreams simplestreams.go:577 candidate matches for products ["com.ubuntu.juju:12.04:amd64"] are [{Wed, 13 Nov 2013 15:58:16 +0000 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64 com.ubuntu.juju:12.04:armhf com.ubuntu.juju:12.04:i386 com.ubuntu.juju:12.10:amd64 com.ubuntu.juju:12.10:i386 com.ubuntu.juju:13.04:amd64 com.ubuntu.juju:13.04:i386 com.ubuntu.juju:13.10:amd64 com.ubuntu.juju:13.10:armhf com.ubuntu.juju:13.10:i386 com.ubuntu.juju:14.04:amd64 com.ubuntu.juju:14.04:armhf com.ubuntu.juju:14.04:i386]}]
2013-11-13 16:13:06 DEBUG juju.environs.simplestreams simplestreams.go:889 finding products at path "streams/v1/com.ubuntu.juju:released:tools.json"
2013-11-13 16:13:06 DEBUG juju.rpc.jsoncodec codec.go:172 -> {"RequestId":27,"Response":{"Results":[{"Tools":{"version":"1.16.3-precise-amd64","url":"https://swift.canonistack.canonical.com/v1/AUTH_526ad877f3e3464589dc1145dfeaac60/juju-dist/testing/tools/releases/juju-1.16.3-precise-amd64.tgz","sha256":"25454089adce600c458511f23dab5fc9a4bb313202726cde797e7714bcee8e04","size":4661306},"DisableSSLHostnameVerification":false,"Error":null}]}}

Which shows that we read: https://swift.canonistack.canonical.com/v1/AUTH_526ad877f3e3464589dc1145dfeaac60/juju-dist/testing/tools/streams/v1/index.json
And find 1.16.3 there.

Then later on we do:
2013-11-13 16:23:23 DEBUG juju.environs.simplestreams simplestreams.go:436 read metadata index at "https://swift.canonistack.canonical.com/v1/AUTH_526ad877f3e3464589dc1145dfeaac60/juju-dist/tools/streams/v1/index.json"
2013-11-13 16:23:23 DEBUG juju.environs.simplestreams simplestreams.go:577 candidate matches for products ["com.ubuntu.juju:12.04:amd64"] are [{Thu, 07 Nov 2013 12:06:19 -0500 products:1.0 content-download [] streams/v1/com.ubuntu.juju:released:tools.json [com.ubuntu.juju:12.04:amd64 com.ubuntu.juju:12.04:armhf com.ubuntu.juju:12.04:i386 com.ubuntu.juju:12.10:amd64 com.ubuntu.juju:12.10:i386 com.ubuntu.juju:13.04:amd64 com.ubuntu.juju:13.04:i386 com.ubuntu.juju:13.10:amd64 com.ubuntu.juju:13.10:armhf com.ubuntu.juju:13.10:i386 com.ubuntu.juju:14.04:amd64 com.ubuntu.juju:14.04:armhf com.ubuntu.juju:14.04:i386]}]
2013-11-13 16:23:23 DEBUG juju.environs.simplestreams simplestreams.go:889 finding products at path "streams/v1/com.ubuntu.juju:released:tools.json"
2013-11-13 16:23:23 DEBUG juju.environs.simplestreams simplestreams.go:444 index has no matching records
2013-11-13 16:23:23 DEBUG juju.rpc.jsoncodec codec.go:172 -> {"RequestId":105,"Response":{"Results":[{"Tools":null,"DisableSSLHostnameVerification":false,"Error":{"Message":"no ma...

[Ian Booth (wallyworld)]

I have managed to reproduce the problem and also solve it.
The fix:

=== modified file 'environs/config/config.go'
--- environs/config/config.go 2013-11-13 07:33:21 +0000
+++ environs/config/config.go 2013-11-14 08:53:18 +0000
@@ -264,7 +264,7 @@
                        cfg.m["tools-metadata-url"] = oldToolsURL
                }
                logger.Warningf(msg)
- delete(cfg.m, "tools-url")
        }
        return nil
 }

Right now, this doesn't make a lot of sense to me. Deleting the tools-url attribute from the config attributes is supposed to be the right thing to do. And besides that, there is supposed to be the behaviour (bug) that no environ attribute, once in state, ever gets deleted. See bug 1248809.

So there's a quick fix but more work is needed to fully understand the cause. If bug 1248809 is still there, then deleting the tools-url attr from the config map should not cause the behaviour we are seeing. And even if bug 1248809 is fixed, I would expect SetEnvironConfig to only update what attrs it is passed, not delete things are aren't in the map.

[Ian Booth (wallyworld)]

I added code to the environs config to ensure tools-url was always left in the config map, even if it was used to set the value of tools-metadata-url