ERROR creating hosted model: model already exists

Bug #1738993 reported by Kevin Wennemuth
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Canonical Juju
Incomplete
High
Unassigned
2.3
Fix Released
High
Andrew Wilkins

Bug Description

juju bootstrap vsphere/esx.power.lab jujucontroller --to zone=esx.power.lab --config primary-network="VM Network" --config external-network="VM Network" --config datastore=ds00 --debug

...

10:03:52 INFO juju.cmd supercommand.go:56 running juju [2.3.1 gc go1.9.2]
10:03:52 DEBUG juju.cmd supercommand.go:57 args: []string{"juju", "bootstrap", "vsphere/esx.power.lab", "jujucontroller", "--to", "zone=esx.power.lab", "--config", "primary-network=VM Network", "--config", "external-network=VM Network", "--config", "datastore=ds00", "--debug"}

2017-12-19 09:42:59 DEBUG juju.agent.agentbootstrap bootstrap.go:302 create new random password for machine 0
2017-12-19 09:42:59 DEBUG juju.state open.go:306 closed state without error
2017-12-19 09:42:59 DEBUG juju.worker runner.go:223 killing runner 0xc420373e10
2017-12-19 09:42:59 INFO juju.worker runner.go:313 runner is dying
2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "pingbatcher"
2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "leadership"
2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "singular"
2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "txnlog"
2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "presence"
2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "pingbatcher", err: <nil>
2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "presence", err: <nil>
2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "singular", err: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "pingbatcher" done: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing "pingbatcher" from known workers
2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "presence" done: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing "presence" from known workers
2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "singular" done: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing "singular" from known workers
2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "txnlog", err: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "txnlog" done: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing "txnlog" from known workers
2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "leadership", err: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "leadership" done: <nil>
2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing "leadership" from known workers
2017-12-19 09:42:59 DEBUG juju.state open.go:306 closed state without error
ERROR creating hosted model: model already exists
2017-12-19 09:42:59 DEBUG cmd supercommand.go:459 error stack:
github.com/juju/juju/state/model.go:428: model already exists
github.com/juju/juju/state/model.go:432:
github.com/juju/juju/agent/agentbootstrap/bootstrap.go:216: creating hosted model
github.com/juju/juju/cmd/jujud/agent/agent.go:104:
2017-12-19 09:42:59 DEBUG juju.cmd.jujud main.go:187 jujud complete, code 0, err <nil>
10:42:59 ERROR juju.cmd.juju.commands bootstrap.go:519 failed to bootstrap model: subprocess encountered error code 1
10:42:59 DEBUG juju.cmd.juju.commands bootstrap.go:520 (error details: [{github.com/juju/juju/cmd/juju/commands/bootstrap.go:611: failed to bootstrap model} {subprocess encountered error code 1}])
10:42:59 DEBUG juju.cmd.juju.commands bootstrap.go:1117 cleaning up after failed bootstrap
10:43:00 INFO juju.provider.common destroy.go:20 destroying model "controller"
10:43:00 INFO juju.provider.common destroy.go:31 destroying instances
10:43:01 DEBUG juju.provider.vmware client.go:105 powering off "juju-e08976-0"
10:43:01 DEBUG juju.provider.vmware client.go:114 destroying "juju-e08976-0"
10:43:02 INFO juju.provider.common destroy.go:55 destroying storage
10:43:04 DEBUG juju.provider.vmware client.go:84 no VMs matching path "Juju Controller (2f0c0337-429d-4523-8327-32a0103fcae2)/Model \"*\" (*)/*"
10:43:05 DEBUG juju.provider.vmware environ.go:233 deleting: [ds03] juju-vmdks/2f0c0337-429d-4523-8327-32a0103fcae2
10:43:05 DEBUG juju.provider.vmware environ.go:233 deleting: [ds02] juju-vmdks/2f0c0337-429d-4523-8327-32a0103fcae2
10:43:05 DEBUG juju.provider.vmware environ.go:233 deleting: [ds00] juju-vmdks/2f0c0337-429d-4523-8327-32a0103fcae2
10:43:06 INFO cmd supercommand.go:465 command finished

The full log is attached

Revision history for this message
Kevin Wennemuth (feffi) wrote :
Revision history for this message
Kevin Wennemuth (feffi) wrote :

Tested with various combinations: CLI Version 2.3.1

juju bootstrap vsphere/esx.power.lab jujucontroller --to zone=esx.power.lab --config primary-network="VM Network" --config external-network="VM Network" --config datastore=ds00

juju bootstrap vsphere jujucontroller --to zone=esx.power.lab --config primary-network="VM Network" --config external-network="VM Network" --config datastore=ds00

juju bootstrap vsphere jujucontroller --config primary-network="VM Network" --config external-network="VM Network" --config datastore=ds00

Revision history for this message
John A Meinel (jameinel) wrote : Re: [Bug 1738993] [NEW] ERROR creating hosted model: model already exists
Download full text (5.8 KiB)

Is there any chance that the VM's disk was not clean? I know we saw similar
failures in MAAS when it would re-use a machine that had been a controller
previously, and the disk was not wiped.

From the detailed log, it does look like this was a clean install (apt
install juju-mongodb3.2 took 1.5min to complete). So that doesn't seem to
explain it.

If it is a fresh install, then it would be very surprising for the hosted
model "(eg 'default')" to already exist.

I don't see anything in the above that would cause us to change the name of
either "controller" or "default" unless there is config somewhere in
~/.local/share/juju that is defining this cloud with something custom.

On Tue, Dec 19, 2017 at 2:01 PM, Kevin Wennemuth <<email address hidden>
> wrote:

> Public bug reported:
>
> juju bootstrap vsphere/esx.power.lab jujucontroller --to
> zone=esx.power.lab --config primary-network="VM Network" --config
> external-network="VM Network" --config datastore=ds00 --debug
>
> ...
>
> 10:03:52 INFO juju.cmd supercommand.go:56 running juju [2.3.1 gc go1.9.2]
> 10:03:52 DEBUG juju.cmd supercommand.go:57 args: []string{"juju",
> "bootstrap", "vsphere/esx.power.lab", "jujucontroller", "--to",
> "zone=esx.power.lab", "--config", "primary-network=VM Network", "--config",
> "external-network=VM Network", "--config", "datastore=ds00", "--debug"}
>
> 2017-12-19 09:42:59 DEBUG juju.agent.agentbootstrap bootstrap.go:302
> create new random password for machine 0
> 2017-12-19 09:42:59 DEBUG juju.state open.go:306 closed state without error
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:223 killing runner
> 0xc420373e10
> 2017-12-19 09:42:59 INFO juju.worker runner.go:313 runner is dying
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "pingbatcher"
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "leadership"
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "singular"
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "txnlog"
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:456 killing "presence"
> 2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "pingbatcher",
> err: <nil>
> 2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "presence",
> err: <nil>
> 2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "singular",
> err: <nil>
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "pingbatcher" done:
> <nil>
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing
> "pingbatcher" from known workers
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "presence" done: <nil>
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing
> "presence" from known workers
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "singular" done: <nil>
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing
> "singular" from known workers
> 2017-12-19 09:42:59 INFO juju.worker runner.go:483 stopped "txnlog", err:
> <nil>
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:332 "txnlog" done: <nil>
> 2017-12-19 09:42:59 DEBUG juju.worker runner.go:395 no restart, removing
> "txnlog" from known workers
> 2017-12-19 09:42:59 INFO juju.worker...

Read more...

Revision history for this message
John A Meinel (jameinel) wrote : Re: [Bug 1738993] Re: ERROR creating hosted model: model already exists

Is there anything about "datastore" that is causing us to re-use the same
block disk between runs?

On Tue, Dec 19, 2017 at 4:31 PM, Kevin Wennemuth <<email address hidden>
> wrote:

> Tested with various combinations: CLI Version 2.3.1
>
> juju bootstrap vsphere/esx.power.lab jujucontroller --to
> zone=esx.power.lab --config primary-network="VM Network" --config
> external-network="VM Network" --config datastore=ds00
>
> juju bootstrap vsphere jujucontroller --to zone=esx.power.lab --config
> primary-network="VM Network" --config external-network="VM Network"
> --config datastore=ds00
>
> juju bootstrap vsphere jujucontroller --config primary-network="VM
> Network" --config external-network="VM Network" --config datastore=ds00
>
> --
> You received this bug notification because you are subscribed to juju.
> Matching subscriptions: juju bugs
> https://bugs.launchpad.net/bugs/1738993
>
> Title:
> ERROR creating hosted model: model already exists
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/juju/+bug/1738993/+subscriptions
>

Revision history for this message
Kevin Wennemuth (feffi) wrote :

rerun with juju 2.2.8

Revision history for this message
Kevin Wennemuth (feffi) wrote :

Hi, just reran the same with juju 2.2.8

./juju bootstrap vsphere jujucontroller --config primary-network="VM Network" --config external-network="VM Network" --config datastore=ds00 --debug

...
21:49:54 INFO juju.cmd supercommand.go:63 running juju [2.2.8 gc go1.8]
...

same outcome. So here are my configs, maybe they can help.

------------------------------
vsphere.yml

---
clouds:
  vsphere:
    type: vsphere
    auth-types: [userpass]
    endpoint: 10.1.1.174
    regions:
      esx.power.lab: {}
------------------------------

credentials.yml
------------------------------
---
credentials:
  vsphere:
    default-credential: test01
    test01:
      auth-type: userpass
      password: test01
      username: <email address hidden>
------------------------------

Revision history for this message
Kevin Wennemuth (feffi) wrote :

The datastore is clean, I manually deleted the leftovers from juju-vmdk upload after each unsuccessful run.

Revision history for this message
Kevin Wennemuth (feffi) wrote :

Hi, to clarify this whole story a bit:

I'm deploying on an on premise vsphere. All datastores and vm's in use are cleared after a juju run, so no dragons here.
I'm running juju on macOS 10.13.2 High Sierra and now did a rerun with a clean install and an uninstall beforehand. Outcome: same error.

@see detailed_log_run_after_cleanup.txt

-------------------------------------------------------------------------------------
$ brew uninstall juju juju-quickstart juju-wait
$ rm -rf /Users/test01/.local/share/juju
$ brew install juju juju-quickstart juju-wait
-------------------------------------------------------------------------------------
$ juju add-cloud vsphere vsphere.yml
Since Juju 2 is being run for the first time, downloading latest cloud information.
Fetching latest public cloud list...
Updated your list of public clouds with 4 cloud regions deleted:

    deleted cloud region:
        - google/europe-west2
        - google/europe-west3
        - google/southamerica-east1
        - google/us-east4
-------------------------------------------------------------------------------------
$ juju clouds
Cloud Regions Default Type Description
aws 14 us-east-1 ec2 Amazon Web Services
aws-china 1 cn-north-1 ec2 Amazon China
aws-gov 1 us-gov-west-1 ec2 Amazon (USA Government)
azure 26 centralus azure Microsoft Azure
azure-china 2 chinaeast azure Microsoft Azure China
cloudsigma 5 hnl cloudsigma CloudSigma Cloud
google 9 us-east1 gce Google Cloud Platform
joyent 6 eu-ams-1 joyent Joyent Cloud
oracle 5 uscom-central-1 oracle Oracle Compute Cloud Service
rackspace 6 dfw rackspace Rackspace Cloud
localhost 1 localhost lxd LXD Container Hypervisor
vsphere 1 esx.power.lab vsphere

Try 'list-regions <cloud>' to see available regions.
-------------------------------------------------------------------------------------
$ juju add-credential vsphere
Enter credential name: test01
Using auth-type "userpass".
Enter user: <email address hidden>
Enter password:
Credentials added for cloud vsphere.
-------------------------------------------------------------------------------------
$ juju set-default-credential vsphere test01
Default credential for vsphere set to "test01".
-------------------------------------------------------------------------------------
$ juju list-credentials
Cloud Credentials
vsphere test01*
-------------------------------------------------------------------------------------
$ juju bootstrap vsphere jujucontroller --config primary-network="VM Network" --config external-network="VM Network" --config datastore=ds00 --debug

...

Revision history for this message
Kevin Wennemuth (feffi) wrote :

Hi, any more data needed to track or fix this?

Andrew Wilkins (axwalk)
Changed in juju:
status: New → Triaged
importance: Undecided → High
Revision history for this message
Andrew Wilkins (axwalk) wrote :

Kevin, the error message is incorrect of course (the model can't exist already during bootstrap!), but it did point to the cause. There's a transaction failure in mongo caused by us not escaping the dots in the region name.

As a workaround, you can change the region name from esx.power.lab to, say, esx-power-lab. We'll look to fix things to allow dots in the mean time.

Revision history for this message
Andrew Wilkins (axwalk) wrote :
Revision history for this message
NecLimDul (neclimdul) wrote :

I know this was only just committed so not trying to rush it but curious when could we expect to see a release with this in it.

Revision history for this message
Tim Penhey (thumper) wrote :

We are looking to release 2.3.2 early next week.

Revision history for this message
Kevin Wennemuth (feffi) wrote :

This sounds nice. Thanks for your effort! I'll try it as soon as it's released.

Revision history for this message
Heather Lanigan (hmlanigan) wrote :

@feffi, was the issue resolved in 2.3.2?

Changed in juju:
status: Triaged → Incomplete
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.