MAAS

Bug #1740935
Comment #3

Comment 3 for bug 1740935

Revision history for this message

Chris Sanders (chris.sanders) wrote on 2018-01-02:

I've just re-run this while watching all 3 of the maas log files.

Rackd.log has no output during this operation.

regiond:
2018-01-02 21:16:48 regiond: [info] 10.0.100.1 GET /MAAS/api/2.0/users/?op=whoami HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:53 regiond: [info] 10.0.100.1 GET /MAAS/api/2.0/users/?op=whoami HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:53 regiond: [info] 10.0.100.1 GET /MAAS/api/2.0/zones/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:55 regiond: [info] 127.0.0.1 GET /MAAS/rpc/ HTTP/1.0 --> 200 OK (referrer: -; agent: provisioningserver.rpc.clusterservice.ClusterClientService)
2018-01-02 21:16:56 regiond: [info] 10.0.100.1 POST /MAAS/api/2.0/machines/?op=allocate HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:56 regiond: [info] 10.0.100.1 POST /MAAS/api/2.0/machines/xyxwet/?op=deploy HTTP/1.1 --> 400 BAD_REQUEST (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:57 regiond: [info] 10.0.100.1 POST /MAAS/api/2.0/machines/?op=release HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:57 regiond: [info] 10.0.100.1 GET /MAAS/api/2.0/files/9b344ab7-ed2a-4295-8cb3-e2f94301d5b9-provider-state/ HTTP/1.1 --> 404 NOT_FOUND (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:57 regiond: [info] 10.0.100.1 GET /MAAS/api/2.0/machines/?agent_name=9b344ab7-ed2a-4295-8cb3-e2f94301d5b9 HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:16:57 regiond: [info] 10.0.100.1 GET /MAAS/api/2.0/files/?prefix=9b344ab7-ed2a-4295-8cb3-e2f94301d5b9- HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
2018-01-02 21:17:02 maasserver.region_controller: [info] Reloaded DNS configuration; removed node native-ibex

maas.log:
Jan 2 21:16:53 maas2 maas.api: [info] Request from user admin to acquire a machine with constraints: [('mem', ['3584']), ('zone', ['default']), ('agent_name', ['9b344ab7-ed2a-4295-8cb3-e2f94301d5b9'])]
Jan 2 21:16:54 maas2 maas.drivers.pod.virsh: [info] native-ibex: Successfully set network boot order
Jan 2 21:16:56 maas2 maas.node: [info] native-ibex: Storage layout was set to flat.
Jan 2 21:16:56 maas2 maas.node: [info] native-ibex: Status transition from READY to ALLOCATED
Jan 2 21:16:56 maas2 maas.node: [info] native-ibex: allocated to user admin
Jan 2 21:16:56 maas2 maas.node: [info] native-ibex: Releasing node
Jan 2 21:16:56 maas2 maas.node: [info] native-ibex: Status transition from ALLOCATED to RELEASING
Jan 2 21:16:56 maas2 maas.node: [info] native-ibex: Decomposing machine
Jan 2 21:16:57 maas2 maas.node: [info] native-ibex: Deleting machine

juju bootstrap debug:
juju bootstrap maas2-lxd --debug
15:16:48 INFO juju.cmd supercommand.go:56 running juju [2.3.1 gc go1.9.2]
15:16:48 DEBUG juju.cmd supercommand.go:57 args: []string{"/snap/juju/3106/bin/juju", "bootstrap", "maas2-lxd", "--debug"}
15:16:48 DEBUG juju.cmd.juju.commands bootstrap.go:826 authenticating with region "" and credential "maas-creds" ()
15:16:48 DEBUG juju.cmd.juju.commands bootstrap.go:954 provider attrs: map[]
15:16:48 INFO cmd authkeys.go:114 Adding contents of "/home/chris/.local/share/juju/ssh/juju_id_rsa.pub" to authorized-keys
15:16:48 INFO cmd authkeys.go:114 Adding contents of "/home/chris/.ssh/id_rsa.pub" to authorized-keys
15:16:48 DEBUG juju.cmd.juju.commands bootstrap.go:1010 preparing controller with config: map[max-status-history-size:5G type:maas transmit-vendor-metrics:true development:false enable-os-refresh-update:true egress-subnets: firewall-mode:instance resource-tags: name:controller fan-config: uuid:9b344ab7-ed2a-4295-8cb3-e2f94301d5b9 default-series:xenial apt-no-proxy: automatically-retry-hooks:true max-status-history-age:336h agent-stream:released proxy-ssh:false net-bond-reconfigure-delay:17 test-mode:false max-action-results-age:336h enable-os-upgrade:true update-status-hook-interval:5m authorized-keys:ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCaLXFR1bZIufdEMhJ/dSgX6VWo4OHI2nb2MZu61hyxnC6ynaITWCxGwBFFBduilIixBZ27TQZTIw5rCeh1jMXlAshTGT/W0hTIs85NO3/bZ6xtj8FXFTcLLaZD4zm8ZiSULAggTQYP5UrjkwoDuIWYwR0ZPm2PwNAu/0cUydkr8eeUwJiWarTKjugaVufT85vC+H9AzypviSBQaIeU1kXA+ny1FvnHm7+mFWCDG1Iyky4uP9A4vumt93EyS7WVmirJ6IranvLDmwwQKrEjcyGUxbn+hZ1lf0HKzKzJmuBWiU1+4DNXey9SLeru2AMETHahGSbgqT8P6ELMcKhjMi1/ juju-client-key
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDEjX1LfTNmy2kd4jhSWliNGkkDzBebyrwDnHq1DMG8UebN1aVms7RFJFZQLmFo5L4fxfVgu9YAQxKa7bPbHH8+TWTPuqN1mC9d2XCy9cSGa/28/rslxh+ex+Kn4DejriGiEgJjrtTjDfOB+FxBb64oaudA/yPksENcw51ycB74fshPhP+XnQadqt8WD7HmMUk8YfH5QzDfKgPpCcZV5eHjgVfL9ritUANK6swCycHhZoo+wFG3pDXW1eQorKB+oT5FK6Rwk9QE0kPW52CpyYSstj5DBJK6ZGBM+I8m8hxR5km6G1h/Yh3/d2D3tubq0qAxLYzAO7Gkq+PbJR0ij1H2aooKFbNb3y5fMSvRI6wcty2ZkubtBKUUz93CUlAR3ZOLcEL6Mspa8ICak7ay0P4BtQIoysGSvEBBX158e4wE0r0dJRBA3C3mnGDTsqTCFd/CZOWH1PaMUjEaCPyCSwIp6fB8VtfeRM/lgwNsJoIljgzqgdfhgyKiiHUQJM4Vsoz65Ud7vvFv7uoqL7gYHgunoz5FjDluBoOF3Y2egcTkXnPvON2VJyPuutNVnWGAfWrnAQOORItmk1G7GIqN9xKnA8fXfWMfCPbkE+YLJRJkttrhoOppwdjROPpzS04i8jYHpQ7rFsvtgKpfo+QExzyp7AmIkme5+ba1LHNBbBjuGQ== chris@chris-XPS-15-9550
cloudinit-userdata: image-stream:released logforward-enabled:false ftp-proxy: max-action-results-size:5G apt-ftp-proxy: apt-http-proxy: agent-metadata-url: apt-https-proxy: ignore-machine-addresses:false logging-config: ssl-hostname-verification:true image-metadata-url: container-networking-method: provisioner-harvest-mode:destroyed http-proxy: disable-network-management:false https-proxy: apt-mirror: no-proxy:127.0.0.1,localhost,::1]
15:16:48 DEBUG juju.provider.maas environprovider.go:61 opening model "controller".
15:16:49 INFO cmd bootstrap.go:499 Creating Juju controller "maas2-lxd" on maas2-lxd
15:16:49 INFO juju.cmd.juju.commands bootstrap.go:563 combined bootstrap constraints:
15:16:49 DEBUG juju.environs.bootstrap bootstrap.go:199 model "controller" supports service/machine networks: true
15:16:49 DEBUG juju.environs.bootstrap bootstrap.go:201 network management by juju enabled: true
15:16:49 INFO cmd bootstrap.go:233 Loading image metadata
15:16:49 INFO cmd bootstrap.go:296 Looking for packaged Juju agent version 2.3.1 for amd64
15:16:49 INFO juju.environs.bootstrap tools.go:72 looking for bootstrap agent binaries: version=2.3.1
15:16:49 DEBUG juju.environs.tools tools.go:102 finding agent binaries in stream: "released"
15:16:49 DEBUG juju.environs.tools tools.go:104 reading agent binaries with major.minor version 2.3
15:16:49 DEBUG juju.environs.tools tools.go:112 filtering agent binaries by version: 2.3.1
15:16:49 DEBUG juju.environs.tools tools.go:118 filtering agent binaries by architecture: amd64
15:16:49 DEBUG juju.environs.tools urls.go:109 trying datasource "keystone catalog"
15:16:50 DEBUG juju.environs.simplestreams simplestreams.go:683 using default candidate for content id "com.ubuntu.juju:released:tools" are {20161007 mirrors:1.0 content-download streams/v1/cpc-mirrors.sjson []}
15:16:52 INFO juju.environs.bootstrap tools.go:74 found 16 packaged agent binaries
15:16:53 INFO cmd bootstrap.go:371 Starting new instance for initial controller
15:16:53 INFO cmd bootstrap.go:151 Launching controller instance(s) on maas2-lxd...
15:16:53 DEBUG juju.provider.maas environ.go:929 attempting to acquire node in zone "default"
15:16:56 DEBUG juju.cloudconfig.instancecfg instancecfg.go:828 Setting numa ctl preference to false
15:16:56 DEBUG juju.service discovery.go:63 discovered init system "systemd" from series "xenial"
15:16:56 DEBUG juju.provider.maas environ.go:1019 maas user data; 4200 bytes
15:16:57 ERROR juju.cmd.juju.commands bootstrap.go:519 failed to bootstrap model: cannot start bootstrap instance: unexpected: ServerError: 400 BAD REQUEST (Failed to render preseed: 'NoneType' object has no attribute 'url')
15:16:57 DEBUG juju.cmd.juju.commands bootstrap.go:520 (error details: [{github.com/juju/juju/cmd/juju/commands/bootstrap.go:611: failed to bootstrap model} {github.com/juju/juju/provider/common/bootstrap.go:202: cannot start bootstrap instance} {github.com/juju/juju/provider/maas/environ.go:1043: } {github.com/juju/juju/provider/maas/environ.go:882: } {github.com/juju/gomaasapi/errors.go:41: } {github.com/juju/gomaasapi/controller.go:745: } {github.com/juju/gomaasapi/controller.go:776: } {github.com/juju/gomaasapi/client.go:124: } {ServerError: 400 BAD REQUEST (Failed to render preseed: 'NoneType' object has no attribute 'url')}])
15:16:57 DEBUG juju.cmd.juju.commands bootstrap.go:1117 cleaning up after failed bootstrap
15:16:57 INFO juju.provider.common destroy.go:20 destroying model "controller"
15:16:57 INFO juju.provider.common destroy.go:31 destroying instances
15:16:57 INFO juju.provider.common destroy.go:55 destroying storage
15:16:58 INFO cmd supercommand.go:465 command finished

This is a fresh install that I just completed, let the image sync complete, and tried to bootstrap.

I've just re-run this while watching all 3 of the maas log files.

Rackd.log has no output during this operation.

maas.log:
Jan  2 21:16:53 maas2 maas.api: [info] Request from user admin to acquire a machine with constraints: [('mem', ['3584']), ('zone', ['default']), ('agent_name', ['9b344ab7-ed2a-4295-8cb3-e2f94301d5b9'])]
Jan  2 21:16:54 maas2 maas.drivers.pod.virsh: [info] native-ibex: Successfully set network boot order
Jan  2 21:16:56 maas2 maas.node: [info] native-ibex: Storage layout was set to flat.
Jan  2 21:16:56 maas2 maas.node: [info] native-ibex: Status transition from READY to ALLOCATED
Jan  2 21:16:56 maas2 maas.node: [info] native-ibex: allocated to user admin
Jan  2 21:16:56 maas2 maas.node: [info] native-ibex: Releasing node
Jan  2 21:16:56 maas2 maas.node: [info] native-ibex: Status transition from ALLOCATED to RELEASING
Jan  2 21:16:56 maas2 maas.node: [info] native-ibex: Decomposing machine
Jan  2 21:16:57 maas2 maas.node: [info] native-ibex: Deleting machine

juju bootstrap debug:
juju bootstrap maas2-lxd --debug
15:16:48 INFO  juju.cmd supercommand.go:56 running juju [2.3.1 gc go1.9.2]
15:16:48 DEBUG juju.cmd supercommand.go:57   args: []string{"/snap/juju/3106/bin/juju", "bootstrap", "maas2-lxd", "--debug"}
15:16:48 DEBUG juju.cmd.juju.commands bootstrap.go:826 authenticating with region "" and credential "maas-creds" ()
15:16:48 DEBUG juju.cmd.juju.commands bootstrap.go:954 provider attrs: map[]
15:16:48 INFO  cmd authkeys.go:114 Adding contents of "/home/chris/.local/share/juju/ssh/juju_id_rsa.pub" to authorized-keys
15:16:48 INFO  cmd authkeys.go:114 Adding contents of "/home/chris/.ssh/id_rsa.pub" to authorized-keys
15:16:48 DEBUG juju.cmd.juju.commands bootstrap.go:1010 preparing controller with config: map[max-status-history-size:5G type:maas transmit-vendor-metrics:true development:false enable-os-refresh-update:true egress-subnets: firewall-mode:instance resource-tags: name:controller fan-config: uuid:9b344ab7-ed2a-4295-8cb3-e2f94301d5b9 default-series:xenial apt-no-proxy: automatically-retry-hooks:true max-status-history-age:336h agent-stream:released proxy-ssh:false net-bond-reconfigure-delay:17 test-mode:false max-action-results-age:336h enable-os-upgrade:true update-status-hook-interval:5m authorized-keys:ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCaLXFR1bZIufdEMhJ/dSgX6VWo4OHI2nb2MZu61hyxnC6ynaITWCxGwBFFBduilIixBZ27TQZTIw5rCeh1jMXlAshTGT/W0hTIs85NO3/bZ6xtj8FXFTcLLaZD4zm8ZiSULAggTQYP5UrjkwoDuIWYwR0ZPm2PwNAu/0cUydkr8eeUwJiWarTKjugaVufT85vC+H9AzypviSBQaIeU1kXA+ny1FvnHm7+mFWCDG1Iyky4uP9A4vumt93EyS7WVmirJ6IranvLDmwwQKrEjcyGUxbn+hZ1lf0HKzKzJmuBWiU1+4DNXey9SLeru2AMETHahGSbgqT8P6ELMcKhjMi1/ juju-client-key
ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDEjX1LfTNmy2kd4jhSWliNGkkDzBebyrwDnHq1DMG8UebN1aVms7RFJFZQLmFo5L4fxfVgu9YAQxKa7bPbHH8+TWTPuqN1mC9d2XCy9cSGa/28/rslxh+ex+Kn4DejriGiEgJjrtTjDfOB+FxBb64oaudA/yPksENcw51ycB74fshPhP+XnQadqt8WD7HmMUk8YfH5QzDfKgPpCcZV5eHjgVfL9ritUANK6swCycHhZoo+wFG3pDXW1eQorKB+oT5FK6Rwk9QE0kPW52CpyYSstj5DBJK6ZGBM+I8m8hxR5km6G1h/Yh3/d2D3tubq0qAxLYzAO7Gkq+PbJR0ij1H2aooKFbNb3y5fMSvRI6wcty2ZkubtBKUUz93CUlAR3ZOLcEL6Mspa8ICak7ay0P4BtQIoysGSvEBBX158e4wE0r0dJRBA3C3mnGDTsqTCFd/CZOWH1PaMUjEaCPyCSwIp6fB8VtfeRM/lgwNsJoIljgzqgdfhgyKiiHUQJM4Vsoz65Ud7vvFv7uoqL7gYHgunoz5FjDluBoOF3Y2egcTkXnPvON2VJyPuutNVnWGAfWrnAQOORItmk1G7GIqN9xKnA8fXfWMfCPbkE+YLJRJkttrhoOppwdjROPpzS04i8jYHpQ7rFsvtgKpfo+QExzyp7AmIkme5+ba1LHNBbBjuGQ== chris@chris-XPS-15-9550
 cloudinit-userdata: image-stream:released logforward-enabled:false ftp-proxy: max-action-results-size:5G apt-ftp-proxy: apt-http-proxy: agent-metadata-url: apt-https-proxy: ignore-machine-addresses:false logging-config: ssl-hostname-verification:true image-metadata-url: container-networking-method: provisioner-harvest-mode:destroyed http-proxy: disable-network-management:false https-proxy: apt-mirror: no-proxy:127.0.0.1,localhost,::1]
15:16:48 DEBUG juju.provider.maas environprovider.go:61 opening model "controller".
15:16:49 INFO  cmd bootstrap.go:499 Creating Juju controller "maas2-lxd" on maas2-lxd
15:16:49 INFO  juju.cmd.juju.commands bootstrap.go:563 combined bootstrap constraints: 
15:16:49 DEBUG juju.environs.bootstrap bootstrap.go:199 model "controller" supports service/machine networks: true
15:16:49 DEBUG juju.environs.bootstrap bootstrap.go:201 network management by juju enabled: true
15:16:49 INFO  cmd bootstrap.go:233 Loading image metadata
15:16:49 INFO  cmd bootstrap.go:296 Looking for packaged Juju agent version 2.3.1 for amd64
15:16:49 INFO  juju.environs.bootstrap tools.go:72 looking for bootstrap agent binaries: version=2.3.1
15:16:49 DEBUG juju.environs.tools tools.go:102 finding agent binaries in stream: "released"
15:16:49 DEBUG juju.environs.tools tools.go:104 reading agent binaries with major.minor version 2.3
15:16:49 DEBUG juju.environs.tools tools.go:112 filtering agent binaries by version: 2.3.1
15:16:49 DEBUG juju.environs.tools tools.go:118 filtering agent binaries by architecture: amd64
15:16:49 DEBUG juju.environs.tools urls.go:109 trying datasource "keystone catalog"
15:16:50 DEBUG juju.environs.simplestreams simplestreams.go:683 using default candidate for content id "com.ubuntu.juju:released:tools" are {20161007 mirrors:1.0 content-download streams/v1/cpc-mirrors.sjson []}
15:16:52 INFO  juju.environs.bootstrap tools.go:74 found 16 packaged agent binaries
15:16:53 INFO  cmd bootstrap.go:371 Starting new instance for initial controller
15:16:53 INFO  cmd bootstrap.go:151 Launching controller instance(s) on maas2-lxd...
15:16:53 DEBUG juju.provider.maas environ.go:929 attempting to acquire node in zone "default"
15:16:56 DEBUG juju.cloudconfig.instancecfg instancecfg.go:828 Setting numa ctl preference to false
15:16:56 DEBUG juju.service discovery.go:63 discovered init system "systemd" from series "xenial"
15:16:56 DEBUG juju.provider.maas environ.go:1019 maas user data; 4200 bytes
15:16:57 ERROR juju.cmd.juju.commands bootstrap.go:519 failed to bootstrap model: cannot start bootstrap instance: unexpected: ServerError: 400 BAD REQUEST (Failed to render preseed: 'NoneType' object has no attribute 'url')
15:16:57 DEBUG juju.cmd.juju.commands bootstrap.go:520 (error details: [{github.com/juju/juju/cmd/juju/commands/bootstrap.go:611: failed to bootstrap model} {github.com/juju/juju/provider/common/bootstrap.go:202: cannot start bootstrap instance} {github.com/juju/juju/provider/maas/environ.go:1043: } {github.com/juju/juju/provider/maas/environ.go:882: } {github.com/juju/gomaasapi/errors.go:41: } {github.com/juju/gomaasapi/controller.go:745: } {github.com/juju/gomaasapi/controller.go:776: } {github.com/juju/gomaasapi/client.go:124: } {ServerError: 400 BAD REQUEST (Failed to render preseed: 'NoneType' object has no attribute 'url')}])
15:16:57 DEBUG juju.cmd.juju.commands bootstrap.go:1117 cleaning up after failed bootstrap
15:16:57 INFO  juju.provider.common destroy.go:20 destroying model "controller"
15:16:57 INFO  juju.provider.common destroy.go:31 destroying instances
15:16:57 INFO  juju.provider.common destroy.go:55 destroying storage
15:16:58 INFO  cmd supercommand.go:465 command finished

This is a fresh install that I just completed, let the image sync complete, and tried to bootstrap.