juju bootstrap fails, apt-get update fails, zookeeper doesn't install

[Donald Pearson]

After issuing the command 'juju bootstrap'
Monitoring with 'juju -v status' returns the following which will cycle indefinitely.

2012-08-17 18:18:18,444 DEBUG Spawning SSH process with remote_user="ubuntu" remote_host="Galaxy2" remote_port="2181" local_port="48794".
2012-08-17 18:18:18,953:9418(0x7fc007146700):ZOO_INFO@log_env@658: Client environment:zookeeper.version=zookeeper C client 3.3.5
2012-08-17 18:18:18,953:9418(0x7fc007146700):ZOO_INFO@log_env@662: Client environment:host.name=Galaxy1
2012-08-17 18:18:18,954:9418(0x7fc007146700):ZOO_INFO@log_env@669: Client environment:os.name=Linux
2012-08-17 18:18:18,954:9418(0x7fc007146700):ZOO_INFO@log_env@670: Client environment:os.arch=3.2.0-23-generic
2012-08-17 18:18:18,954:9418(0x7fc007146700):ZOO_INFO@log_env@671: Client environment:os.version=#36-Ubuntu SMP Tue Apr 10 20:39:51 UTC 2012
2012-08-17 18:18:18,954:9418(0x7fc007146700):ZOO_INFO@log_env@679: Client environment:user.name=donald
2012-08-17 18:18:18,954:9418(0x7fc007146700):ZOO_INFO@log_env@687: Client environment:user.home=/home/donald
2012-08-17 18:18:18,955:9418(0x7fc007146700):ZOO_INFO@log_env@699: Client environment:user.dir=/home/donald
2012-08-17 18:18:18,955:9418(0x7fc007146700):ZOO_INFO@zookeeper_init@727: Initiating client connection, host=localhost:48794 sessionTimeout=10000 watcher=0x7fc0050ea6b0 sessionId=0 sessionPasswd=<null> context=0x318da70 flags=0
2012-08-17 18:18:18,955:9418(0x7fc001e44700):ZOO_INFO@check_events@1585: initiated connection to server [127.0.0.1:48794]
2012-08-17 18:18:18,957:9418(0x7fc001e44700):ZOO_ERROR@handle_socket_error_msg@1603: Socket [127.0.0.1:48794] zk retcode=-4, errno=112(Host is down): failed while receiving a server response

This appears to be a zookeeper problem.
Logging in to the remote node, the following errors appear in lock-step with the MaaS primary box's looping of the zookeeper failures above, showing a constant attempt and failure to connect to localhost on the zookeeper port 2181.

Aug 17 18:20:18 Galaxy2 sshd[6593]: Accepted publickey for ubuntu from 192.168.10.10 port 56629 ssh2
Aug 17 18:20:18 Galaxy2 sshd[6593]: pam_unix(sshd:session): session opened for user ubuntu by (uid=0)
Aug 17 18:20:19 Galaxy2 sshd[6723]: error: connect_to localhost port 2181: failed.
Aug 17 18:20:19 Galaxy2 sshd[6723]: error: connect_to localhost port 2181: failed.
Aug 17 18:20:19 Galaxy2 sshd[6723]: Received disconnect from 192.168.10.10: 11: disconnected by user
Aug 17 18:20:19 Galaxy2 sshd[6593]: pam_unix(sshd:session): session closed for user ubuntu

/var/log/cloud-init-output.log shows that an apt-get update command fails to access some repositories. For example:
Err http://ubuntu-mirror precise-updates/main i386 Packages
  403 Forbidden

This causes the failure of some packages to be installed.

WARNING: The following packages cannot be authenticated!
  libavahi-client3 ttf-dejavu-core fontconfig-config libfontconfig1
  libpixman-1-0 libxcb-render0 libxcb-shm0 libxrender1 libcairo2 libcups2
  libdatrie1 x11-common libice6 libjpeg-turbo8 libnspr4 libnss3 libthai-data
  libthai0 libxft2 fontconfig libpango1.0-0 libsm6 libxt6 libxmu6 libxpm4
  libxaw7 libzookeeper-mt2 libjpeg8 libgd2-noxpm java-common
  default-jre-headless libnss3-1d ca-certificates-java tzdata-java
  python-bzrlib bzr fonts-liberation libcdt4 libcgraph5 libgraph4 libpathplan4
  libgvc5 libgvpr1 graphviz python-pyasn1 python-twisted-conch
  python-twisted-mail python-twisted-web python-twisted-lore
  python-twisted-names python-twisted-news python-twisted-runner
  python-twisted-words python-twisted python-zookeeper python-txzookeeper
  python-dateutil python-txaws juju libjline-java liblog4j1.2-java
  libnetty-java libservlet2.5-java libxml-commons-resolver1.1-java
  libxml-commons-external-java libxerces2-java libzookeeper-java
  python-support python-pyparsing python-pydot python-setuptools
  ttf-liberation zookeeper zookeeperd
E: There are problems and -y was used without --force-yes
2012-08-17 17:40:20,711 - cc_apt_update_upgrade.py[WARNING]: Failed to install packages: ['bzr', 'byobu', 'tmux', 'python-setuptools', 'python-twisted', 'python-txaws', 'python-zookeeper', 'default-jre-headless', 'zookeeper', 'zookeeperd', 'juju']
2012-08-17 17:40:20,714 - __init__.py[WARNING]: Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/cloudinit/CloudConfig/__init__.py", line 117, in run_cc_modules
    cc.handle(name, run_args, freq=freq)
  File "/usr/lib/python2.7/dist-packages/cloudinit/CloudConfig/__init__.py", line 78, in handle
    [name, self.cfg, self.cloud, cloudinit.log, args])
  File "/usr/lib/python2.7/dist-packages/cloudinit/__init__.py", line 326, in sem_and_run
    func(*args)
  File "/usr/lib/python2.7/dist-packages/cloudinit/CloudConfig/cc_apt_update_upgrade.py", line 103, in handle
    raise errors[0]
CalledProcessError: Command '['apt-get', '--option', 'Dpkg::Options::=--force-confold', '--assume-yes', 'update']' returned non-zero exit status 100

2012-08-17 17:40:20,714 - __init__.py[ERROR]: config handling of apt-update-upgrade, None, [] failed

2012-08-17 17:40:20,737 - cloud-init-cfg[ERROR]: errors running cloud_config [config]: ['apt-update-upgrade']
errors running cloud_config [config]: ['apt-update-upgrade']
/var/lib/cloud/instance/scripts/runcmd: 4: /var/lib/cloud/instance/scripts/runcmd: juju-admin: not found

Zookeeper, and a host of other packages fail to install on the remote node, ultimately causing the 'juju bootstrap' command to fail.

Manually running 'sudo apt-get update' on the remote node fails in the same manner.

/etc/apt/sources.list on the remote node shows ubuntu-mirror as the domain for all packages.

[Donald Pearson (donaldwhpearson)]

Full cloud-init-output.log

ubuntu@Galaxy2:~$ cat /var/log/cloud-init-output.log
Generating public/private rsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_rsa_key.
Your public key has been saved in /etc/ssh/ssh_host_rsa_key.pub.
The key fingerprint is:
bd:3e:14:5e:ca:4b:1c:e4:1b:f6:a7:f3:dd:2e:b1:74 root@Galaxy2
The key's randomart image is:
+--[ RSA 2048]----+
| |
| . |
| o |
| .* . |
| S=.O |
| O.. + E|
| o.. + + |
| .o o o..|
| .. o.o+|
+-----------------+
Generating public/private dsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_dsa_key.
Your public key has been saved in /etc/ssh/ssh_host_dsa_key.pub.
The key fingerprint is:
79:01:c1:87:6e:2b:14:15:c9:03:c5:9c:14:08:0a:f8 root@Galaxy2
The key's randomart image is:
+--[ DSA 1024]----+
|o ...@OB |
|.. . o X.. |
| .. o o. |
| E . o. . |
| . .S.. |
| . .. |
| . |
| |
| |
+-----------------+
Generating public/private ecdsa key pair.
Your identification has been saved in /etc/ssh/ssh_host_ecdsa_key.
Your public key has been saved in /etc/ssh/ssh_host_ecdsa_key.pub.
The key fingerprint is:
4c:9d:23:53:75:70:7c:f0:bd:5c:33:c6:5e:2c:2e:56 root@Galaxy2
The key's randomart image is:
+--[ECDSA 256]---+
| ..oo+. |
| o . oooo|
| + + E**|
| o o . o+.*|
| S o .+ |
| . . |
| |
| |
| |
+-----------------+
Generating locales...
  en_US.UTF-8... up-to-date
Generation complete.
Ign http://ubuntu-mirror precise InRelease
Ign http://ubuntu-mirror precise-updates InRelease
Ign http://ubuntu-mirror precise Release.gpg
Ign http://ubuntu-mirror precise-updates Release.gpg
Ign http://ubuntu-mirror precise Release
Ign http://ubuntu-mirror precise-updates Release
Ign http://ubuntu-mirror precise/main Sources/DiffIndex
Ign http://ubuntu-mirror precise/universe Sources/DiffIndex
Ign http://ubuntu-mirror precise/main amd64 Packages/DiffIndex
Ign http://ubuntu-mirror precise/universe amd64 Packages/DiffIndex
Ign http://ubuntu-mirror precise/main i386 Packages/DiffIndex
Ign http://ubuntu-mirror precise/universe i386 Packages/DiffIndex
Ign http://ubuntu-mirror precise/main TranslationIndex
Ign http://ubuntu-mirror precise/universe TranslationIndex
Ign http://ubuntu-mirror precise-updates/main Sources/DiffIndex
Ign http://ubuntu-mirror precise-updates/universe Sources/DiffIndex
Ign http://ubuntu-mirror precise-updates/main amd64 Packages/DiffIndex
Ign http://ubuntu-mirror precise-updates/universe amd64 Packages/DiffIndex
Ign http://ubuntu-mirror precise-updates/main i386 Packages/DiffIndex
Ign http://ubuntu-mirror precise-updates/universe i386 Packages/DiffIndex
Ign http://ubuntu-mirror precise-updates/main TranslationIndex
Ign http://ubuntu-mirror precise-updates/universe TranslationIndex
Ign http://security.ubuntu.com precise-security InRelease
Err http://ubuntu-mirror precise/main Sources
  403 Forbidden
Err http://ubuntu-mirror precise/universe Sources
  403 Forbidden
Err http://ubuntu...

[Donald Pearson (donaldwhpearson)]

Full cloud-init.log

ubuntu@Galaxy2:~$ cat /var/log/cloud-init.log
2012-08-17 17:39:31,059 - cloud-init[INFO]: cloud-init start-local running: Fri, 17 Aug 2012 21:39:30 +0000. up 3.70 seconds
2012-08-17 17:39:31,095 - __init__.py[DEBUG]: searching for data source in []
2012-08-17 17:39:31,095 - __init__.py[DEBUG]: Did not find data source. searched classes: []
2012-08-17 17:39:33,003 - cloud-init[INFO]: cloud-init start running: Fri, 17 Aug 2012 21:39:32 +0000. up 5.73 seconds
2012-08-17 17:39:33,017 - __init__.py[DEBUG]: searching for data source in ['DataSourceMAAS']
2012-08-17 17:39:33,041 - DataSourceMAAS.py[DEBUG]: Using metadata source: 'http://192.168.10.10/MAAS/metadata//2012-03-01/meta-data/instance-id'
2012-08-17 17:39:33,168 - __init__.py[DEBUG]: found data source DataSourceMAAS
2012-08-17 17:39:33,232 - cloud-init[DEBUG]: found data source: DataSourceMAAS[http://192.168.10.10/MAAS/metadata/]
2012-08-17 17:39:33,261 - __init__.py[DEBUG]: handling bootcmd with freq=None and args=[]
2012-08-17 17:39:33,471 - __init__.py[DEBUG]: handling resizefs with freq=None and args=[]
2012-08-17 17:39:33,584 - cc_resizefs.py[DEBUG]: resize took 0.108814954758 seconds
2012-08-17 17:39:33,584 - cc_resizefs.py[DEBUG]: resizing root filesystem (type=ext4, maj=8, min=1, val=True)
2012-08-17 17:39:33,584 - __init__.py[DEBUG]: handling set_hostname with freq=None and args=[]
2012-08-17 17:39:33,689 - cc_set_hostname.py[DEBUG]: populated /etc/hostname with Galaxy2 on first boot
2012-08-17 17:39:33,690 - __init__.py[DEBUG]: handling update_hostname with freq=None and args=[]
2012-08-17 17:39:33,691 - cc_update_hostname.py[DEBUG]: wrote Galaxy2 to /var/lib/cloud/data/previous-hostname
2012-08-17 17:39:33,692 - __init__.py[DEBUG]: handling update_etc_hosts with freq=None and args=[]
2012-08-17 17:39:33,693 - cc_update_etc_hosts.py[DEBUG]: managing 127.0.1.1 in /etc/hosts
2012-08-17 17:39:33,693 - __init__.py[DEBUG]: handling ca-certs with freq=None and args=[]
2012-08-17 17:39:33,694 - __init__.py[DEBUG]: handling rsyslog with freq=None and args=[]
2012-08-17 17:39:33,695 - __init__.py[DEBUG]: handling ssh with freq=None and args=[]
Aug 17 17:39:35 Galaxy2 [CLOUDINIT] cloud-init-cfg[INFO]: cloud-init-cfg ['all', 'config']
Aug 17 17:39:35 Galaxy2 [CLOUDINIT] __init__.py[DEBUG]: handling mounts with freq=None and args=[]
Aug 17 17:39:35 Galaxy2 [CLOUDINIT] __init__.py[DEBUG]: handling ssh-import-id with freq=None and args=[]
Aug 17 17:39:35 Galaxy2 [CLOUDINIT] __init__.py[DEBUG]: handling locale with freq=None and args=[]
Aug 17 17:39:35 Galaxy2 [CLOUDINIT] cc_locale.py[DEBUG]: setting locale to en_US.UTF-8
Aug 17 17:39:36 Galaxy2 [CLOUDINIT] __init__.py[DEBUG]: handling set-passwords with freq=None and args=[]
Aug 17 17:39:36 Galaxy2 [CLOUDINIT] __init__.py[DEBUG]: handling grub-dpkg with freq=None and args=[]
Aug 17 17:39:36 Galaxy2 [CLOUDINIT] cc_grub_dpkg.py[DEBUG]: setting grub debconf-set-selections with '/dev/sda','false'
Aug 17 17:39:36 Galaxy2 [CLOUDINIT] __init__.py[DEBUG]: handling apt-pipelining with freq=None and args=[]
Aug 17 17:39:36 Galaxy2 [CLOUDINIT] cc_apt_pipelining.py[DEBUG]: Wrote /etc/apt/apt.conf.d/90cloud-init-pipelining with APT pi...

[Julian Edwards (julian-edwards)]

It's failing because the juju installation on the node is not completing

--------
Err http://ubuntu-mirror precise/main Sources
  403 Forbidden
---------

Whatever your "ubuntu-mirror" is, it's not accepting connections.