Description of problem: when upgrade v3.9 to v3.10. Task 'Migrate from etcd to CustomResources' failed at ' unable to migrate all extracted credentials' Version-Release number of selected component (if applicable): openshift-ansible-3.10.0-0.50.0 How reproducible: always Steps to Reproduce: 1. install OCP v3.9 , 2. provision postgresql(with binding) +mediawiki in project1, provision postgresql+2binding in project2. 3. upgrade to v3.10 Actual results: upgrade failed. Play: Upgrade Service Catalog Task: Fail out because the ASB etcd to CRD migration was unsuccessful Message: The migration from etcd to CustomResourceDefinitions was not successful, aborting upgrade of the ansible service broker. asb pod: # oc get pod NAME READY STATUS RESTARTS AGE asb-1-gsqph 1/1 Running 0 37m asb-etcd-1-ftmqm 1/1 Running 0 1m asb-etcd-1-rftmr 0/1 Evicted 0 3h asb-etcd-migration-2245v 0/1 Error 0 26m ....... it generate a lot of asb-etcd-migration** pod even after the upgrade job completed [root@qe-zitang-39up-master-etcd-1 ~]# oc get pod | wc -l 355 [root@qe-zitang-39up-master-etcd-1 ~]# oc get pod | wc -l 368 # oc log -f asb-1-gsqph log is DEPRECATED and will be removed in a future version. Use logs instead. Using config file mounted to /etc/ansible-service-broker/config.yaml ============================================================ == Starting Ansible Service Broker... == ============================================================ 2018/05/23 06:03:34 Unable to get log.logfile from config [2018-05-23T06:03:34.362Z] [NOTICE] - Initializing clients... [2018-05-23T06:03:34.363Z] [INFO] - == ETCD CX == [2018-05-23T06:03:34.363Z] [INFO] - EtcdHost: asb-etcd.openshift-ansible-service-broker.svc [2018-05-23T06:03:34.363Z] [INFO] - EtcdPort: 2379 [2018-05-23T06:03:34.363Z] [INFO] - Endpoints: [https://asb-etcd.openshift-ansible-service-broker.svc:2379] [2018-05-23T06:03:34.38Z] [INFO] - Etcd Version [Server: 3.2.18, Cluster: 3.2.0] [2018-05-23T06:03:34.392Z] [INFO] - OpenShift version: v3.10.0-0.50.0 [2018-05-23T06:03:34.397Z] [INFO] - Kubernetes version: v1.10.0+b81c8f8 [2018-05-23T06:03:34.397Z] [INFO] - == REGISTRY CX == [2018-05-23T06:03:34.397Z] [INFO] - Name: rh [2018-05-23T06:03:34.397Z] [INFO] - Type: rhcc [2018-05-23T06:03:34.397Z] [INFO] - Url: https://registry.access.redhat.com [2018-05-23T06:03:34.397Z] [INFO] - == REGISTRY CX == [2018-05-23T06:03:34.398Z] [INFO] - Name: localregistry [2018-05-23T06:03:34.398Z] [INFO] - Type: local_openshift [2018-05-23T06:03:34.398Z] [INFO] - Url: [2018-05-23T06:03:34.398Z] [INFO] - Initiating Recovery Process [2018-05-23T06:03:34.398Z] [INFO] - Listening for provision messages [2018-05-23T06:03:34.398Z] [INFO] - Listening for deprovision messages [2018-05-23T06:03:34.398Z] [INFO] - Listening for binding messages [2018-05-23T06:03:34.398Z] [INFO] - Listening for update messages [2018-05-23T06:03:34.398Z] [INFO] - Listening for binding messages [2018-05-23T06:03:34.4Z] [INFO] - Recovery complete [2018-05-23T06:03:34.4Z] [NOTICE] - recover called [2018-05-23T06:03:34.4Z] [INFO] - Broker configured to bootstrap on startup [2018-05-23T06:03:34.4Z] [INFO] - Attempting bootstrap... [2018-05-23T06:03:34.4Z] [INFO] - AnsibleBroker::Bootstrap [2018-05-23T06:03:36.196Z] [INFO] - Validating specs... [2018-05-23T06:03:36.196Z] [NOTICE] - All specs passed validation! [2018-05-23T06:03:36.516Z] [INFO] - Validating specs... [2018-05-23T06:03:36.517Z] [NOTICE] - All specs passed validation! [2018-05-23T06:03:36.532Z] [NOTICE] - Broker successfully bootstrapped on startup [2018-05-23T06:03:37.199Z] [NOTICE] - Listening on https://[::]:1338 [2018-05-23T06:03:37.199Z] [NOTICE] - Ansible Service Broker Starting [2018-05-23T06:04:52.223Z] [INFO] - AnsibleBroker::Catalog 10.128.0.1 - - [23/May/2018:06:04:52 +0000] "GET /ansible-service-broker/v2/catalog HTTP/1.1" 200 31690 [2018-05-23T06:04:53.247Z] [INFO] - AnsibleBroker::Catalog 10.128.0.1 - - [23/May/2018:06:04:53 +0000] "GET /ansible-service-broker/v2/catalog HTTP/1.1" 200 31690 [2018-05-23T06:13:36.532Z] [INFO] - Broker configured to refresh specs every 10m0s seconds [2018-05-23T06:13:36.532Z] [INFO] - Attempting bootstrap at 2018-05-23 06:13:36.532536283 +0000 UTC [2018-05-23T06:13:36.532Z] [INFO] - AnsibleBroker::Bootstrap [2018-05-23T06:13:38.393Z] [INFO] - Validating specs... [2018-05-23T06:13:38.393Z] [NOTICE] - All specs passed validation! [2018-05-23T06:13:38.693Z] [INFO] - Validating specs... [2018-05-23T06:13:38.693Z] [NOTICE] - All specs passed validation! [2018-05-23T06:13:38.708Z] [NOTICE] - Broker successfully bootstrapped [2018-05-23T06:20:10.465Z] [INFO] - AnsibleBroker::Catalog 10.128.0.1 - - [23/May/2018:06:20:10 +0000] "GET /ansible-service-broker/v2/catalog HTTP/1.1" 200 31690 [2018-05-23T06:23:36.532Z] [INFO] - Broker configured to refresh specs every 10m0s seconds [2018-05-23T06:23:36.532Z] [INFO] - Attempting bootstrap at 2018-05-23 06:23:36.532607646 +0000 UTC [2018-05-23T06:23:36.532Z] [INFO] - AnsibleBroker::Bootstrap [2018-05-23T06:23:38.143Z] [INFO] - Validating specs... [2018-05-23T06:23:38.143Z] [NOTICE] - All specs passed validation! [2018-05-23T06:23:38.442Z] [INFO] - Validating specs... [2018-05-23T06:23:38.442Z] [NOTICE] - All specs passed validation! [2018-05-23T06:23:38.456Z] [NOTICE] - Broker successfully bootstrapped The pod log of migration: # oc logs -f asb-etcd-migration-gqb7f time="2018-05-23T06:05:03Z" level=info msg="etcd configuration: {asb-etcd.openshift-ansible-service-broker.svc /var/run/secrets/kubernetes.io/serviceaccount/service-ca.crt /var/run/asb-etcd-auth/client.crt /var/run/asb-etcd-auth/client.key 2379}" time="2018-05-23T06:05:03Z" level=info msg="== ETCD CX ==" time="2018-05-23T06:05:03Z" level=info msg="EtcdHost: asb-etcd.openshift-ansible-service-broker.svc" time="2018-05-23T06:05:03Z" level=info msg="EtcdPort: 2379" time="2018-05-23T06:05:03Z" level=info msg="Endpoints: [https://asb-etcd.openshift-ansible-service-broker.svc:2379]" 2018/05/23 06:05:03 Dao::BatchGetRaw 2018/05/23 06:05:03 Successfully loaded [ 4 ] objects from etcd dir [ /spec ] 2018/05/23 06:05:03 Batch idx [ 0 ] -> [ 73ead67495322cc462794387fa9884f5 ] 2018/05/23 06:05:03 Batch idx [ 1 ] -> [ 2c259ddd8059b9bc65081e07bf20058f ] 2018/05/23 06:05:03 Batch idx [ 2 ] -> [ 03b69500305d9859bb9440d9f9023784 ] 2018/05/23 06:05:03 Batch idx [ 3 ] -> [ d5915e05b253df421efe6e41fb6a66ba ] 2018/05/23 06:05:03 set spec: 73ead67495322cc462794387fa9884f5 2018/05/23 06:05:03 set spec: 2c259ddd8059b9bc65081e07bf20058f 2018/05/23 06:05:03 set spec: 03b69500305d9859bb9440d9f9023784 2018/05/23 06:05:03 set spec: d5915e05b253df421efe6e41fb6a66ba 2018/05/23 06:05:03 Dao::BatchGetRaw 2018/05/23 06:05:03 Successfully loaded [ 3 ] objects from etcd dir [ /service_instance ] 2018/05/23 06:05:03 set service instance: 2e782145-398a-412e-8f36-c4ebd3d0d169 2018/05/23 06:05:03 set service instance: c63bbb58-2807-464d-bebb-e7a1053923e4 2018/05/23 06:05:03 set service instance: bdbda3b5-7fde-40cc-9d5c-8f09d10f4d03 2018/05/23 06:05:03 Dao::BatchGetRaw 2018/05/23 06:05:03 Successfully loaded [ 3 ] objects from etcd dir [ /bind_instance ] 2018/05/23 06:05:03 set binding instance: 2f3a9503-2230-4447-8911-f09f0985c142 2018/05/23 06:05:03 set binding instance: a6805d95-f41d-4378-895a-ebe337477b0a 2018/05/23 06:05:03 set binding instance: 03f07398-c313-4cda-925c-aaf32bae9a7f 2018/05/23 06:05:04 Dao::BatchGetRaw 2018/05/23 06:05:04 Successfully loaded [ 1 ] objects from etcd dir [ /state/2e782145-398a-412e-8f36-c4ebd3d0d169/job ] 2018/05/23 06:05:04 set job state for instance: 2e782145-398a-412e-8f36-c4ebd3d0d169 token: e850dfc2-d763-4c3d-a87e-f3ad2146133e 2018/05/23 06:05:04 Dao::BatchGetRaw 2018/05/23 06:05:04 Successfully loaded [ 1 ] objects from etcd dir [ /state/c63bbb58-2807-464d-bebb-e7a1053923e4/job ] 2018/05/23 06:05:04 set job state for instance: c63bbb58-2807-464d-bebb-e7a1053923e4 token: 835aeaf2-2cf2-40a7-bc70-f60c9063e9bc 2018/05/23 06:05:04 Dao::BatchGetRaw 2018/05/23 06:05:04 Successfully loaded [ 1 ] objects from etcd dir [ /state/bdbda3b5-7fde-40cc-9d5c-8f09d10f4d03/job ] 2018/05/23 06:05:04 set job state for instance: bdbda3b5-7fde-40cc-9d5c-8f09d10f4d03 token: 4a2e7581-bfcf-4994-b69c-9776cc22b3d7 2018/05/23 06:05:05 Dao::DeleteBindInstance -> [ 2f3a9503-2230-4447-8911-f09f0985c142 ] 2018/05/23 06:05:05 Dao::DeleteBindInstance -> [ a6805d95-f41d-4378-895a-ebe337477b0a ] 2018/05/23 06:05:05 Dao::DeleteBindInstance -> [ 03f07398-c313-4cda-925c-aaf32bae9a7f ] time="2018-05-23T06:05:05Z" level=info msg="reverted saved binding instances" 2018/05/23 06:05:05 Dao::DeleteServiceInstance -> [ 2e782145-398a-412e-8f36-c4ebd3d0d169 ] 2018/05/23 06:05:06 Dao::DeleteServiceInstance -> [ c63bbb58-2807-464d-bebb-e7a1053923e4 ] 2018/05/23 06:05:06 Dao::DeleteServiceInstance -> [ bdbda3b5-7fde-40cc-9d5c-8f09d10f4d03 ] time="2018-05-23T06:05:06Z" level=info msg="reverted service instances" 2018/05/23 06:05:06 Dao::DeleteSpec-> [ 73ead67495322cc462794387fa9884f5 ] 2018/05/23 06:05:06 Dao::DeleteSpec-> [ 2c259ddd8059b9bc65081e07bf20058f ] 2018/05/23 06:05:06 Dao::DeleteSpec-> [ 03b69500305d9859bb9440d9f9023784 ] 2018/05/23 06:05:07 Dao::DeleteSpec-> [ d5915e05b253df421efe6e41fb6a66ba ] time="2018-05-23T06:05:07Z" level=info msg="reverted saved specs - exiting now - migration failed" panic: Unable to migrate all extracted credentials - 100: Key not found (/extracted_credentials/2f3a9503-2230-4447-8911-f09f0985c142) [270] goroutine 1 [running]: main.main() /builddir/build/BUILD/ansible-service-broker-1.2.12/cmd/migration/main.go:247 +0x2e42 data in etcd: #eta ls /extracted_credentials /extracted_credentials/c63bbb58-2807-464d-bebb-e7a1053923e4 /extracted_credentials/bdbda3b5-7fde-40cc-9d5c-8f09d10f4d03 /extracted_credentials/2e782145-398a-412e-8f36-c4ebd3d0d169 Expected results: upgrage succeed. Additional info:
ASB haven't upgrade succeed still now, so add TestBlocker tag
This bug is blocking all upgrade testing in asb side.
master: https://github.com/openshift/ansible-service-broker/pull/965 release-1.2: https://github.com/openshift/ansible-service-broker/pull/966
verified asb version: 1.2.14 openshift-ansible-3.10.0-0.53.0
Since the problem described in this bug report should be resolved in a recent advisory, it has been closed with a resolution of ERRATA. For information on the advisory, and where to find the updated files, follow the link below. If the solution does not work for you, open a new bug report. https://access.redhat.com/errata/RHBA-2018:1816