re-inspection attempt failed with db error

[Julia Kreger]

Upon attempting to re-inspect a node that failed to inspect, we observe the following in bifrost via shade, which was surfaced from what python-ironicclient ultimately surfaced.

failed: [testvm1 -> localhost] => {"failed": true}
msg: Error inspecting machine: Inspection of node a8cb6624-0d9f-c882-affc-046ebb96ec01 failed, last error: Failed to start inspection: Internal server error (DBReferenceError): (_mysql_exceptions.IntegrityError) (1451, 'Cannot delete or update a parent row: a foreign key x`constraint fails (`inspector`.`attributes`, CONSTRAINT `attributes_ibfk_1` FOREIGN KEY (`uuid`) REFERENCES `nodes` (`uuid`))') [SQL: u'DELETE FROM nodes WHERE nodes.uuid = %s'] [parameters: ('a8cb6624-0d9f-c882-affc-046ebb96ec01',)]

What occurred was that the node, with pre-defined uuid, was deleted from Ironic where an inspection failed to occur due to a boot failure. The node was re-added to ironic, and inspection was re-called without the contents of the inspector database having been purged.

Inspector log file:

2015-10-23 19:41:18.607 27972 INFO werkzeug [-] 10.0.2.15 - - [23/Oct/2015 19:41:18] "GET / HTTP/1.1" 200 -
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main [-] Internal server error
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main Traceback (most recent call last):
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/ironic_inspector/main.py", line 72, in wrapper
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main return func(*args, **kwargs)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/ironic_inspector/main.py", line 196, in api_introspection
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main token=flask.request.headers.get('X-Auth-Token'))
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/ironic_inspector/introspect.py", line 101, in introspect
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main ironic=ironic)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/ironic_inspector/node_cache.py", line 311, in add_node
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main _delete_node(uuid)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/ironic_inspector/node_cache.py", line 342, in _delete_node
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main (db.model_query(db.Node, session=session).filter_by(uuid=uuid).
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/query.py", line 2883, in delete
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main delete_op.exec_()
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 1112, in exec_
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main self._do_exec()
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/persistence.py", line 1290, in _do_exec
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main mapper=self.mapper)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/orm/session.py", line 1034, in execute
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main bind, close_with_result=True).execute(clause, params or {})
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 914, in execute
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main return meth(self, multiparams, params)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main return connection._execute_clauseelement(self, multiparams, params)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main compiled_sql, distilled_params
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main context)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main util.raise_from_cause(newraise, exc_info)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main reraise(type(exception), exception, tb=exc_tb)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main context)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main cursor.execute(statement, parameters)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/lib/python2.7/dist-packages/MySQLdb/cursors.py", line 174, in execute
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main self.errorhandler(self, exc, value)
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main File "/usr/lib/python2.7/dist-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main raise errorclass, errorvalue
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main DBReferenceError: (_mysql_exceptions.IntegrityError) (1451, 'Cannot delete or update a parent row: a foreign key constraint fails (`inspector`.`attributes`, CONSTRAINT `attributes_ibfk_1` FOREIGN KEY (`uuid`) REFERENCES `nodes` (`uuid`))') [SQL: u'DELETE FROM nodes WHERE nodes.uuid = %s'] [parameters: ('a8cb6624-0d9f-c882-affc-046ebb96ec01',)]
2015-10-23 19:41:18.948 27972 ERROR ironic_inspector.main
2015-10-23 19:41:18.957 27972 DEBUG ironic_inspector.main [-] Returning error to client: Internal server error (DBReferenceError): (_mysql_exceptions.IntegrityError) (1451, 'Cannot delete or update a parent row: a foreign key constraint fails (`inspector`.`attributes`, CONSTRAINT `attributes_ibfk_1` FOREIGN KEY (`uuid`) REFERENCES `nodes` (`uuid`))') [SQL: u'DELETE FROM nodes WHERE nodes.uuid = %s'] [parameters: ('a8cb6624-0d9f-c882-affc-046ebb96ec01',)] error_response /usr/local/lib/python2.7/dist-packages/ironic_inspector/main.py:64
2015-10-23 19:41:18.958 27972 INFO werkzeug [-] 10.0.2.15 - - [23/Oct/2015 19:41:18] "POST /v1/introspection/a8cb6624-0d9f-c882-affc-046ebb96ec01 HTTP/1.1" 500 -
2015-10-23 19:41:27.929 27972 DEBUG ironic_inspector.main [-] Running periodic clean up of node cache periodic_clean_up /usr/local/lib/python2.7/dist-packages/ironic_inspector/main.py:280

Please let me know if you need more information.

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/243553

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/243553
Committed: https://git.openstack.org/cgit/openstack/ironic-inspector/commit/?id=9c62b95ffade6f289138b9096027c87196dd8258
Submitter: Jenkins
Branch: master

commit 9c62b95ffade6f289138b9096027c87196dd8258
Author: Dmitry Tantsur <email address hidden>
Date: Tue Nov 10 12:53:38 2015 +0100

    Properly order node deletion from cache

    In databases that actually support foreign keys (like MySQL),
    we need to delete everything linking to a node before deleting a node.

    Change-Id: I320d8547697c3c13b7acb2e3fee117347550e264
    Closes-Bug: #1511187

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: stable/liberty
Review: https://review.openstack.org/244664

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/244664
Committed: https://git.openstack.org/cgit/openstack/ironic-inspector/commit/?id=37717e1ece723b3f6322192561d11c955e62f51d
Submitter: Jenkins
Branch: stable/liberty

commit 37717e1ece723b3f6322192561d11c955e62f51d
Author: Dmitry Tantsur <email address hidden>
Date: Tue Nov 10 12:53:38 2015 +0100

    Properly order node deletion from cache

    In databases that actually support foreign keys (like MySQL),
    we need to delete everything linking to a node before deleting a node.

    Change-Id: I320d8547697c3c13b7acb2e3fee117347550e264
    Closes-Bug: #1511187
    (cherry picked from commit 9c62b95ffade6f289138b9096027c87196dd8258)

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/ironic-inspector 2.3.0 release.

[Doug Hellmann (doug-hellmann)]

This issue was fixed in the openstack/ironic-inspector 2.2.3 release.