machine-0: 14:20:26 INFO juju.cmd running jujud [2.8-beta1 0  gc go1.10.4]
machine-0: 14:20:26 DEBUG juju.cmd   args: []string{"/var/lib/juju/tools/machine-0/jujud", "machine", "--data-dir", "/var/lib/juju", "--machine-id", "0", "--debug"}
machine-0: 14:20:26 DEBUG juju.utils setting GOMAXPROCS to 2
machine-0: 14:20:26 DEBUG juju.agent read agent config, format "2.0"
machine-0: 14:20:28 INFO juju.worker.upgradesteps upgrade steps for 2.8-beta1 have already been run.
machine-0: 14:20:28 DEBUG juju.worker.dependency "upgrade-steps-gate" manifold worker started at 2020-03-20 19:20:28.41810181 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "upgrade-check-gate" manifold worker started at 2020-03-20 19:20:28.418661565 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "agent" manifold worker started at 2020-03-20 19:20:28.421797597 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "termination-signal-handler" manifold worker started at 2020-03-20 19:20:28.421902923 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "clock" manifold worker started at 2020-03-20 19:20:28.42196217 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "upgrade-check-flag" manifold worker started at 2020-03-20 19:20:28.423180467 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.introspection introspection worker listening on "@jujud-machine-0"
machine-0: 14:20:28 DEBUG juju.worker.introspection stats worker now serving
machine-0: 14:20:28 DEBUG juju.worker.dependency "upgrade-steps-flag" manifold worker started at 2020-03-20 19:20:28.427508247 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "api-config-watcher" manifold worker started at 2020-03-20 19:20:28.432152784 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "state-config-watcher" manifold worker started at 2020-03-20 19:20:28.433157219 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.apicaller connecting with current password
machine-0: 14:20:28 DEBUG juju.api looked up localhost -> [127.0.0.1]
machine-0: 14:20:28 DEBUG juju.worker.dependency "central-hub" manifold worker started at 2020-03-20 19:20:28.443386291 +0000 UTC
machine-0: 14:20:28 INFO juju.mongo Ensuring mongo server is running; data directory /var/lib/juju; port 37017
machine-0: 14:20:28 INFO juju.packaging installing "mongodb-server-core" via "apt"
machine-0: 14:20:28 INFO juju.packaging.manager Running: apt-get --option=Dpkg::Options::=--force-confold --option=Dpkg::Options::=--force-unsafe-io --assume-yes --quiet install mongodb-server-core
machine-0: 14:20:28 DEBUG juju.worker.pubsub subscribing to details topic
machine-0: 14:20:28 DEBUG juju.worker.dependency "pubsub-forwarder" manifold worker started at 2020-03-20 19:20:28.453274477 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.dependency "presence" manifold worker started at 2020-03-20 19:20:28.453688379 +0000 UTC
machine-0: 14:20:28 DEBUG juju.worker.apicaller [4b38a0] failed to connect
machine-0: 14:20:28 DEBUG juju.worker.dependency "api-caller" manifold worker stopped: [4b38a0] "machine-0" cannot open api: unable to connect to API: dial tcp 127.0.0.1:17070: connect: connection refused
machine-0: 14:20:28 ERROR juju.worker.dependency "api-caller" manifold worker returned unexpected error: [4b38a0] "machine-0" cannot open api: unable to connect to API: dial tcp 127.0.0.1:17070: connect: connection refused
machine-0: 14:20:28 DEBUG juju.worker.dependency stack trace:
dial tcp 127.0.0.1:17070: connect: connection refused
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:1109: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:1084: unable to connect to API
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:980: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:635: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:213: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/apicaller/connect.go:156: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/apicaller/connect.go:211: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/apicaller/manifold.go:97: [4b38a0] "machine-0" cannot open api
machine-0: 14:20:28 INFO juju.packaging installing "mongodb-clients" via "apt"
machine-0: 14:20:28 INFO juju.packaging.manager Running: apt-get --option=Dpkg::Options::=--force-confold --option=Dpkg::Options::=--force-unsafe-io --assume-yes --quiet install mongodb-clients
machine-0: 14:20:29 DEBUG juju.mongo using mongod: /usr/bin/mongod --version: "db version v3.6.3\ngit version: 9586e557d54ef70f9ca4b43c26892cd55257e1a5\nOpenSSL version: OpenSSL 1.1.1  11 Sep 2018\nallocator: tcmalloc\nmodules: none\nbuild environment:\n    distarch: x86_64\n    target_arch: x86_64\n"
machine-0: 14:20:29 DEBUG juju.mongo creating mongo service configuration for mongo version: 3.6.3- at "/usr/bin/mongod"
machine-0: 14:20:29 DEBUG juju.service discovered init system "systemd" from local host
machine-0: 14:20:29 DEBUG juju.mongo updating mongo service configuration
machine-0: 14:20:31 DEBUG juju.service.systemd service "juju-db" successfully stopped
machine-0: 14:20:31 INFO juju.service Installing and starting service &{Service:{Name:juju-db Conf:{Desc:juju state database Transient:false AfterStopped: Env:map[] Limit:map[fsize:unlimited cpu:unlimited as:unlimited memlock:unlimited nofile:64000 nproc:64000] Timeout:300 ExecStart:/usr/bin/mongod --auth --bind_ip_all --dbpath '/var/lib/juju/db' --ipv6 --journal --keyFile '/var/lib/juju/shared-secret' --oplogSize 1024 --port 37017 --quiet --replSet juju --sslMode requireSSL --sslPEMKeyFile '/var/lib/juju/server.pem' --sslPEMKeyPassword=ignored --storageEngine wiredTiger --syslog ExecStopPost: Logfile: ExtraScript: ServiceBinary: ServiceArgs:[]}} ConfName:juju-db.service UnitName:juju-db.service DirName:/etc/systemd/system FallBackDirName:/var/lib/juju/init Script:[] fileOps:{} newDBus:0xb8e1b0}
machine-0: 14:20:31 DEBUG juju.service.systemd service "juju-db" not running
machine-0: 14:20:31 DEBUG juju.worker.apicaller connecting with current password
machine-0: 14:20:31 DEBUG juju.api looked up localhost -> [127.0.0.1]
machine-0: 14:20:32 DEBUG juju.worker.apicaller [4b38a0] failed to connect
machine-0: 14:20:32 DEBUG juju.worker.dependency "api-caller" manifold worker stopped: [4b38a0] "machine-0" cannot open api: unable to connect to API: dial tcp 127.0.0.1:17070: connect: connection refused
machine-0: 14:20:32 ERROR juju.worker.dependency "api-caller" manifold worker returned unexpected error: [4b38a0] "machine-0" cannot open api: unable to connect to API: dial tcp 127.0.0.1:17070: connect: connection refused
machine-0: 14:20:32 DEBUG juju.worker.dependency stack trace:
dial tcp 127.0.0.1:17070: connect: connection refused
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:1109: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:1084: unable to connect to API
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:980: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:635: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:213: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/apicaller/connect.go:156: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/apicaller/connect.go:211: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/apicaller/manifold.go:97: [4b38a0] "machine-0" cannot open api
machine-0: 14:20:32 DEBUG juju.service.systemd service "juju-db" successfully removed
machine-0: 14:20:32 DEBUG juju.service.systemd service "juju-db" successfully installed
machine-0: 14:20:32 DEBUG juju.service.systemd service "juju-db" not running
machine-0: 14:20:32 DEBUG juju.service.systemd service "juju-db" successfully started
machine-0: 14:20:32 DEBUG juju.service started &{{juju-db {juju state database false  map[] map[fsize:unlimited cpu:unlimited as:unlimited memlock:unlimited nofile:64000 nproc:64000] 300 /usr/bin/mongod --auth --bind_ip_all --dbpath '/var/lib/juju/db' --ipv6 --journal --keyFile '/var/lib/juju/shared-secret' --oplogSize 1024 --port 37017 --quiet --replSet juju --sslMode requireSSL --sslPEMKeyFile '/var/lib/juju/server.pem' --sslPEMKeyPassword=ignored --storageEngine wiredTiger --syslog     []}} juju-db.service juju-db.service /etc/systemd/system /var/lib/juju/init [] {} 0xb8e1b0}
machine-0: 14:20:32 DEBUG juju.cmd.jujud mongodb service is installed
machine-0: 14:20:32 DEBUG juju.mongo mongodb connection failed, will retry: dial tcp 127.0.0.1:37017: connect: connection refused
machine-0: 14:20:33 DEBUG juju.mongo mongodb connection failed, will retry: dial tcp 127.0.0.1:37017: connect: connection refused
machine-0: 14:20:33 DEBUG juju.mongo mongodb connection failed, will retry: dial tcp 127.0.0.1:37017: connect: connection refused
machine-0: 14:20:34 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:34 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:35 INFO juju.state using client-side transactions
machine-0: 14:20:35 INFO juju.state starting standard state workers
machine-0: 14:20:35 INFO juju.state creating cloud image metadata storage
machine-0: 14:20:35 INFO juju.state started state for model-4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a successfully
machine-0: 14:20:35 DEBUG juju.state.presence using $bit operations with Mongo 3.6.3
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:35 INFO juju.cmd.jujud juju database opened
machine-0: 14:20:35 DEBUG juju.worker.dependency "state" manifold worker started at 2020-03-20 19:20:35.903785862 +0000 UTC
machine-0: 14:20:35 INFO juju.state using client-side transactions
machine-0: 14:20:35 INFO juju.state starting standard state workers
machine-0: 14:20:35 INFO juju.state creating cloud image metadata storage
machine-0: 14:20:35 INFO juju.state started state for model-939f511d-617c-4e70-87fd-61418f460257 successfully
machine-0: 14:20:35 DEBUG juju.state.presence using $bit operations with Mongo 3.6.3
machine-0: 14:20:35 DEBUG juju.worker.dependency "is-controller-flag" manifold worker started at 2020-03-20 19:20:35.922577606 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "restore-watcher" manifold worker started at 2020-03-20 19:20:35.923304432 +0000 UTC
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:35 DEBUG juju.worker.dependency "controller-port" manifold worker started at 2020-03-20 19:20:35.925534206 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "model-cache-initialized-gate" manifold worker started at 2020-03-20 19:20:35.932330546 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "legacy-leases-flag" manifold worker started at 2020-03-20 19:20:35.932911786 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "lease-manager" manifold worker started at 2020-03-20 19:20:35.933361321 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "audit-config-updater" manifold worker started at 2020-03-20 19:20:35.934075056 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "upgrade-database-gate" manifold worker started at 2020-03-20 19:20:35.934226372 +0000 UTC
machine-0: 14:20:35 INFO juju.worker.apiservercertwatcher new certificate addresses: 
machine-0: 14:20:35 DEBUG juju.worker.dependency "certificate-watcher" manifold worker started at 2020-03-20 19:20:35.935309495 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "http-server-args" manifold worker started at 2020-03-20 19:20:35.937160983 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "model-cache-initialized-flag" manifold worker started at 2020-03-20 19:20:35.941585772 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "upgrade-database-flag" manifold worker started at 2020-03-20 19:20:35.943684582 +0000 UTC
machine-0: 14:20:35 DEBUG juju.cmd.jujud mongo is already initialized
machine-0: 14:20:35 DEBUG juju.worker.dependency "raft-transport" manifold worker started at 2020-03-20 19:20:35.948846147 +0000 UTC
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:35 DEBUG juju.worker.dependency "multiwatcher" manifold worker started at 2020-03-20 19:20:35.954459297 +0000 UTC
machine-0: 14:20:35 DEBUG juju.worker.dependency "model-cache" manifold worker started at 2020-03-20 19:20:35.96765914 +0000 UTC
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:35 INFO juju.state using client-side transactions
machine-0: 14:20:35 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:35 INFO juju.state allwatcher loaded for model "4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a" in 19.147863ms
machine-0: 14:20:35 INFO juju.state allwatcher loaded for model "939f511d-617c-4e70-87fd-61418f460257" in 5.431096ms
machine-0: 14:20:35 DEBUG juju.worker.dependency "model-cache-initialized-flag" manifold worker stopped: gate unlocked
machine-0: 14:20:35 DEBUG juju.worker.dependency "model-cache-initialized-flag" manifold worker started at 2020-03-20 19:20:35.996187904 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-server" manifold worker started at 2020-03-20 19:20:36.019702458 +0000 UTC
machine-0: 14:20:36 INFO juju.worker.httpserver listening on "[::]:17070"
machine-0: 14:20:36 DEBUG juju.worker.dependency "http-server" manifold worker started at 2020-03-20 19:20:36.031147456 +0000 UTC
machine-0: 14:20:36 DEBUG juju.state mongodb initialised
machine-0: 14:20:36 INFO juju.state starting standard state workers
machine-0: 14:20:36 INFO juju.state creating cloud image metadata storage
machine-0: 14:20:36 INFO juju.state started state for model-4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a successfully
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-database-runner" manifold worker started at 2020-03-20 19:20:36.035870922 +0000 UTC
machine-0: 14:20:36 DEBUG juju.state.presence using $bit operations with Mongo 3.6.3
machine-0: 14:20:36 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:36 DEBUG juju.state closed state without error
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-database-runner" manifold worker completed successfully
machine-0: 14:20:36 DEBUG juju.worker.apicaller connecting with current password
machine-0: 14:20:36 DEBUG juju.api looked up localhost -> [127.0.0.1]
machine-0: 14:20:36 DEBUG juju.apiserver [1] API connection from 127.0.0.1:44686
machine-0: 14:20:36 DEBUG juju.api successfully dialed "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:36 INFO juju.api connection established to "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:36 DEBUG juju.apiserver <- [1]  {"request-id":1,"type":"Admin","version":3,"request":"Login","params":"'params redacted'"}
machine-0: 14:20:36 INFO juju.apiserver.connection agent login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:36 DEBUG juju.apiserver model login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:36 DEBUG juju.apiserver -> [1]  1.531151ms {"request-id":1,"response":"'body redacted'"} Admin[""].Login
machine-0: 14:20:36 INFO juju.worker.apicaller [4b38a0] "machine-0" successfully connected to "localhost:17070"
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":2,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 756.726µs {"request-id":2,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":3,"type":"Agent","version":2,"request":"SetPasswords","params":"'params redacted'"}
machine-0: 14:20:36 INFO juju.apiserver.common setting mongo password for "machine-0"
machine-0: 14:20:36 INFO juju.apiserver.common setting password for "machine-0"
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 26.090833ms {"request-id":3,"response":"'body redacted'"} Agent[""].SetPasswords
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-caller" manifold worker started at 2020-03-20 19:20:36.745612109 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":4,"type":"Machiner","version":2,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":5,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrader" manifold worker started at 2020-03-20 19:20:36.756161696 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":6,"type":"Singular","version":2,"request":"Claim","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":7,"type":"Upgrader","version":1,"request":"SetTools","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 2.810759ms {"request-id":5,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":8,"type":"MigrationFlag","version":1,"request":"Phase","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":9,"type":"CredentialValidator","version":2,"request":"WatchModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 7.970691ms {"request-id":4,"response":"'body redacted'"} Machiner[""].Life
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":10,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 730.605µs {"request-id":10,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-steps-runner" manifold worker started at 2020-03-20 19:20:36.764724128 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-steps-runner" manifold worker completed successfully
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 5.317897ms {"request-id":8,"response":"'body redacted'"} MigrationFlag[""].Phase
machine-0: 14:20:36 DEBUG juju.worker.dependency "migration-inactive-flag" manifold worker started at 2020-03-20 19:20:36.765466863 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":11,"type":"MigrationFlag","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 13.430914ms {"request-id":9,"response":"'body redacted'"} CredentialValidator[""].WatchModelCredential
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":12,"type":"CredentialValidator","version":2,"request":"WatchCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":13,"type":"NotifyWatcher","version":1,"id":"1","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 10.48765ms {"request-id":11,"response":"'body redacted'"} MigrationFlag[""].Watch
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 20.088778ms {"request-id":7,"response":"'body redacted'"} Upgrader[""].SetTools
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":14,"type":"MigrationFlag","version":1,"request":"Phase","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":15,"type":"NotifyWatcher","version":1,"id":"2","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 516.024µs {"request-id":14,"response":"'body redacted'"} MigrationFlag[""].Phase
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":16,"type":"Upgrader","version":1,"request":"WatchAPIVersion","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 10.780341ms {"request-id":12,"response":"'body redacted'"} CredentialValidator[""].WatchCredential
machine-0: 14:20:36 DEBUG juju.worker.dependency "valid-credential-flag" manifold worker started at 2020-03-20 19:20:36.78528867 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":17,"type":"NotifyWatcher","version":1,"id":"3","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":18,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 847.952µs {"request-id":18,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":19,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 745.006µs {"request-id":19,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 10.520398ms {"request-id":16,"response":"'body redacted'"} Upgrader[""].WatchAPIVersion
machine-0: 14:20:36 INFO juju.worker.upgrader abort check blocked until version event received
machine-0: 14:20:36 INFO juju.worker.upgrader unblocking abort check
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":20,"type":"NotifyWatcher","version":1,"id":"4","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":21,"type":"Upgrader","version":1,"request":"DesiredVersion","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 1.292748ms {"request-id":21,"response":"'body redacted'"} Upgrader[""].DesiredVersion
machine-0: 14:20:36 INFO juju.worker.upgrader desired agent binary version: 2.8-beta1
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-check-flag" manifold worker stopped: gate unlocked
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-check-flag" manifold worker started at 2020-03-20 19:20:36.801375287 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "model-worker-manager" manifold worker started at 2020-03-20 19:20:36.810616986 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "peer-grouper" manifold worker started at 2020-03-20 19:20:36.811942343 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "migration-fortress" manifold worker started at 2020-03-20 19:20:36.812277502 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "certificate-updater" manifold worker started at 2020-03-20 19:20:36.812795076 +0000 UTC
machine-0: 14:20:36 DEBUG juju.workers.modelworkermanager starting workers for model "admin-controller" (4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a)
machine-0: 14:20:36 DEBUG juju.worker.dependency "model-upgrade-gate" manifold worker started at 2020-03-20 19:20:36.815505077 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "agent" manifold worker started at 2020-03-20 19:20:36.815562816 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "clock" manifold worker started at 2020-03-20 19:20:36.815631763 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.peergrouper controller nodes in state: []string{"0"}
machine-0: 14:20:36 DEBUG juju.worker.certupdater new machine addresses: network.SpaceAddresses{local-cloud:172.31.38.92}
machine-0: 14:20:36 DEBUG juju.workers.modelworkermanager starting workers for model "admin-validate-multus" (939f511d-617c-4e70-87fd-61418f460257)
machine-0: 14:20:36 DEBUG juju.worker.certupdater existing cert addresses map[]
machine-0: 14:20:36 DEBUG juju.worker.certupdater new addresses [localhost juju-apiserver juju-mongodb anything 172.31.38.92]
machine-0: 14:20:36 DEBUG juju.worker.peergrouper found new controller "0"
machine-0: 14:20:36 DEBUG juju.worker.dependency "agent" manifold worker started at 2020-03-20 19:20:36.819512697 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "clock" manifold worker started at 2020-03-20 19:20:36.819551156 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "model-upgrade-gate" manifold worker started at 2020-03-20 19:20:36.819582665 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.peergrouper controller "0" not ready: pending
machine-0: 14:20:36 DEBUG juju.worker.dependency "migration-minion" manifold worker started at 2020-03-20 19:20:36.824231003 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":22,"type":"MigrationMinion","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 285.31µs {"request-id":22,"response":"'body redacted'"} MigrationMinion[""].Watch
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":23,"type":"MigrationStatusWatcher","version":1,"id":"5","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.worker.dependency "model-upgraded-flag" manifold worker started at 2020-03-20 19:20:36.825816362 +0000 UTC
machine-0: 14:20:36 DEBUG juju.api looked up localhost -> [127.0.0.1]
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-config-watcher" manifold worker started at 2020-03-20 19:20:36.843672712 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-config-watcher" manifold worker started at 2020-03-20 19:20:36.84374146 +0000 UTC
machine-0: 14:20:36 DEBUG juju.api looked up localhost -> [127.0.0.1]
machine-0: 14:20:36 DEBUG juju.worker.dependency "model-upgraded-flag" manifold worker started at 2020-03-20 19:20:36.844147867 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 35.07526ms {"request-id":23,"response":"'body redacted'"} MigrationStatusWatcher["5"].Next
machine-0: 14:20:36 INFO juju.worker.migrationminion migration phase is now: NONE
machine-0: 14:20:36 DEBUG juju.worker.dependency "storage-provisioner" manifold worker started at 2020-03-20 19:20:36.865033938 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "ssh-authkeys-updater" manifold worker started at 2020-03-20 19:20:36.865086056 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "disk-manager" manifold worker started at 2020-03-20 19:20:36.865131074 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-series" manifold worker started at 2020-03-20 19:20:36.8652763 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.logger initial log config: "<root>=DEBUG"
machine-0: 14:20:36 DEBUG juju.worker.dependency "logging-config-updater" manifold worker started at 2020-03-20 19:20:36.865371547 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.fanconfigurer Processing new fan config
machine-0: 14:20:36 DEBUG juju.worker.peergrouper controller nodes in state: []string{"0"}
machine-0: 14:20:36 DEBUG juju.worker.dependency "log-sender" manifold worker started at 2020-03-20 19:20:36.866169651 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-address-updater" manifold worker started at 2020-03-20 19:20:36.86619873 +0000 UTC
machine-0: 14:20:36 INFO juju.worker.logger logger worker started
machine-0: 14:20:36 DEBUG juju.worker.dependency "machine-action-runner" manifold worker started at 2020-03-20 19:20:36.867652053 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "unit-agent-deployer" manifold worker started at 2020-03-20 19:20:36.867680962 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "proxy-config-updater" manifold worker started at 2020-03-20 19:20:36.867704041 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "host-key-reporter" manifold worker started at 2020-03-20 19:20:36.868099599 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "reboot-executor" manifold worker started at 2020-03-20 19:20:36.868120138 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":24,"type":"MigrationStatusWatcher","version":1,"id":"5","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":25,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":26,"type":"Provisioner","version":10,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":27,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":28,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":29,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":30,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":31,"type":"StorageProvisioner","version":4,"request":"WatchBlockDevices","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":32,"type":"KeyUpdater","version":1,"request":"AuthorisedKeys","params":"'params redacted'"}
machine-0: 14:20:36 INFO juju.worker.diskmanager block devices changed: []storage.BlockDevice{storage.BlockDevice{DeviceName:"loop0", DeviceLinks:[]string(nil), Label:"", UUID:"", HardwareId:"", WWN:"", BusAddress:"", Size:0x5b, FilesystemType:"squashfs", InUse:true, MountPoint:"/snap/core/8689", SerialId:""}, storage.BlockDevice{DeviceName:"loop1", DeviceLinks:[]string(nil), Label:"", UUID:"", HardwareId:"", WWN:"", BusAddress:"", Size:0x11, FilesystemType:"squashfs", InUse:true, MountPoint:"/snap/amazon-ssm-agent/1566", SerialId:""}, storage.BlockDevice{DeviceName:"nvme0n1", DeviceLinks:[]string{"/dev/disk/by-id/nvme-Amazon_Elastic_Block_Store_vol02df4f49a898a4ac7", "/dev/disk/by-id/nvme-nvme.1d0f-766f6c3032646634663439613839386134616337-416d617a6f6e20456c617374696320426c6f636b2053746f7265-00000001", "/dev/disk/by-path/pci-0000:00:04.0-nvme-1"}, Label:"", UUID:"", HardwareId:"", WWN:"nvme.1d0f-766f6c3032646634663439613839386134616337-416d617a6f6e20456c617374696320426c6f636b2053746f7265-00000001", BusAddress:"", Size:0x8000, FilesystemType:"", InUse:true, MountPoint:"", SerialId:"Amazon Elastic Block Store_vol02df4f49a898a4ac7"}, storage.BlockDevice{DeviceName:"nvme0n1p1", DeviceLinks:[]string{"/dev/disk/by-id/nvme-Amazon_Elastic_Block_Store_vol02df4f49a898a4ac7-part1", "/dev/disk/by-id/nvme-nvme.1d0f-766f6c3032646634663439613839386134616337-416d617a6f6e20456c617374696320426c6f636b2053746f7265-00000001-part1", "/dev/disk/by-label/cloudimg-rootfs", "/dev/disk/by-partuuid/71d4cbcb-01", "/dev/disk/by-path/pci-0000:00:04.0-nvme-1-part1", "/dev/disk/by-uuid/2284a005-9684-4e64-b9bb-8759365e8d47"}, Label:"cloudimg-rootfs", UUID:"2284a005-9684-4e64-b9bb-8759365e8d47", HardwareId:"", WWN:"nvme.1d0f-766f6c3032646634663439613839386134616337-416d617a6f6e20456c617374696320426c6f636b2053746f7265-00000001", BusAddress:"", Size:0x7ffe, FilesystemType:"ext4", InUse:true, MountPoint:"/", SerialId:"Amazon Elastic Block Store_vol02df4f49a898a4ac7"}}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":33,"type":"UpgradeSeries","version":1,"request":"WatchUpgradeSeriesNotifications","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":34,"type":"Machiner","version":2,"request":"WatchAPIHostPorts","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":35,"type":"MachineActions","version":1,"request":"RunningActions","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":36,"type":"Deployer","version":1,"request":"WatchUnits","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":37,"type":"ProxyUpdater","version":2,"request":"ProxyConfig","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":38,"type":"HostKeyReporter","version":1,"request":"ReportKeys","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":39,"type":"Reboot","version":2,"request":"WatchForRebootEvent","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":40,"type":"Logger","version":1,"request":"LoggingConfig","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":41,"type":"FanConfigurer","version":1,"request":"FanConfig","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":42,"type":"DiskManager","version":2,"request":"SetMachineBlockDevices","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.worker.peergrouper found new controller "0"
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 4.289501ms {"request-id":25,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:36 DEBUG juju.worker.dependency "tools-version-checker" manifold worker started at 2020-03-20 19:20:36.889095807 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.peergrouper controller "0" not ready: pending
machine-0: 14:20:36 DEBUG juju.apiserver [3] API connection from 127.0.0.1:44690
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":43,"type":"AgentTools","version":1,"request":"UpdateToolsAvailable","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.api successfully dialed "wss://localhost:17070/model/939f511d-617c-4e70-87fd-61418f460257/api"
machine-0: 14:20:36 INFO juju.api connection established to "wss://localhost:17070/model/939f511d-617c-4e70-87fd-61418f460257/api"
machine-0: 14:20:36 DEBUG juju.apiserver <- [3]  {"request-id":1,"type":"Admin","version":3,"request":"Login","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.provider.ec2 opening model "controller"
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 14.225398ms {"request-id":30,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 14.375751ms {"request-id":29,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 14.488839ms {"request-id":28,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 14.614375ms {"request-id":27,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:36 DEBUG juju.apiserver [2] API connection from 127.0.0.1:44688
machine-0: 14:20:36 DEBUG juju.worker.dependency "ssh-identity-writer" manifold worker started at 2020-03-20 19:20:36.900846264 +0000 UTC
machine-0: 14:20:36 WARNING juju.cmd.jujud determining kvm support: INFO: Your CPU does not support KVM extensions
KVM acceleration can NOT be used
: exit status 1
no kvm containers possible
machine-0: 14:20:36 DEBUG juju.worker.dependency "mgo-txn-resumer" manifold worker started at 2020-03-20 19:20:36.907714031 +0000 UTC
machine-0: 14:20:36 INFO juju.agent writing system identity file
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 26.815249ms {"request-id":26,"response":"'body redacted'"} Provisioner[""].Life
machine-0: 14:20:36 DEBUG juju.worker.dependency "ssh-identity-writer" manifold worker completed successfully
machine-0: 14:20:36 DEBUG juju.api successfully dialed "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:36 DEBUG juju.apiserver model login: machine-0 for 939f511d-617c-4e70-87fd-61418f460257
machine-0: 14:20:36 INFO juju.api connection established to "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:36 DEBUG juju.apiserver <- [2]  {"request-id":1,"type":"Admin","version":3,"request":"Login","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [3]  20.642649ms {"request-id":1,"response":"'body redacted'"} Admin[""].Login
machine-0: 14:20:36 INFO juju.apiserver.connection agent login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:36 DEBUG juju.apiserver model login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-caller" manifold worker started at 2020-03-20 19:20:36.914678145 +0000 UTC
machine-0: 14:20:36 DEBUG juju.provider.ec2 opening model "controller"
machine-0: 14:20:36 DEBUG juju.environs.tools finding agent binaries in stream: "released"
machine-0: 14:20:36 DEBUG juju.environs.tools reading agent binaries with major.minor version 2.8
machine-0: 14:20:36 DEBUG juju.environs.tools trying datasource "keystone catalog"
machine-0: 14:20:36 DEBUG juju.apiserver -> [2]  6.206898ms {"request-id":1,"response":"'body redacted'"} Admin[""].Login
controller-0: 14:20:36 INFO juju.worker.apicaller [4b38a0] "machine-0" successfully connected to "localhost:17070"
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-caller" manifold worker started at 2020-03-20 19:20:36.919157349 +0000 UTC
machine-0: 14:20:36 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":44,"type":"Agent","version":2,"request":"ControllerConfig","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 45.643977ms {"request-id":34,"response":"'body redacted'"} Machiner[""].WatchAPIHostPorts
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":45,"type":"Provisioner","version":10,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":46,"type":"Resumer","version":2,"request":"ResumeTransactions","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":47,"type":"Provisioner","version":10,"request":"SupportedContainers","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":2,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":3,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":2,"type":"Singular","version":2,"request":"Claim","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":4,"type":"Singular","version":2,"request":"Claim","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":3,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":4,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":5,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":48,"type":"Machiner","version":2,"request":"APIHostPorts","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":49,"type":"NotifyWatcher","version":1,"id":"6","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [2] machine-0 3.816705ms {"request-id":3,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:36 DEBUG juju.apiserver -> [2] machine-0 4.350109ms {"request-id":2,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:36 DEBUG juju.worker.dependency "not-alive-flag" manifold worker started at 2020-03-20 19:20:36.939419761 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "not-dead-flag" manifold worker started at 2020-03-20 19:20:36.939477729 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 3.636892ms {"request-id":5,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 5.069275ms {"request-id":3,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:36 DEBUG juju.worker.dependency "not-dead-flag" manifold worker started at 2020-03-20 19:20:36.942964865 +0000 UTC
machine-0: 14:20:36 DEBUG juju.worker.dependency "not-alive-flag" manifold worker started at 2020-03-20 19:20:36.946834829 +0000 UTC
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":6,"type":"LifeFlag","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":7,"type":"LifeFlag","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 15.526875ms {"request-id":4,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:36 DEBUG juju.provider.ec2 opening model "controller"
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":8,"type":"CredentialValidator","version":2,"request":"WatchModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":5,"type":"LifeFlag","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":6,"type":"LifeFlag","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":7,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [2] machine-0 2.551417ms {"request-id":7,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:36 DEBUG juju.provider.ec2 opening model "controller"
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 11.047161ms {"request-id":8,"response":"'body redacted'"} CredentialValidator[""].WatchModelCredential
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 16.849862ms {"request-id":7,"response":"'body redacted'"} LifeFlag[""].Watch
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 17.592388ms {"request-id":6,"response":"'body redacted'"} LifeFlag[""].Watch
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 35.447357ms {"request-id":46,"response":"'body redacted'"} Resumer[""].ResumeTransactions
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 35.38957ms {"request-id":47,"response":"'body redacted'"} Provisioner[""].SupportedContainers
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 35.727388ms {"request-id":45,"response":"'body redacted'"} Provisioner[""].Life
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 38.520878ms {"request-id":44,"response":"'body redacted'"} Agent[""].ControllerConfig
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 85.443384ms {"request-id":31,"response":"'body redacted'"} StorageProvisioner[""].WatchBlockDevices
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 34.504059ms {"request-id":48,"response":"'body redacted'"} Machiner[""].APIHostPorts
machine-0: 14:20:36 DEBUG juju.worker.dependency "broker-tracker" manifold worker stopped: no container types determined
machine-0: 14:20:36 ERROR juju.worker.dependency "broker-tracker" manifold worker returned unexpected error: no container types determined
machine-0: 14:20:36 DEBUG juju.worker.dependency stack trace:
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/containerbroker/broker.go:109: no container types determined
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/containerbroker/manifold.go:86: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/fortress/occupy.go:63: 
/build/juju/parts/juju/go/src/github.com/juju/juju/cmd/jujud/agent/engine/housing.go:93: 
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":9,"type":"CredentialValidator","version":2,"request":"WatchCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":10,"type":"NotifyWatcher","version":1,"id":"1","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":11,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":12,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":13,"type":"NotifyWatcher","version":1,"id":"3","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [3] machine-0 {"request-id":14,"type":"NotifyWatcher","version":1,"id":"2","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":50,"type":"StorageProvisioner","version":4,"request":"WatchVolumeAttachmentPlans","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":51,"type":"Provisioner","version":10,"request":"SetSupportedContainers","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":52,"type":"Agent","version":2,"request":"StateServingInfo","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":53,"type":"NotifyWatcher","version":1,"id":"7","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [2] machine-0 19.995171ms {"request-id":5,"response":"'body redacted'"} LifeFlag[""].Watch
machine-0: 14:20:36 DEBUG juju.apiserver -> [2] machine-0 19.611772ms {"request-id":6,"response":"'body redacted'"} LifeFlag[""].Watch
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 3.421019ms {"request-id":12,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 3.721319ms {"request-id":11,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 92.502684ms {"request-id":35,"response":"'body redacted'"} MachineActions[""].RunningActions
machine-0: 14:20:36 DEBUG juju.network no lxc bridge addresses to filter for machine
machine-0: 14:20:36 DEBUG juju.network cannot get "lxdbr0" addresses: route ip+net: no such network interface (ignoring)
machine-0: 14:20:36 DEBUG juju.network cannot get "virbr0" addresses: route ip+net: no such network interface (ignoring)
machine-0: 14:20:36 DEBUG juju.network including address public:54.190.155.89 for machine
machine-0: 14:20:36 DEBUG juju.network including address local-cloud:172.31.38.92 for machine
machine-0: 14:20:36 DEBUG juju.network addresses after filtering: [public:54.190.155.89 local-cloud:172.31.38.92]
machine-0: 14:20:36 DEBUG juju.worker.apiaddressupdater updating API hostPorts to [[54.190.155.89:17070 172.31.38.92:17070]]
machine-0: 14:20:36 DEBUG juju.agent API server address details [["54.190.155.89:17070" "172.31.38.92:17070"]] written to agent config as ["172.31.38.92:17070" "54.190.155.89:17070"]
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":8,"type":"CredentialValidator","version":2,"request":"WatchModelCredential","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":9,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-config-watcher" manifold worker stopped: restart immediately
machine-0: 14:20:36 DEBUG juju.worker.apiconfigwatcher API addresses changed in agent config
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-config-watcher" manifold worker stopped: restart immediately
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-config-watcher" manifold worker stopped: restart immediately
machine-0: 14:20:36 DEBUG juju.api RPC connection died
machine-0: 14:20:36 INFO juju.worker.authenticationworker reading Juju ssh keys for "machine-0": connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "is-primary-controller-flag" manifold worker stopped: connection is shut down
machine-0: 14:20:36 ERROR juju.worker.logger connection is shut down
machine-0: 14:20:36 ERROR juju.worker.dependency "is-primary-controller-flag" manifold worker returned unexpected error: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency stack trace:
/build/juju/parts/juju/go/src/github.com/juju/juju/rpc/client.go:14: connection is shut down
/build/juju/parts/juju/go/src/github.com/juju/juju/rpc/client.go:178: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/apiclient.go:1200: 
/build/juju/parts/juju/go/src/github.com/juju/juju/api/singular/api.go:68: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/singular/flag.go:141: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/singular/flag.go:63: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/singular/shim.go:31: 
/build/juju/parts/juju/go/src/github.com/juju/juju/worker/singular/manifold.go:74: 
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-caller" manifold worker completed successfully
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrade-series" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "unit-agent-deployer" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "proxy-config-updater" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "upgrader" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.apiserver <- [1] machine-0 {"request-id":54,"type":"MachineActions","version":1,"request":"WatchActionNotifications","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.worker.dependency "fan-configurer" manifold worker stopped: creating fanconfigurer orchestrator: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "disk-manager" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "reboot-executor" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "migration-inactive-flag" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "tools-version-checker" manifold worker stopped: cannot update agent binaries information: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "unconverted-api-workers" manifold worker stopped: setting up container support: setting supported containers for machine-0: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "valid-credential-flag" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "host-key-reporter" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "agent-config-updater" manifold worker stopped: getting state serving info: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "machine-action-runner" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "storage-provisioner" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "api-address-updater" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "migration-minion" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "ssh-authkeys-updater" manifold worker stopped: reading Juju ssh keys for "machine-0": connection is shut down
machine-0: 14:20:36 DEBUG juju.worker.dependency "log-sender" manifold worker completed successfully
machine-0: 14:20:36 INFO juju.worker.logger logger worker stopped
machine-0: 14:20:36 DEBUG juju.worker.dependency "mgo-txn-resumer" manifold worker completed successfully
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 10.673313ms {"request-id":53,"error":"watcher has been stopped","error-code":"stopped","response":"'body redacted'"} NotifyWatcher["7"].Next
machine-0: 14:20:36 DEBUG juju.worker.dependency "logging-config-updater" manifold worker stopped: connection is shut down
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 49.717315ms {"request-id":49,"error":"watcher has been stopped","error-code":"stopped","response":"'body redacted'"} NotifyWatcher["6"].Next
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 104.928651ms {"request-id":24,"error":"watcher has been stopped","error-code":"stopped","response":"'body redacted'"} MigrationStatusWatcher["5"].Next
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 198.902877ms {"request-id":20,"error":"watcher has been stopped","error-code":"stopped","response":"'body redacted'"} NotifyWatcher["4"].Next
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 201.779412ms {"request-id":17,"error":"watcher has been stopped","error-code":"stopped","response":"'body redacted'"} NotifyWatcher["3"].Next
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 210.226799ms {"request-id":15,"error":"watcher has been stopped","error-code":"stopped","response":"'body redacted'"} NotifyWatcher["2"].Next
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 213.011788ms {"request-id":13,"error":"watcher has been stopped","error-code":"stopped","response":"'body redacted'"} NotifyWatcher["1"].Next
machine-0: 14:20:36 DEBUG juju.apiserver.logsink logsink unexpected close error: websocket: close 1006 (abnormal closure): unexpected EOF
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":10,"type":"LifeFlag","version":1,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 104.331749ms {"request-id":40,"response":"'body redacted'"} Logger[""].LoggingConfig
machine-0: 14:20:36 DEBUG juju.apiserver -> [3] machine-0 16.894691ms {"request-id":9,"response":"'body redacted'"} CredentialValidator[""].WatchCredential
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 105.676796ms {"request-id":33,"response":"'body redacted'"} UpgradeSeries[""].WatchUpgradeSeriesNotifications
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 113.161823ms {"request-id":37,"response":"'body redacted'"} ProxyUpdater[""].ProxyConfig
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 22.356494ms {"request-id":50,"response":"'body redacted'"} StorageProvisioner[""].WatchVolumeAttachmentPlans
machine-0: 14:20:36 DEBUG juju.apiserver -> [2] machine-0 16.490914ms {"request-id":9,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:36 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 113.595669ms {"request-id":39,"response":"'body redacted'"} Reboot[""].WatchForRebootEvent
machine-0: 14:20:36 DEBUG juju.apiserver -> [1] machine-0 23.073651ms {"request-id":52,"response":"'body redacted'"} Agent[""].StateServingInfo
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":11,"type":"NotifyWatcher","version":1,"id":"2","request":"Next","params":"'params redacted'"}
machine-0: 14:20:36 DEBUG juju.apiserver <- [2] machine-0 {"request-id":12,"type":"NotifyWatcher","version":1,"id":"1","request":"Next","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.worker.dependency "valid-credential-flag" manifold worker started at 2020-03-20 19:20:37.000156447 +0000 UTC
machine-0: 14:20:37 DEBUG juju.apiserver -> [2] machine-0 10.537767ms {"request-id":10,"response":"'body redacted'"} LifeFlag[""].Life
machine-0: 14:20:37 DEBUG juju.apiserver <- [3] machine-0 {"request-id":15,"type":"NotifyWatcher","version":1,"id":"4","request":"Next","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [3] machine-0 {"request-id":16,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.worker.apicaller connecting with current password
machine-0: 14:20:37 DEBUG juju.api looked up localhost -> [127.0.0.1]
machine-0: 14:20:37 DEBUG juju.worker.dependency "api-config-watcher" manifold worker started at 2020-03-20 19:20:37.002098014 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "api-config-watcher" manifold worker started at 2020-03-20 19:20:37.002118823 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "api-config-watcher" manifold worker started at 2020-03-20 19:20:37.002368906 +0000 UTC
machine-0: 14:20:37 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:37 DEBUG juju.apiserver -> [1] machine-0 157.251809ms {"request-id":41,"response":"'body redacted'"} FanConfigurer[""].FanConfig
machine-0: 14:20:37 DEBUG juju.apiserver -> [1] machine-0 158.017255ms {"request-id":36,"response":"'body redacted'"} Deployer[""].WatchUnits
machine-0: 14:20:37 DEBUG juju.apiserver [4] API connection from 127.0.0.1:44704
machine-0: 14:20:37 DEBUG juju.api successfully dialed "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:37 INFO juju.api connection established to "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:37 DEBUG juju.apiserver -> [3] machine-0 47.578609ms {"request-id":16,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:37 DEBUG juju.apiserver -> [2] machine-0 66.98468ms {"request-id":8,"response":"'body redacted'"} CredentialValidator[""].WatchModelCredential
machine-0: 14:20:37 DEBUG juju.mongo dialled mongodb server at "127.0.0.1:37017"
machine-0: 14:20:37 DEBUG juju.apiserver <- [4]  {"request-id":1,"type":"Admin","version":3,"request":"Login","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.mongo dialled mongodb server at "172.31.38.92:37017"
machine-0: 14:20:37 DEBUG juju.apiserver <- [3] machine-0 {"request-id":17,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [2] machine-0 {"request-id":13,"type":"CredentialValidator","version":2,"request":"WatchCredential","params":"'params redacted'"}
machine-0: 14:20:37 INFO juju.apiserver.connection agent login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:37 DEBUG juju.apiserver model login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:37 DEBUG juju.apiserver <- [2] machine-0 {"request-id":14,"type":"NotifyWatcher","version":1,"id":"3","request":"Next","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [1] machine-0 96.065098ms {"request-id":54,"response":"'body redacted'"} MachineActions[""].WatchActionNotifications
machine-0: 14:20:37 DEBUG juju.apiserver -> [4]  30.884767ms {"request-id":1,"response":"'body redacted'"} Admin[""].Login
machine-0: 14:20:37 DEBUG juju.apiserver -> [2] machine-0 17.074408ms {"request-id":13,"response":"'body redacted'"} CredentialValidator[""].WatchCredential
machine-0: 14:20:37 DEBUG juju.worker.dependency "valid-credential-flag" manifold worker started at 2020-03-20 19:20:37.081372848 +0000 UTC
machine-0: 14:20:37 INFO juju.worker.apicaller [4b38a0] "machine-0" successfully connected to "localhost:17070"
machine-0: 14:20:37 DEBUG juju.apiserver -> [3] machine-0 19.158502ms {"request-id":17,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:37 DEBUG juju.apiserver <- [4] machine-0 {"request-id":2,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [2] machine-0 {"request-id":15,"type":"NotifyWatcher","version":1,"id":"4","request":"Next","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [2] machine-0 {"request-id":16,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [1] machine-0 201.633435ms {"request-id":32,"response":"'body redacted'"} KeyUpdater[""].AuthorisedKeys
machine-0: 14:20:37 DEBUG juju.apiserver -> [1] machine-0 109.977973ms {"request-id":51,"response":"'body redacted'"} Provisioner[""].SetSupportedContainers
machine-0: 14:20:37 DEBUG juju.apiserver -> [4] machine-0 2.752355ms {"request-id":2,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:37 DEBUG juju.apiserver -> [1] machine-0 203.210156ms {"request-id":38,"response":"'body redacted'"} HostKeyReporter[""].ReportKeys
machine-0: 14:20:37 DEBUG juju.apiserver -> [2] machine-0 3.740543ms {"request-id":16,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:37 DEBUG juju.apiserver <- [4] machine-0 {"request-id":3,"type":"Agent","version":2,"request":"SetPasswords","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [2] machine-0 {"request-id":17,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [2] machine-0 2.922419ms {"request-id":17,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:37 DEBUG juju.apiserver -> [1] machine-0 213.500406ms {"request-id":42,"response":"'body redacted'"} DiskManager[""].SetMachineBlockDevices
machine-0: 14:20:37 INFO juju.apiserver.common setting mongo password for "machine-0"
machine-0: 14:20:37 INFO juju.apiserver.common setting password for "machine-0"
machine-0: 14:20:37 DEBUG juju.apiserver -> [4] machine-0 31.964563ms {"request-id":3,"response":"'body redacted'"} Agent[""].SetPasswords
machine-0: 14:20:37 DEBUG juju.api RPC connection died
machine-0: 14:20:37 DEBUG juju.worker.dependency "api-caller" manifold worker completed successfully
machine-0: 14:20:37 DEBUG juju.rpc error closing codec: write tcp 127.0.0.1:17070->127.0.0.1:44704: write: broken pipe
machine-0: 14:20:37 INFO juju.apiserver.connection agent disconnected: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:37 DEBUG juju.apiserver [4] machine-0 API connection terminated after 76.008511ms
machine-0: 14:20:37 DEBUG juju.worker.apicaller connecting with current password
machine-0: 14:20:37 DEBUG juju.api looked up localhost -> [127.0.0.1]
machine-0: 14:20:37 DEBUG juju.apiserver [5] API connection from 127.0.0.1:44708
machine-0: 14:20:37 DEBUG juju.api successfully dialed "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:37 INFO juju.api connection established to "wss://localhost:17070/model/4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a/api"
machine-0: 14:20:37 DEBUG juju.apiserver <- [5]  {"request-id":1,"type":"Admin","version":3,"request":"Login","params":"'params redacted'"}
machine-0: 14:20:37 INFO juju.apiserver.connection agent login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:37 DEBUG juju.apiserver model login: machine-0 for 4b38a0ca-e97f-4dac-8fc8-1a6d7a0a192a
machine-0: 14:20:37 DEBUG juju.apiserver -> [5]  1.551062ms {"request-id":1,"response":"'body redacted'"} Admin[""].Login
machine-0: 14:20:37 INFO juju.worker.apicaller [4b38a0] "machine-0" successfully connected to "localhost:17070"
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":2,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 751.307µs {"request-id":2,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":3,"type":"Agent","version":2,"request":"SetPasswords","params":"'params redacted'"}
machine-0: 14:20:37 INFO juju.apiserver.common setting mongo password for "machine-0"
machine-0: 14:20:37 INFO juju.apiserver.common setting password for "machine-0"
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 46.817132ms {"request-id":3,"response":"'body redacted'"} Agent[""].SetPasswords
machine-0: 14:20:37 DEBUG juju.worker.dependency "api-caller" manifold worker started at 2020-03-20 19:20:37.200792196 +0000 UTC
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":4,"type":"Singular","version":2,"request":"Claim","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.worker.dependency "upgrader" manifold worker started at 2020-03-20 19:20:37.211470553 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "migration-minion" manifold worker started at 2020-03-20 19:20:37.211584389 +0000 UTC
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":5,"type":"Machiner","version":2,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":6,"type":"Upgrader","version":1,"request":"SetTools","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":7,"type":"MigrationMinion","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 829.094µs {"request-id":5,"response":"'body redacted'"} Machiner[""].Life
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 712.078µs {"request-id":7,"response":"'body redacted'"} MigrationMinion[""].Watch
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":8,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":9,"type":"MigrationStatusWatcher","version":1,"id":"1","request":"Next","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 634.221µs {"request-id":8,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:37 DEBUG juju.worker.dependency "upgrade-steps-runner" manifold worker started at 2020-03-20 19:20:37.214717692 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "upgrade-steps-runner" manifold worker completed successfully
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":10,"type":"MigrationFlag","version":1,"request":"Phase","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":11,"type":"CredentialValidator","version":2,"request":"ModelCredential","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 1.493514ms {"request-id":10,"response":"'body redacted'"} MigrationFlag[""].Phase
machine-0: 14:20:37 DEBUG juju.worker.dependency "migration-inactive-flag" manifold worker started at 2020-03-20 19:20:37.21767835 +0000 UTC
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 1.565011ms {"request-id":11,"response":"'body redacted'"} CredentialValidator[""].ModelCredential
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":12,"type":"MigrationFlag","version":1,"request":"Watch","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":13,"type":"CredentialValidator","version":2,"request":"WatchModelCredential","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 9.723087ms {"request-id":9,"response":"'body redacted'"} MigrationStatusWatcher["1"].Next
machine-0: 14:20:37 INFO juju.worker.migrationminion migration phase is now: NONE
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":14,"type":"MigrationStatusWatcher","version":1,"id":"1","request":"Next","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 12.835659ms {"request-id":6,"response":"'body redacted'"} Upgrader[""].SetTools
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":15,"type":"Upgrader","version":1,"request":"WatchAPIVersion","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":16,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.worker.dependency "upgrade-series" manifold worker started at 2020-03-20 19:20:37.227680257 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "host-key-reporter" manifold worker started at 2020-03-20 19:20:37.227801754 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "unit-agent-deployer" manifold worker started at 2020-03-20 19:20:37.227858162 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "machine-action-runner" manifold worker started at 2020-03-20 19:20:37.228033056 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "disk-manager" manifold worker started at 2020-03-20 19:20:37.22858618 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "reboot-executor" manifold worker started at 2020-03-20 19:20:37.228645028 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "proxy-config-updater" manifold worker started at 2020-03-20 19:20:37.228702595 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.logger initial log config: "<root>=DEBUG"
machine-0: 14:20:37 DEBUG juju.worker.dependency "logging-config-updater" manifold worker started at 2020-03-20 19:20:37.228821313 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "api-address-updater" manifold worker started at 2020-03-20 19:20:37.229231579 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.dependency "log-sender" manifold worker started at 2020-03-20 19:20:37.229251928 +0000 UTC
machine-0: 14:20:37 INFO juju.worker.logger logger worker started
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":17,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 18.800073ms {"request-id":16,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":18,"type":"UpgradeSeries","version":1,"request":"WatchUpgradeSeriesNotifications","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":19,"type":"HostKeyReporter","version":1,"request":"ReportKeys","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":20,"type":"Deployer","version":1,"request":"WatchUnits","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":21,"type":"MachineActions","version":1,"request":"RunningActions","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":22,"type":"Provisioner","version":10,"request":"Life","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":23,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":24,"type":"Agent","version":2,"request":"GetEntities","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":25,"type":"Reboot","version":2,"request":"WatchForRebootEvent","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":26,"type":"ProxyUpdater","version":2,"request":"ProxyConfig","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":27,"type":"Machiner","version":2,"request":"WatchAPIHostPorts","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.apiserver <- [5] machine-0 {"request-id":28,"type":"Logger","version":1,"request":"LoggingConfig","params":"'params redacted'"}
machine-0: 14:20:37 DEBUG juju.worker.dependency "tools-version-checker" manifold worker started at 2020-03-20 19:20:37.251950562 +0000 UTC
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 6.378761ms {"request-id":17,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 4.050724ms {"request-id":28,"response":"'body redacted'"} Logger[""].LoggingConfig
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 15.158918ms {"request-id":27,"response":"'body redacted'"} Machiner[""].WatchAPIHostPorts
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 19.721126ms {"request-id":19,"response":"'body redacted'"} HostKeyReporter[""].ReportKeys
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 17.338129ms {"request-id":23,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:37 DEBUG juju.worker.dependency "mgo-txn-resumer" manifold worker started at 2020-03-20 19:20:37.266494748 +0000 UTC
machine-0: 14:20:37 DEBUG juju.worker.logger reconfiguring logging from "<root>=DEBUG" to "<root>=WARNING;unit=DEBUG"
machine-0: 14:20:37 DEBUG juju.apiserver -> [5] machine-0 17.415018ms {"request-id":24,"response":"'body redacted'"} Agent[""].GetEntities
machine-0: 14:20:37 WARNING juju.cmd.jujud determining kvm support: INFO: Your CPU does not support KVM extensions
KVM acceleration can NOT be used
: exit status 1
no kvm containers possible
machine-0: 14:20:42 WARNING juju.cmd.jujud determining kvm support: INFO: Your CPU does not support KVM extensions
KVM acceleration can NOT be used
: exit status 1
no kvm containers possible
controller-0: 14:20:46 INFO juju.worker.logforwarder config change - log forwarding not enabled
controller-0: 14:20:47 INFO juju.worker.machineundertaker setting up machine undertaker
controller-0: 14:20:47 INFO juju.worker.logger logger worker started
machine-0: 14:50:04 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:50:09 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:50:14 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:50:20 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:50:27 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:50:37 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:50:47 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:51:01 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:51:17 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:51:36 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:51:58 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:52:27 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:52:57 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:53:39 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:54:22 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:55:21 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:56:25 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:57:44 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 14:59:23 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:01:23 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:03:21 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:05:33 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:07:41 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:09:50 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:11:49 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:13:44 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:15:51 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:17:39 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration
machine-0: 15:19:30 ERROR juju.worker.dependency "caas-operator-provisioner" manifold worker returned unexpected error: failed to generate operator config for "multus": password not found in configuration