Description of problem: Deploying overcloud fails at step4 of the controllers with the following errors: Aug 26 05:25:07 overcloud-controller-0.localdomain os-collect-config[4461]: b_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters [-] DBAPIError exception wrapped from (pymysql.err.InternalError) (1060, u\"Duplicate column name 'modified_at'\") [SQL: u'\\nALTER TABLE services ADD modified_at DATETIME']\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py\", line 1139, in _execute_context\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters context)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py\", line 450, in do_execute\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters cursor.execute(statement, parameters)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/cursors.py\", line 146, in execute\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters result = self._query(query)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/cursors.py\", line 296, in _query\u001b[0m\n\u001 Aug 26 05:25:07 overcloud-controller-0.localdomain os-collect-config[4461]: b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters conn.query(q)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/connections.py\", line 781, in query\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters self._affected_rows = self._read_query_result(unbuffered=unbuffered)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/connections.py\", line 942, in _read_query_result\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters result.read()\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/connections.py\", line 1138, in read\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters first_packet = self.connection._read_packet()\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/connections.py\", line 906, in _read_packet\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters packet.check_error()\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-man Aug 26 05:25:07 overcloud-controller-0.localdomain os-collect-config[4461]: age db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/connections.py\", line 367, in check_error\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters err.raise_mysql_exception(self._data)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/err.py\", line 120, in raise_mysql_exception\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters _check_mysql_exception(errinfo)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters File \"/usr/lib/python2.7/site-packages/pymysql/err.py\", line 115, in _check_mysql_exception\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters raise InternalError(errno, errorvalue)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1060, u\"Duplicate column name 'modified_at'\")\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.144 18485 ERROR oslo_db.sqlalchemy.exc_filters \u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 CRITICAL cinder [-] DBError: (pymysql.err.InternalError) (1060, u\"Duplicate column name 'modified_at'\") [SQL: u'\\nALTER TABLE services ADD modified_at DATETIME']\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_syn Aug 26 05:25:07 overcloud-controller-0.localdomain os-collect-config[4461]: c]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder Traceback (most recent call last):\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder File \"/usr/bin/cinder-manage\", line 10, in <module>\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder sys.exit(main())\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder File \"/usr/lib/python2.7/site-packages/cinder/cmd/manage.py\", line 592, in main\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder fn(*fn_args)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder File \"/usr/lib/python2.7/site-packages/cinder/cmd/manage.py\", line 231, in sync\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder return db_migration.db_sync(version)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder File \"/usr/lib/python2.7/site-packages/cinder/db/migration.py\", line 61, in db_sync\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder init_version=init_version)\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder File \"/usr/lib/python2.7/site-packages/oslo_db/sqlalchemy/migration.py\", line 79, in db_sync\u001b[0m\n\u001b[mNotice: /Stage[main]/Cinder::Db::Sync/Exec[cinder-manage db_sync]/returns: 2016-08-26 05:22:39.151 18485 ERROR cinder migration = versioning_api.upgrade(engine, repository, version)\u001b[0m\n\ Version-Release number of selected component (if applicable): How reproducible: Always Steps to Reproduce: 1. Create overcloud images 2. Try deploying an overcloud 3. Actual results: Fails Deploying overcloud fails at step4 of the controllers [stack@undercloud-0-liberty cloud]$ heat resource-list -n5 overcloud | grep -vi complete +---------------------------------------------+-----------------------------------------------+--------------------------------------------------------------------------+-----------------+---------------------+---------------------------------------------------------------------------------------------------------------+ | resource_name | physical_resource_id | resource_type | resource_status | updated_time | stack_name | +---------------------------------------------+-----------------------------------------------+--------------------------------------------------------------------------+-----------------+---------------------+---------------------------------------------------------------------------------------------------------------+ | ComputeNodesPostDeployment | 9e573066-f57f-4793-a9d7-f3dabf261822 | OS::TripleO::ComputePostDeployment | CREATE_FAILED | 2016-08-26T04:31:08 | overcloud | | ControllerNodesPostDeployment | 804ca95c-5103-4a24-9e59-8b72b721392e | OS::TripleO::ControllerPostDeployment | CREATE_FAILED | 2016-08-26T04:31:08 | overcloud | | ControllerOvercloudServicesDeployment_Step4 | 1a226697-9eb3-46c7-bb45-63a2c96a15d2 | OS::Heat::StructuredDeployments | CREATE_FAILED | 2016-08-26T05:15:53 | overcloud-ControllerNodesPostDeployment-b55fbpzb3luy | | 0 | decbfbd0-3a4b-4a67-98da-8e4ce4a1dfdc | OS::Heat::StructuredDeployment | CREATE_FAILED | 2016-08-26T05:20:33 | overcloud-ControllerNodesPostDeployment-b55fbpzb3luy-ControllerOvercloudServicesDeployment_Step4-mthncnqlu5h3 | | 1 | 7a9c57a9-5efd-4b54-8d9c-ccab08406cfd | OS::Heat::StructuredDeployment | CREATE_FAILED | 2016-08-26T05:20:33 | overcloud-ControllerNodesPostDeployment-b55fbpzb3luy-ControllerOvercloudServicesDeployment_Step4-mthncnqlu5h3 | | 2 | 25e2c981-0ccf-4e27-ab9b-cf23599a3493 | OS::Heat::StructuredDeployment | CREATE_FAILED | 2016-08-26T05:20:34 | overcloud-ControllerNodesPostDeployment-b55fbpzb3luy-ControllerOvercloudServicesDeployment_Step4-mthncnqlu5h3 | +---------------------------------------------+-----------------------------------------------+--------------------------------------------------------------------------+-----------------+---------------------+---------------------------------------------------------------------------------------------------------------+ Expected results: Succeeds Additional info: Installing it on RHEL 7.2
This looks like a race condition because if I re-run the openstack overcloud deploy command , it will update the stack and successfully complete.
I can reproduce this issue with Mitaka as well. A redeployment will update it and it'll finish successfully.
This issue is also affecting Newton.
I am also hitting this issue with mitaka. Do we have any workaround for the issue ?
David, Sorry no response to this ticket. Are you still seeing this issue? Thanks
I haven't hit this issue for a while so I guess it's safe to close this bz.