juju bootstrap fails inside a wily container

[Adam Stokes]

Running juju 1.24.5 and attempting to do a local bootstrap inside a wily container fails with the following:

[DEBUG: 09-03 20:49:56, container.py:139] Error with command: [Output] '2015-09-03 20:49:35 INFO juju.cmd supercommand.go:37 running juju [1.24.5-wily-amd64 gc]

2015-09-03 20:49:35 DEBUG juju.environs.configstore disk.go:109 Made dir /home/ubuntu/.cloud-install/juju/environments

2015-09-03 20:49:35 INFO juju.provider.local environprovider.go:245 checking state port

2015-09-03 20:49:35 INFO juju.provider.local environprovider.go:245 checking API port

2015-09-03 20:49:35 INFO juju.provider.local environprovider.go:38 opening environment "local"

2015-09-03 20:49:35 DEBUG juju.container.kvm kvm.go:71 kvm-ok output:

INFO: /dev/kvm exists

KVM acceleration can be used

2015-09-03 20:49:35 DEBUG juju.provider.local environ.go:325 found "10.0.6.1" as address for "lxcbr0"

2015-09-03 20:49:35 DEBUG juju.environs.configstore disk.go:308 writing jenv file

2015-09-03 20:49:35 DEBUG juju.environs.configstore disk.go:432 writing jenv file to /home/ubuntu/.cloud-install/juju/environments/local.jenv

2015-09-03 20:49:35 INFO juju.network network.go:194 setting prefer-ipv6 to false

2015-09-03 20:49:35 INFO juju.cmd cmd.go:113 Bootstrapping environment "local"

2015-09-03 20:49:35 DEBUG juju.environs.bootstrap bootstrap.go:98 environment "local" supports service/machine networks: false

2015-09-03 20:49:35 DEBUG juju.environs.bootstrap bootstrap.go:100 network management by juju enabled: true

2015-09-03 20:49:35 DEBUG juju.provider.local environ.go:325 found "10.0.6.1" as address for "lxcbr0"

2015-09-03 20:49:35 INFO juju.cmd cmd.go:113 Starting new instance for initial state server

2015-09-03 20:49:35 INFO juju.environs.bootstrap bootstrap.go:184 newest version: 1.24.5.1

2015-09-03 20:49:36 INFO juju.environs.bootstrap bootstrap.go:212 picked bootstrap tools version: 1.24.5.1

2015-09-03 20:49:36 INFO juju.cmd cmd.go:113 Building tools to upload (1.24.5.1-wily-amd64)

2015-09-03 20:49:36 DEBUG juju.environs.sync sync.go:304 Building tools

2015-09-03 20:49:36 DEBUG juju.environs.tools build.go:122 looking for: juju

2015-09-03 20:49:36 DEBUG juju.environs.tools build.go:161 checking: /usr/bin/jujud

2015-09-03 20:49:36 INFO juju.environs.tools build.go:167 found existing jujud

2015-09-03 20:49:36 INFO juju.environs.tools build.go:177 target: /tmp/juju-tools782467678/jujud

2015-09-03 20:49:36 DEBUG juju.environs.tools build.go:232 forcing version to 1.24.5.1

2015-09-03 20:49:36 DEBUG juju.environs.tools build.go:38 adding entry: &tar.Header{Name:"FORCE-VERSION", Mode:436, Uid:0, Gid:0, Size:8, ModTime:time.Time{sec:63576910176, nsec:90190527, loc:(*time.Location)(0x2c9b140)}, Typeflag:0x30, Linkname:"", Uname:"ubuntu", Gname:"ubuntu", Devmajor:0, Devminor:0, AccessTime:time.Time{sec:63576910176, nsec:90190527, loc:(*time.Location)(0x2c9b140)}, ChangeTime:time.Time{sec:63576910176, nsec:90190527, loc:(*time.Location)(0x2c9b140)}, Xattrs:map[string]string(nil)}

2015-09-03 20:49:36 DEBUG juju.environs.tools build.go:38 adding entry: &tar.Header{Name:"jujud", Mode:493, Uid:0, Gid:0, Size:67623560, ModTime:time.Time{sec:63576910176, nsec:90190527, loc:(*time.Location)(0x2c9b140)}, Typeflag:0x30, Linkname:"", Uname:"ubuntu", Gname:"ubuntu", Devmajor:0, Devminor:0, AccessTime:time.Time{sec:63576910176, nsec:90190527, loc:(*time.Location)(0x2c9b140)}, ChangeTime:time.Time{sec:63576910176, nsec:90190527, loc:(*time.Location)(0x2c9b140)}, Xattrs:map[string]string(nil)}

2015-09-03 20:49:42 INFO juju.environs.sync sync.go:323 built tools 1.24.5.1-wily-amd64 (13769kB)

2015-09-03 20:49:42 INFO juju.cmd cmd.go:113 Installing Juju agent on bootstrap instance

2015-09-03 20:49:42 DEBUG juju.cloudconfig.instancecfg instancecfg.go:521 Setting numa ctl preference to false

2015-09-03 20:49:42 INFO juju.provider.local environ.go:156 local provider; disabling refreshing OS updates.

2015-09-03 20:49:42 INFO juju.provider.local environ.go:162 local provider; disabling OS upgrades.

Logging to /home/ubuntu/.cloud-install/juju/local/cloud-init-output.log on remote host

Installing package: curl

Installing package: cpu-checker

Installing package: bridge-utils

Installing package: rsyslog-gnutls

Installing package: cloud-utils

Installing package: cloud-image-utils

Installing package: tmux

Bootstrapping Juju machine agent

Reading package lists...

Building dependency tree...

Reading state information...

curl is already the newest version.

The following packages were automatically installed and are no longer required:

  libfreetype6 os-prober

Use 'apt-get autoremove' to remove them.

0 upgraded, 0 newly installed, 0 to remove and 44 not upgraded.

Reading package lists...

Building dependency tree...

Reading state information...

cpu-checker is already the newest version.

cpu-checker set to manually installed.

The following packages were automatically installed and are no longer required:

  libfreetype6 os-prober

Use 'apt-get autoremove' to remove them.

0 upgraded, 0 newly installed, 0 to remove and 44 not upgraded.

Reading package lists...

Building dependency tree...

Reading state information...

bridge-utils is already the newest version.

bridge-utils set to manually installed.

The following packages were automatically installed and are no longer required:

  libfreetype6 os-prober

Use 'apt-get autoremove' to remove them.

0 upgraded, 0 newly installed, 0 to remove and 44 not upgraded.

Reading package lists...

Building dependency tree...

Reading state information...

rsyslog-gnutls is already the newest version.

rsyslog-gnutls set to manually installed.

The following packages were automatically installed and are no longer required:

  libfreetype6 os-prober

Use 'apt-get autoremove' to remove them.

0 upgraded, 0 newly installed, 0 to remove and 44 not upgraded.

Reading package lists...

Building dependency tree...

Reading state information...

The following packages were automatically installed and are no longer required:

  libfreetype6 os-prober

Use 'apt-get autoremove' to remove them.

The following NEW packages will be installed:

  cloud-utils

0 upgraded, 1 newly installed, 0 to remove and 44 not upgraded.

Need to get 1,566 B of archives.

After this operation, 32.8 kB of additional disk space will be used.

Get:1 http://archive.ubuntu.com/ubuntu/ wily/main cloud-utils all 0.27-0ubuntu18 [1,566 B]

Fetched 1,566 B in 0s (10.8 kB/s)

Selecting previously unselected package cloud-utils.

(Reading database ...
(Reading database ... 5%
(Reading database ... 10%
(Reading database ... 15%
(Reading database ... 20%
(Reading database ... 25%
(Reading database ... 30%
(Reading database ... 35%
(Reading database ... 40%
(Reading database ... 45%
(Reading database ... 50%
(Reading database ... 55%
(Reading database ... 60%
(Reading database ... 65%
(Reading database ... 70%
(Reading database ... 75%
(Reading database ... 80%
(Reading database ... 85%
(Reading database ... 90%
(Reading database ... 95%
(Reading database ... 100%
(Reading database ... 33706 files and directories currently installed.)

Preparing to unpack .../cloud-utils_0.27-0ubuntu18_all.deb ...

Unpacking cloud-utils (0.27-0ubuntu18) ...

Setting up cloud-utils (0.27-0ubuntu18) ...

Reading package lists...

Building dependency tree...

Reading state information...

cloud-image-utils is already the newest version.

cloud-image-utils set to manually installed.

The following packages were automatically installed and are no longer required:

  libfreetype6 os-prober

Use 'apt-get autoremove' to remove them.

0 upgraded, 0 newly installed, 0 to remove and 44 not upgraded.

Reading package lists...

Building dependency tree...

Reading state information...

tmux is already the newest version.

The following packages were automatically installed and are no longer required:

  libfreetype6 os-prober

Use 'apt-get autoremove' to remove them.

0 upgraded, 0 newly installed, 0 to remove and 44 not upgraded.

eb03889e40c2269052ff95d1cddaf230d4955d17d7e4bb60dc8bc4f8374090bc /home/ubuntu/.cloud-install/juju/local/tools/1.24.5.1-wily-amd64/tools.tar.gz

2015-09-03 20:49:54 INFO juju.cmd supercommand.go:37 running jujud [1.24.5.1-wily-amd64 gc]

2015-09-03 20:49:54 DEBUG juju.agent agent.go:432 read agent config, format "1.18"

2015-09-03 20:49:54 INFO juju.network network.go:194 setting prefer-ipv6 to false

2015-09-03 20:49:54 INFO juju.provider.local environprovider.go:38 opening environment "local"

2015-09-03 20:49:54 DEBUG juju.container.kvm kvm.go:71 kvm-ok output:

INFO: /dev/kvm exists

KVM acceleration can be used

2015-09-03 20:49:55 INFO juju.agent identity.go:22 writing system identity file

2015-09-03 20:49:55 DEBUG juju.cmd.jujud bootstrap.go:253 starting mongo

2015-09-03 20:49:55 DEBUG juju.cmd.jujud bootstrap.go:278 calling ensureMongoServer

2015-09-03 20:49:55 INFO juju.mongo mongo.go:173 Ensuring mongo server is running; data directory /home/ubuntu/.cloud-install/juju/local; port 37017

2015-09-03 20:49:55 INFO juju.mongo mongo.go:348 installing juju-mongodb

2015-09-03 20:49:55 INFO juju.utils.packaging.manager utils.go:57 Running: apt-get --option=Dpkg::Options::=--force-confold --option=Dpkg::options::=--force-unsafe-io --assume-yes --quiet install juju-mongodb

2015-09-03 20:49:55 DEBUG juju.mongo mongo.go:295 using mongod: /usr/lib/juju/bin/mongod --version: "db version v2.4.10\nThu Sep 3 20:49:55.651 git version: nogitversion\n"

2015-09-03 20:49:55 DEBUG juju.service discovery.go:115 discovered init system "systemd" from local host

2015-09-03 20:49:55 DEBUG juju.service.systemd service.go:349 service "juju-db-ubuntu-local" not running

2015-09-03 20:49:56 ERROR juju.service.systemd service.go:145 dbus enable request failed for service "juju-db-ubuntu-local": Unit name /var/lib/juju/init/juju-db-ubuntu-local/juju-db-ubuntu-local.service is not valid.

2015-09-03 20:49:56 DEBUG juju.service.systemd service.go:146 stack trace:

Unit name /var/lib/juju/init/juju-db-ubuntu-local/juju-db-ubuntu-local.service is not valid.

github.com/juju/juju/service/systemd/service.go:500: dbus enable request failed for service "juju-db-ubuntu-local"

2015-09-03 20:49:56 ERROR juju.service.systemd service.go:448 failed to install service "juju-db-ubuntu-local": dbus enable request failed for service "juju-db-ubuntu-local": Unit name /var/lib/juju/init/juju-db-ubuntu-local/juju-db-ubuntu-local.service is not valid.

2015-09-03 20:49:56 ERROR juju.cmd supercommand.go:430 dbus enable request failed for service "juju-db-ubuntu-local": Unit name /var/lib/juju/init/juju-db-ubuntu-local/juju-db-ubuntu-local.service is not valid.

2015-09-03 20:49:56 ERROR juju.cmd supercommand.go:430 failed to bootstrap environment: exit status 1' [Error] ''

Steps to reproduce:

1. Create a wily lxc container on a wily host
2. Log into container, install juju-local
3. Verify kvm_intel is loaded inside the container (may or may not be required, our installer loads this automatically)
4. Setup a local profile
5. juju bootstrap --debug

Or the easiest way is to run the installer:

On wily host

1. sudo apt-add-repository ppa:cloud-installer/experimental
2. sudo apt-get install openstack
3. DEBUG_JUJU_BOOTSTRAP=1 sudo -E openstack-install
4. Select Single install, enter password, wait for exception
5. tail -f ~/.cloud-install/commands.log on host

[Cheryl Jennings (cherylj)]

This is most likely a dup of bug 1480310. Can you update to systemd 224-2ubuntu2 and see if that resolves the issue?

[Adam Stokes (adam-stokes)]

Thanks will test ASAP

[Mike McCracken (mikemc)]

I just tested this with systemd: 225-1ubuntu4
and I still see the same issue as above.

See the juju bootstrap --debug output here, starting at line 85: http://paste.ubuntu.com/12528995/

[Adam Stokes (adam-stokes)]

Hi, any word on this bug? What else can we do to provide more information for you?

[Cheryl Jennings (cherylj)]

Are you guys still having this problem with the latest wily images? If so, can you tell me which version of systemd you have installed?

[Adam Stokes (adam-stokes)]

Yea we're still hitting this bug on wily, heres the systemd output:

ii libpam-systemd:amd64 225-1ubuntu9 amd64 system and service manager - PAM module
ii libsystemd0:amd64 225-1ubuntu9 amd64 systemd utility library
ii systemd 225-1ubuntu9 amd64 system and service manager
ii systemd-sysv 225-1ubuntu9 amd64 system and service manager - SysV links

[Cheryl Jennings (cherylj)]

Opening up a systemd record so that team can take a look.

[Martin Pitt (pitti)]

2015-09-22 22:28:47 ERROR juju.service.systemd service.go:145 dbus enable request failed for service "juju-db-ubuntu-local": Unit name /var/lib/juju/init/juju-db-ubuntu-local/juju-db-ubuntu-local.service is not valid.

What is juju trying to do here? Indeed this isn't an unit *name*, it's a path to a unit. But you can't have units in arbitrary paths, they need to be in {/etc,/lib,/run}/systemd/system/. They can be symlinked there with "systemctl link" or plain ln -s.

[Cheryl Jennings (cherylj)]

Juju will issue a systemctl link to link the unit files, then run systemctl enable. I cannot recreate this issue on wily, either as a host, or a wily container running on a wily host (with or without KVM enabled).

Martin - what information could Adam gather to help debug the issue?