update-status ERROR connection is shut down during upgrade from 2.7 to 2.8

[Ryan Beisner]

During a 2.7 -> 2.8 controller upgrade (`juju upgrade-juju --model controller`), hooks may fail. In this case, the update-status hook of designate/0 failed. Retrying resolved it (`juju resolved designate/0`).

Note that in this scenario, only the controller was upgraded to 2.8. The user's model ("zaza-589c39c6cb60") remains on 2.7.8.

I used the https://opendev.org/openstack/charm-designate gate test as a small bundle to reproduce this. ie. tox -e build, then cd into the built charm dir, then tox -e func-smoke. That deploys the following small bundle:

https://opendev.org/openstack/charm-designate/src/branch/master/src/tests/bundles/bionic-train.yaml

...

ubuntu@beisner-bastion:~/git/charm-designate/build/builds/designate$ tox -e func-smoke

(deployed & tested ok)

ubuntu@beisner-bastion:~/temp/lp1890465$ juju controllers
Use --refresh option with this command to see the latest information.

Controller Model User Access Cloud/Region Models Nodes HA Version
beisner-serverstack* zaza-589c39c6cb60 admin superuser serverstack/serverstack 6 1 none 2.7.8

ubuntu@beisner-bastion:~/temp/lp1890465$ juju models
Controller: beisner-serverstack

Model Cloud/Region Type Status Machines Cores Units Access Last connection
beisner serverstack/serverstack openstack available 0 - - admin 22 minutes ago
controller serverstack/serverstack openstack available 1 4 - admin just now
default serverstack/serverstack openstack available 0 - - admin 22 minutes ago
leftbrain serverstack/serverstack openstack available 0 - - admin never connected
rightbrain serverstack/serverstack openstack available 0 - - admin 19 minutes ago
zaza-589c39c6cb60* serverstack/serverstack openstack available 7 10 7 admin just now

ubuntu@beisner-bastion:~/temp/lp1890465$ juju status
Model Controller Cloud/Region Version SLA Timestamp
zaza-589c39c6cb60 beisner-serverstack serverstack/serverstack 2.7.8 unsupported 20:06:15Z

App Version Status Scale Charm Store Rev OS Notes
designate 9.0.1 active 1 designate local 0 ubuntu
designate-bind 9.11.3+dfsg active 1 designate-bind jujucharms 29 ubuntu
keystone 16.0.1 active 1 keystone jujucharms 316 ubuntu
memcached active 1 memcached jujucharms 10 ubuntu
neutron-api 15.1.0 active 1 neutron-api jujucharms 286 ubuntu
percona-cluster 5.7.20 active 1 percona-cluster jujucharms 290 ubuntu
rabbitmq-server 3.6.10 active 1 rabbitmq-server jujucharms 272 ubuntu

Unit Workload Agent Machine Public address Ports Message
designate-bind/0* active idle 3 10.5.0.20 Unit is ready
designate/0* active idle 5 10.5.0.12 9001/tcp Unit is ready
keystone/0* active idle 1 10.5.0.17 5000/tcp Unit is ready
memcached/0* active idle 4 10.5.0.7 11211/tcp Unit is ready
neutron-api/0* active idle 6 10.5.0.11 9696/tcp Unit is ready
percona-cluster/0* active idle 0 10.5.0.8 3306/tcp Unit is ready
rabbitmq-server/0* active idle 2 10.5.0.3 5672/tcp Unit is ready

Machine State DNS Inst id Series AZ Message
0 started 10.5.0.8 41040305-18e2-463a-bd09-b100085dd6f4 bionic nova ACTIVE
1 started 10.5.0.17 290536b0-0640-4e61-9c00-32f88d4c1d28 bionic nova ACTIVE
2 started 10.5.0.3 95cb6f6b-9603-4a1c-9707-536636f28986 bionic nova ACTIVE
3 started 10.5.0.20 66947fdf-2148-41a3-9023-b9a514384c79 bionic nova ACTIVE
4 started 10.5.0.7 af35a79a-bfde-48c1-aee7-d7167d0bbcb7 bionic nova ACTIVE
5 started 10.5.0.12 404b790a-e692-45a4-bd9e-a952b0b4e576 bionic nova ACTIVE
6 started 10.5.0.11 98e8156f-c80e-4ae1-9422-8a1f3f7aa72c bionic nova ACTIVE

ubuntu@beisner-bastion:~/git/charm-designate/build/builds/designate$ sudo snap refresh juju --channel 2.8/stable

ubuntu@beisner-bastion:~/temp/lp1890465$ snap list
Name Version Rev Tracking Publisher Notes
charm 2.3.1 212 latest/stable canonical✓ -
core 16-2.45.3.1 9804 latest/stable canonical✓ core
core18 20200724 1885 latest/stable canonical✓ base
juju 2.8.1 13324 2.8/stable canonical✓ classic
juju-crashdump 1.0.2+git69.048c306 193 latest/stable jason-hobbs classic

ubuntu@beisner-bastion:~/git/charm-designate/build/builds/designate$ juju upgrade-juju --model controller
best version:
    2.8.2
started upgrade to 2.8.2

#### Error state after controller upgrade:
ubuntu@beisner-bastion:~/temp/lp1890465$ juju status
Model Controller Cloud/Region Version SLA Timestamp
zaza-589c39c6cb60 beisner-serverstack serverstack/serverstack 2.7.8 unsupported 20:15:39Z

App Version Status Scale Charm Store Rev OS Notes
designate 9.0.1 error 1 designate local 0 ubuntu
designate-bind 9.11.3+dfsg active 1 designate-bind jujucharms 29 ubuntu
keystone 16.0.1 active 1 keystone jujucharms 316 ubuntu
memcached active 1 memcached jujucharms 10 ubuntu
neutron-api 15.1.0 active 1 neutron-api jujucharms 286 ubuntu
percona-cluster 5.7.20 active 1 percona-cluster jujucharms 290 ubuntu
rabbitmq-server 3.6.10 active 1 rabbitmq-server jujucharms 272 ubuntu

Unit Workload Agent Machine Public address Ports Message
designate-bind/0* active idle 3 10.5.0.20 Unit is ready
designate/0* error idle 5 10.5.0.12 9001/tcp hook failed: "update-status"
keystone/0* active idle 1 10.5.0.17 5000/tcp Unit is ready
memcached/0* active idle 4 10.5.0.7 11211/tcp Unit is ready
neutron-api/0* active idle 6 10.5.0.11 9696/tcp Unit is ready
percona-cluster/0* active idle 0 10.5.0.8 3306/tcp Unit is ready
rabbitmq-server/0* active idle 2 10.5.0.3 5672/tcp Unit is ready

Machine State DNS Inst id Series AZ Message
0 started 10.5.0.8 41040305-18e2-463a-bd09-b100085dd6f4 bionic nova ACTIVE
1 started 10.5.0.17 290536b0-0640-4e61-9c00-32f88d4c1d28 bionic nova ACTIVE
2 started 10.5.0.3 95cb6f6b-9603-4a1c-9707-536636f28986 bionic nova ACTIVE
3 started 10.5.0.20 66947fdf-2148-41a3-9023-b9a514384c79 bionic nova ACTIVE
4 started 10.5.0.7 af35a79a-bfde-48c1-aee7-d7167d0bbcb7 bionic nova ACTIVE
5 started 10.5.0.12 404b790a-e692-45a4-bd9e-a952b0b4e576 bionic nova ACTIVE
6 started 10.5.0.11 98e8156f-c80e-4ae1-9422-8a1f3f7aa72c bionic nova ACTIVE

#### Unit log error:
2020-08-11 20:08:37 DEBUG update-status
2020-08-11 20:08:37 INFO juju-log Invoking reactive handler: reactive/designate_handlers.py:214:expose_endpoint
2020-08-11 20:08:38 INFO juju-log Invoking reactive handler: reactive/designate_handlers.py:220:run_assess_status_on_every_hook
2020-08-11 20:08:38 INFO juju-log Invoking reactive handler: hooks/relations/tls-certificates/requires.py:109:broken:certificates
2020-08-11 20:08:38 DEBUG juju-log Running _assess_status()
2020-08-11 20:08:39 ERROR juju.worker.dependency engine.go:671 "api-caller" manifold worker returned unexpected error: api connection broken unexpectedly
2020-08-11 20:08:39 DEBUG update-status ERROR connection is shut down
2020-08-11 20:08:39 DEBUG update-status ERROR connection is shut down
2020-08-11 20:08:39 DEBUG update-status active
2020-08-11 20:08:39 DEBUG update-status active
2020-08-11 20:08:39 DEBUG update-status active
2020-08-11 20:08:39 DEBUG update-status active
2020-08-11 20:08:39 DEBUG update-status active
2020-08-11 20:08:39 DEBUG update-status active
2020-08-11 20:08:39 DEBUG update-status active
2020-08-11 20:08:39 DEBUG update-status ERROR connection is shut down
2020-08-11 20:08:39 INFO juju-log status-set failed: active Unit is ready
2020-08-11 20:08:40 ERROR juju.worker.uniter.context context.go:829 could not write settings from "update-status" to relation 9: connection is shut down
2020-08-11 20:08:40 ERROR juju.worker.uniter.context context.go:829 could not write settings from "update-status" to relation 11: connection is shut down
2020-08-11 20:08:40 ERROR juju.worker.uniter.context context.go:829 could not write settings from "update-status" to relation 12: connection is shut down
2020-08-11 20:08:40 ERROR juju.worker.uniter.context context.go:829 could not write settings from "update-status" to relation 13: connection is shut down
2020-08-11 20:08:40 ERROR juju.worker.uniter.context context.go:829 could not write settings from "update-status" to relation 0: connection is shut down
2020-08-11 20:08:40 ERROR juju.worker.uniter.context context.go:829 could not write settings from "update-status" to relation 7: connection is shut down
2020-08-11 20:08:40 ERROR juju.worker.uniter.context context.go:829 could not write settings from "update-status" to relation 8: connection is shut down
2020-08-11 20:08:40 ERROR juju.worker.uniter.operation runhook.go:132 hook "update-status" failed: could not write settings from "update-status" to relation 9: connection is shut down
2020-08-11 20:08:42 ERROR juju.worker.dependency engine.go:671 "api-caller" manifold worker returned unexpected error: [025764] "unit-designate-0" cannot open api: unable to connect to API: dial tcp 252.0.23.1:17070: connect: connection refused
2020-08-11 20:08:46 ERROR juju.worker.dependency engine.go:671 "api-caller" manifold worker returned unexpected error: [025764] "unit-designate-0" cannot open api: unable to connect to API: dial tcp 10.5.0.23:17070: connect: connection refused
2020-08-11 20:08:50 ERROR juju.worker.dependency engine.go:671 "api-caller" manifold worker returned unexpected error: [025764] "unit-designate-0" cannot open api: unable to connect to API: dial tcp 252.0.23.1:17070: connect: connection refused
2020-08-11 20:08:56 ERROR juju.worker.dependency engine.go:671 "api-caller" manifold worker returned unexpected error: [025764] "unit-designate-0" cannot open api: login for unit designate/0 blocked because upgrade is in progress
"unit-designate-0.log" [readonly] 3642L, 300662C

#### Unit status history:
ubuntu@beisner-bastion:~/git/charm-test-infra$ juju show-status-log designate/0 -n40
Time Type Status Message
11 Aug 2020 19:46:40Z juju-unit allocating
11 Aug 2020 19:46:40Z workload waiting waiting for machine
11 Aug 2020 19:48:30Z workload waiting installing agent
11 Aug 2020 19:48:33Z workload waiting agent initializing
11 Aug 2020 19:48:34Z workload maintenance installing charm software
11 Aug 2020 19:48:34Z juju-unit executing running install hook
11 Aug 2020 19:49:54Z workload maintenance Installing packages
11 Aug 2020 19:51:05Z workload maintenance Installation complete - awaiting next status
11 Aug 2020 19:51:09Z juju-unit executing running leader-elected hook
11 Aug 2020 19:51:15Z juju-unit executing running config-changed hook
11 Aug 2020 19:51:22Z juju-unit executing running start hook
11 Aug 2020 19:51:29Z juju-unit executing running amqp-relation-joined hook
11 Aug 2020 19:51:38Z juju-unit executing running coordinator-memcached-relation-joined hook
11 Aug 2020 19:51:48Z juju-unit executing running dns-backend-relation-joined hook
11 Aug 2020 19:51:58Z workload blocked Need either a dns-backend relation or config(dns-slaves) or both.
11 Aug 2020 19:51:58Z juju-unit executing running dns-backend-relation-changed hook
11 Aug 2020 19:52:09Z juju-unit executing running coordinator-memcached-relation-changed hook
11 Aug 2020 19:52:18Z workload blocked 'shared-db' missing, 'amqp' incomplete, 'identity-service' missing
11 Aug 2020 19:52:19Z juju-unit executing running identity-service-relation-joined hook
11 Aug 2020 19:52:32Z workload blocked 'shared-db' missing, 'amqp' incomplete, 'identity-service' incomplete
11 Aug 2020 19:52:32Z juju-unit executing running amqp-relation-changed hook
11 Aug 2020 19:52:44Z workload blocked 'shared-db' missing, 'identity-service' incomplete
11 Aug 2020 19:52:45Z juju-unit executing running shared-db-relation-joined hook
11 Aug 2020 19:52:59Z juju-unit executing running dnsaas-relation-joined hook
11 Aug 2020 19:53:13Z workload waiting 'shared-db' incomplete, 'identity-service' incomplete
11 Aug 2020 19:53:13Z juju-unit executing running shared-db-relation-changed hook
11 Aug 2020 19:53:29Z workload waiting 'identity-service' incomplete
11 Aug 2020 19:53:29Z juju-unit executing running identity-service-relation-changed hook
11 Aug 2020 19:55:50Z juju-unit executing running dnsaas-relation-changed hook
11 Aug 2020 19:56:06Z juju-unit executing running identity-service-relation-changed hook
11 Aug 2020 19:56:23Z juju-unit idle
11 Aug 2020 20:03:59Z workload active Unit is ready
11 Aug 2020 20:09:03Z juju-unit error hook failed: "update-status"

[Ryan Beisner (1chb1n)]

This may be entirely expected, given that this is a non-HA, single-controller scenario. Documenting, nonetheless. :-)

[Canonical Juju QA Bot (juju-qa-bot)]

This bug has not been updated in 2 years, so we're marking it Low importance. If you believe this is incorrect, please update the importance.