juju.-gui fails with a config-changed error when used under juju 1.21alpha

[Abel Deuring]

http://juju-ci.vapour.ws:8080/job/build-juju-vagrant-trusty-amd64/

Attempts to deploy the GUI with juju-core debian packages for juju-core 1.21alpha built by CI from gitbranch:master:github.com/juju/juju r362f1fc3 in a Vagrant box fail in the config-changed hook with this error:

2014-09-08 12:43:19 INFO unit.juju-gui/0.juju-log cmd.go:247 >>> Entering config-changed
2014-09-08 12:43:19 INFO unit.juju-gui/0.juju-log cmd.go:247 Updating configuration.
2014-09-08 12:43:19 INFO unit.juju-gui/0.juju-log cmd.go:247 Stopping the builtin server.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Installing dependencies.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 No missing deb packages.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Setting up base dir: /var/lib/juju-gui.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 No change to juju-gui-source. Skipping step.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Installing the builtin server dependencies.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Installing the builtin server.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Starting Juju GUI.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Generating the Juju GUI configuration file.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Running in insecure mode! Port 80 will serve unencrypted.
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 Exception caught:
2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 error: cannot open ports 80-80/tcp for unit "juju-gui/0": cannot open ports 80-80/tcp on machine 1 due to conflict

2014-09-08 12:43:20 INFO unit.juju-gui/0.juju-log cmd.go:247 <<< Exiting config-changed
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 Traceback (most recent call last):
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/config-changed", line 58, in <module>
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 main()
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/config-changed", line 50, in main
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 backend.start()
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/backend.py", line 286, in start
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 call_methods(self.mixins, 'start', self)
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/backend.py", line 215, in call_methods
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 method(*args)
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/backend.py", line 137, in start
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 open_port(80)
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/charmhelpers.py", line 128, in open_port
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 cmd(*args)
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/shelltoolbox.py", line 138, in callable_command
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 return run(*all_args)
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 File "/var/lib/juju/agents/unit-juju-gui-0/charm/hooks/shelltoolbox.py", line 457, in run
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 raise exception
2014-09-08 12:43:20 INFO unit.juju-gui/0.config-changed context.go:473 subprocess.CalledProcessError: Command '['open-port', '80/TCP']' returned non-zero exit status 1
2014-09-08 12:43:20 ERROR juju.worker.uniter uniter.go:566 hook failed: exit status 1
2014-09-08 12:49:48 ERROR juju.api.watcher watcher.go:83 error trying to stop watcher: connection is shut down

More log files are attaeched, as well as the debian packages

[Richard Harding (rharding)]

This looks like either there's a bug in juju around port opening or there was something else on that vagrant box using the port before the GUI could gain access to it. I'm not as familiar with the vagrant setup. I thought at one point the GUI was auto setup when you did a vagrant install. If this is true is it possible you were actually deploying a second GUI?

I'd like to know more about the Vagrant setup and exact steps to reproduce from the start to debug farther. I'm going to make as incomplete at the moment. Thanks for the bug report and I look forward to the updated information on the environment/vagrant setup so we can attempt to duplicate easier.

[Abel Deuring (adeuring)]

Am 08.09.2014 um 15:51 schrieb Richard Harding:
> This looks like either there's a bug in juju around port opening or
> there was something else on that vagrant box using the port before the
> GUI could gain access to it. I'm not as familiar with the vagrant setup.
> I thought at one point the GUI was auto setup when you did a vagrant
> install. If this is true is it possible you were actually deploying a
> second GUI?
>
> I'd like to know more about the Vagrant setup and exact steps to
> reproduce from the start to debug farther. I'm going to make as
> incomplete at the moment. Thanks for the bug report and I look forward
> to the updated information on the environment/vagrant setup so we can
> attempt to duplicate easier.

The Vagrant box was built by the same script that is also used to build
the "official" Juju/Vagrant images. In other words, the only change is
that other juju-core and juju-localpackages were used. This may very
well be a bug in juju-core -- I can't assess who is to blame ;)

I'll upload the Vagrant image to my home directory on chinstrap -- you
can copy it from there. Or get it from
http://juju-ci.vapour.ws:8080/job/build-juju-vagrant-trusty-amd64/10/

(though that link is ephemeral)

[Abel Deuring (adeuring)]

Am 08.09.2014 um 15:51 schrieb Richard Harding:
> This looks like either there's a bug in juju around port opening or
> there was something else on that vagrant box using the port before the
> GUI could gain access to it. I'm not as familiar with the vagrant setup.
> I thought at one point the GUI was auto setup when you did a vagrant
> install. If this is true is it possible you were actually deploying a
> second GUI?

sorry, forgot to answer this question: No, rthere was no attempt to
install a second GUI. The error occured during Vagrant's regular
provisioning.

[Abel Deuring (adeuring)]

Am 08.09.2014 um 15:51 schrieb Richard Harding:
> I'd like to know more about the Vagrant setup and exact steps to
> reproduce from the start to debug farther. I'm going to make as
> incomplete at the moment.

sorry, not my best day. Here are the steps to reproduce:

- install virtualbox and vagrant
- download the vagrant image
- cd into a temp directory
- run

  vagrant box add testbox path-to-downloaded-box-file
  vagrant init testbox
  vagrant up

"vagrant up" needs 3 or 4 minutes; when that's done, access to the gui
should be possible by visiting http://127.0.0.1:6079 or
http://127.0.0.1:6080.

Actually, you'll get this error message from the provisioning script:

Traceback (most recent call last):
  File "/root/redirect.py", line 44, in <module>
    env.wait_for_units()
  File "/usr/local/lib/python2.7/dist-packages/jujuclient.py", line 608,
in wait_for_units
    return WaitForUnits(watch, goal_state).run(callback)
  File "/usr/local/lib/python2.7/dist-packages/jujuclient.py", line 904,
in run
    if self.complete() is True:
  File "/usr/local/lib/python2.7/dist-packages/jujuclient.py", line 944,
in complete
    raise UnitErrors(state['errors'])
jujuclient.UnitErrors
start: Job failed to start

The provisioning script (found in
~/.vagrant.d/boxes/testbox/virtualbox/Vagrantfile):

bzr branch lp:jujuredirector/quickstart /tmp/jujuredir
bash /tmp/jujuredir/setup-juju.sh 6079

In other words; The "real" provisioning script is:
lp:jujuredirector/quickstart/setup-juju.sh

From the directory where you ran "vagrant init testbox", you can run
"vagrant ssh" to log into the virtual box.

Cleanup hints:

- remove the temp directory
- remove the virtualbox created during "vagrant up"
- remove the directory ~/.vagrant/boxes/testbox (contains the unpacked
  vagrnat box, i.e., occupies about 700MB)

[Curtis Hovey (sinzui)]

This appears to be fixed in the tip of 1.20 and master. We see three passes We are testing again to verify the issue is fixed in devel and stable.