Can't reprovision a machine with manual provider

[Michael Foord]

If I bootstrap to a machine using the manual provider, then destroy-environment and attempt to re-bootstrap it fails. This is because of "turds" left in place that "destroy-environment" doesn't clean-up.

$ juju bootstrap --upload-tools
Bootstrapping environment "manual"
Starting new instance for initial state server
ERROR failed to bootstrap environment: machine is already provisioned

$ ssh michael@192.168.178.180
michael@192.168.178.180's password:
Welcome to Ubuntu 14.04.1 LTS (GNU/Linux 3.13.0-45-generic x86_64)

 * Documentation: https://help.ubuntu.com/

  System information as of Wed Feb 4 17:28:09 GMT 2015

  System load: 0.04 Processes: 94
  Usage of /: 25.0% of 6.76GB Users logged in: 1
  Memory usage: 14% IP address for eth0: 192.168.178.180
  Swap usage: 0%

  Graph this data and manage this system at:
    https://landscape.canonical.com/

Last login: Wed Feb 4 17:20:46 2015 from ubuntubox.fritz.box
michael@ubuntu:~$ sudo find / -name "*juju*"
[sudo] password for michael:
/etc/apt/apt.conf.d/42-juju-proxy-settings
/etc/init/jujud-unit-wordpress-0.conf
/etc/sudoers.d/90-juju-ubuntu
/usr/lib/juju
/usr/lib/python2.7/dist-packages/landscape/lib/juju.pyc
/usr/lib/python2.7/dist-packages/landscape/lib/juju.py
/usr/share/doc/juju-mongodb
/home/ubuntu/.juju-proxy
/var/cache/apt/archives/juju-mongodb_2.4.9-0ubuntu3_amd64.deb
/var/log/juju
/var/log/upstart/juju-db.log
/var/lib/dpkg/info/juju-mongodb.list
/var/lib/dpkg/info/juju-mongodb.md5sums
/var/lib/juju

[Curtis Hovey (sinzui)]

This has happened twice on the machines we do manual provider testing. This also the same problem with a failed destroy-environment with local-provider. When destroy-environment fails to cleanup resources, a subsequent bootstrap will also fail.

I believe destroy-environment --force does not guarantee cleanup of resources, and several people have used --force in error.

Was this failure seen with a released juju version? Does it happen all the time? What --force used?

[Michael Foord (mfoord)]

When using kvm images and the manual provider I see the issue reproducibly even when *not* using --force. This is using trunk, I can test with 1.21 and 1.22 as well to see if it's a regression.

[Michael Foord (mfoord)]

I've just tried again with 1.21, 1.22 and 1.23 (current branches in all cases rather than a released version) and it worked fine. I suspect the problem is therefore that my memory is faulty and I used "--force" to destroy-environment. I'll retry to confirm.

[Michael Foord (mfoord)]

Ok, so it worked when I used "--force" as well. When I was seeing this reliably I had the kvm instance firewalled off to use a proxy. It seems unlikely that this is the difference, but I'll try it and see.

[Michael Foord (mfoord)]

Hah, so with trunk and a firewalled kvm instance (only access to the network via a proxy except for the state server port and ssh) I see the problem.

$ juju bootstrap --upload-tools
Bootstrapping environment "manual"
Starting new instance for initial state server
Building tools to upload (1.23-alpha1.1-trusty-amd64)
Installing Juju agent on bootstrap instance
Logging to /var/log/cloud-init-output.log on remote host
Running apt-get update
Installing package: curl
Installing package: cpu-checker
Installing package: bridge-utils
Installing package: rsyslog-gnutls
Bootstrapping Juju machine agent
Starting Juju machine agent (jujud-machine-0)
Bootstrap complete
$ juju destroy-environment
error: no environment specified
$ juju destroy-environment manual
WARNING! this command will destroy the "manual" environment (type: manual)
This includes all machines, services, data and other resources.

Continue [y/N]? y
$ juju bootstrap --upload-tools
WARNING This juju environment is already bootstrapped. If you want to start a new Juju
environment, first run juju destroy-environment to clean up, or switch to an
alternative environment.
ERROR environment is already bootstrapped

[Chris Gregan (cgregan)]

I have also reproduced this issue using the following steps

1) Bootstrap a manual environment
2) Deploy a charm that fails to complete deployment
3) Reboot local machine to ensure all connections to env are closed
4) Open terminal
5) juju switch
6) juju destroy-environment -e manual

System requests password to local ssh keyfile and attempt to destroy env, but fails
After that destroy says the environment returns that it is not bootstrapped but bootstrap returns that the machine is already provisioned.

[Eric Snow (ericsnowcurrently)]

I poked at this but was not able to get things set up to reproduce. I also tried to take the alternate approach of modifying the "uninstall juju" script that the manual provider runs when destroying the environment:

  https://github.com/juju/juju/blob/juju-1.25.3/provider/manual/environ.go#L283

I deleted the lines that remove the files and directories. However, though the script ran, the directories and files were removed anyway. So not only does that script run but the agent also cleans up after itself directly (e.g. the data dir is deleted when the agent gets ErrTerminateAgent).

Anyway, apparently the proxy-dependent scenario is causing that both the manual provider's cleanup script *and* the machine agent's cleanup operations are getting circumvented. That said, it looks like *some* files were cleaned up (e.g. /etc/rsyslog.d/25-juju.conf), based on Michael's origin post-destroy file listing.

So hopefully that combination of clues gets us closer to the source of the problem.

[Nate Finch (natefinch)]

I don't seem to need to do anything special for this to break.. it just breaks randomly some of the time, as far as I can tell.

[Nate Finch (natefinch)]

Here's the end of the log... the problem is a panic during shutdown:

....
2016-05-06 02:52:25 ERROR juju.worker runner.go:212 fatal "instancepoller": watcher has been stopped
2016-05-06 02:52:25 ERROR juju.worker runner.go:212 fatal "environ-provisioner": watcher has been stopped
2016-05-06 02:52:25 ERROR juju.worker runner.go:212 fatal "firewaller": watcher has been stopped
2016-05-06 02:52:25 ERROR juju.worker runner.go:223 exited "ceffd324-fb1b-488c-894d-3ddc5e0c5216": watcher has been stopped
2016-05-06 02:52:25 ERROR juju.worker runner.go:212 fatal "api-post-upgrade": watcher has been stopped
2016-05-06 02:52:25 ERROR juju.worker runner.go:223 exited "api": watcher has been stopped
panic: send on closed channel

goroutine 776 [running]:
panic(0x1937800, 0xc820aeda00)
 /home/nate/go/src/runtime/panic.go:464 +0x3e6
github.com/godbus/dbus.(*Conn).inWorker(0xc820620480)
 /home/nate/src/github.com/godbus/dbus/conn.go:327 +0x1048
created by github.com/godbus/dbus.(*Conn).Auth
 /home/nate/src/github.com/godbus/dbus/auth.go:118 +0xf3d

[Nate Finch (natefinch)]

There's a bug filed (by the intrepid davecheney, no less) back in november:
https://github.com/godbus/dbus/issues/45

The response? PRs welcome, we don't care, we never close the connections anyway.

[Nate Finch (natefinch)]

I have a fix... it's super simple. Just needs a test, but it's late, so I'm punting on that.

For our purposes, we can patch it as needed for demos.

Here's my PR to the original repo: https://github.com/godbus/dbus/pull/64

[Nate Finch (natefinch)]

PR now has a test that will show the panic if you remove the fix: https://github.com/godbus/dbus/pull/64

[Nate Finch (natefinch)]

PR for fix in our repo here: https://github.com/juju/juju/pull/5363

[Cheryl Jennings (cherylj)]

Nate - was the update to godbus the only change needed to fix this bug?

[Anastasia (anastasia-macmood)]

@Nate

Could you please update this report?

I saw that your fix to 1.25 has landed. Has the fix landed in master too?

Is there anything else needed to consider this bug fixed?

Thank you :)

[Nate Finch (natefinch)]

The fix is landed in both 1.25 and master. It's been in master since May 9th.