upgrade-model failed after upgrade-controller to 2.7.6

[Adam Dyess]

$ juju --debug upgrade-model -m my_model --agent-version 2.7.6
15:21:17 INFO juju.cmd supercommand.go:83 running juju [2.7.6 gc go1.10.4]
15:21:17 DEBUG juju.cmd supercommand.go:84 args: []string{"/snap/juju/11454/bin/juju", "--debug", "-v", "upgrade-model", "-m", "openstack", "--agent-version", "2.7.6"}
15:21:17 INFO juju.juju api.go:67 connecting to API addresses: [172.18.247.106:17070 172.18.247.83:17070 172.18.247.174:17070]
15:21:17 DEBUG juju.api apiclient.go:1092 successfully dialed "wss://172.18.247.83:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
15:21:17 INFO juju.api apiclient.go:624 connection established to "wss://172.18.247.83:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
15:21:18 INFO juju.juju api.go:302 API endpoints changed from [172.18.247.83:17070 172.18.247.174:17070 172.18.247.106:17070] to [172.18.247.83:17070 172.18.247.106:17070 172.18.247.174:17070]
15:21:18 INFO juju.juju api.go:67 connecting to API addresses: [172.18.247.83:17070 172.18.247.106:17070 172.18.247.174:17070]
15:21:18 DEBUG juju.api apiclient.go:1092 successfully dialed "wss://172.18.247.83:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
15:21:18 INFO juju.api apiclient.go:624 connection established to "wss://172.18.247.83:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
15:21:18 INFO juju.juju api.go:67 connecting to API addresses: [172.18.247.83:17070 172.18.247.106:17070 172.18.247.174:17070]
15:21:18 DEBUG juju.api apiclient.go:1092 successfully dialed "wss://172.18.247.106:17070/api"
15:21:18 INFO juju.api apiclient.go:624 connection established to "wss://172.18.247.106:17070/api"
15:21:18 INFO juju.juju api.go:302 API endpoints changed from [172.18.247.106:17070 172.18.247.174:17070 172.18.247.83:17070] to [172.18.247.106:17070 172.18.247.83:17070 172.18.247.174:17070]
15:21:18 DEBUG juju.cmd.juju.commands upgrademodel.go:610 searching for "" agent binaries with major: 2
15:21:30 INFO cmd upgrademodel.go:500 available agent binaries:
    2.7.6
best version:
    2.7.6
15:23:01 DEBUG juju.api monitor.go:35 RPC connection died
15:23:01 DEBUG juju.api monitor.go:35 RPC connection died
15:23:01 DEBUG juju.api monitor.go:35 RPC connection died
ERROR cannot make API call to provider: unexpected: Get http://172.18.247.21/MAAS/api/2.0/machines/?agent_name=eafa14a6-708b-4b54-819a-62827e7cfc1d: EOF
15:23:01 DEBUG cmd supercommand.go:519 error stack:
cannot make API call to provider: unexpected: Get http://172.18.247.21/MAAS/api/2.0/machines/?agent_name=eafa14a6-708b-4b54-819a-62827e7cfc1d: EOF
/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:1187:

[Adam Dyess (addyess)]

juju is unable to complete a model upgrade after a controller upgrade.

I am able to issue commands to maas. but it seems juju is not. I did find this error in the juju audit.log

{"errors":{"conversation-id":"36092e7ce5a65b06","connection-id":"C5","request-id":3,"when":"2020-05-13T15:06:41Z","errors":[{"message":"cannot make API call to provider: unexpected: Get http://172.18.247.21/MAAS/api/2.0/machines/?agent_name=eafa14a6-708b-4b54-819a-62827e7cfc1d: EOF","code":""}]}}

but it seems this error is very similar to output to juju client

[Adam Dyess (addyess)]

I was able to issue this command in maas

maas admin machines read agent_name=eafa14a6-708b-4b54-819a-62827e7cfc1d > maas_agents.dat

and produce a file which has this uuid present in a number of fields in the resulting json
   juju-model-uuid

It seems to list all the machines associated with this juju-model... it does take a while for this command to execute though. Perhaps there's a timeout in the juju controller?

[Heather Lanigan (hmlanigan)]

@addyess, regarding #2, what machine did you run the maas command from? Where the client is? From one of the controller machines?

[Heather Lanigan (hmlanigan)]

Juju is failing in a basic check of the provider, maas, before allowing the upgrade-model to be done. The basic check is to get a list all machines from the provider.

[Adam Dyess (addyess)]

It doesn't see the controllers have trouble accessing basic maas API

$ juju run -a juju-controller "curl --head http://172.18.247.21/MAAS/"
- Stderr: " % Total % Received % Xferd Average Speed Time Time Time
    \ Current\n Dload Upload Total Spent Left
    \ Speed\n\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\n"
  Stdout: |+
    HTTP/1.1 302 FOUND
    Content-Type: text/html; charset=utf-8
    Location: http://172.18.247.21/MAAS/accounts/login/?next=%2FMAAS%2F
    X-Frame-Options: SAMEORIGIN
    Vary: Cookie
    Server: TwistedWeb/16.0.0
    Date: Wed, 13 May 2020 17:38:02 GMT

  UnitId: juju-controller/0
- Stderr: " % Total % Received % Xferd Average Speed Time Time Time
    \ Current\n Dload Upload Total Spent Left
    \ Speed\n\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\n"
  Stdout: |+
    HTTP/1.1 302 FOUND
    Date: Wed, 13 May 2020 17:38:02 GMT
    Server: TwistedWeb/16.0.0
    Vary: Cookie
    X-Frame-Options: SAMEORIGIN
    Location: http://172.18.247.21/MAAS/accounts/login/?next=%2FMAAS%2F
    Content-Type: text/html; charset=utf-8

  UnitId: juju-controller/1
- Stderr: " % Total % Received % Xferd Average Speed Time Time Time
    \ Current\n Dload Upload Total Spent Left
    \ Speed\n\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\r 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:--
    \ 0\n"
  Stdout: |+
    HTTP/1.1 302 FOUND
    Content-Type: text/html; charset=utf-8
    Date: Wed, 13 May 2020 17:38:02 GMT
    Vary: Cookie
    Location: http://172.18.247.21/MAAS/accounts/login/?next=%2FMAAS%2F
    Server: TwistedWeb/16.0.0
    X-Frame-Options: SAMEORIGIN

  UnitId: juju-controller/2

[Tim Penhey (thumper)]

Where did this end up? Did retrying later fix the problem?

[Adam Dyess (addyess)]

This no longer appears to be an active issue on the cloud. I saw
$ juju model-config agent-version
2.7.6
$ juju --debug -v upgrade-model -m openstack --agent-version 2.7.6
13:28:36 INFO juju.cmd supercommand.go:83 running juju [2.7.8 gc go1.10.4]
13:28:36 DEBUG juju.cmd supercommand.go:84 args: []string{"/snap/juju/13563/bin/juju", "--debug", "-v", "upgrade-model", "-m", "openstack", "--agent-version", "2.7.6"}
13:28:36 INFO juju.juju api.go:67 connecting to API addresses: [10.10.10.1:17070 10.10.10.2:17070 10.10.10.3:17070]
13:28:36 DEBUG juju.api apiclient.go:1092 successfully dialed "wss://10.10.10.1:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
13:28:36 INFO juju.api apiclient.go:624 connection established to "wss://10.10.10.1:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
13:28:36 INFO juju.juju api.go:67 connecting to API addresses: [10.10.10.1:17070 10.10.10.2:17070 10.10.10.3:17070]
13:28:36 DEBUG juju.api apiclient.go:1092 successfully dialed "wss://10.10.10.1:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
13:28:36 INFO juju.api apiclient.go:624 connection established to "wss://10.10.10.1:17070/model/eafa14a6-708b-4b54-819a-62827e7cfc1d/api"
13:28:36 INFO juju.juju api.go:67 connecting to API addresses: [10.10.10.1:17070 10.10.10.2:17070 10.10.10.3:17070]
13:28:36 DEBUG juju.api apiclient.go:1092 successfully dialed "wss://10.10.10.1:17070/api"
13:28:36 INFO juju.api apiclient.go:624 connection established to "wss://10.10.10.1:17070/api"
13:28:36 INFO cmd upgrademodel.go:406 no upgrades available
13:28:36 DEBUG juju.api monitor.go:35 RPC connection died
13:28:36 DEBUG juju.api monitor.go:35 RPC connection died
13:28:36 DEBUG juju.api monitor.go:35 RPC connection died
13:28:36 INFO cmd supercommand.go:525 command finished

Looks like either someone else worked around the issue or it just went away

[Michael Skalka (mskalka)]

Given the above comment I am removing the crit subscription.

[Launchpad Janitor (janitor)]

[Expired for juju because there has been no activity for 60 days.]