Ironic Inspector

"Unknown column 'nodes.finished_at' in 'where clause'"

Bug #1616057 reported by Waldemar Znoinski
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Ironic Inspector
Incomplete
Undecided
Waldemar Znoinski
Mitaka
New
Undecided
Unassigned

Bug Description

stable/mitaka setup using kolla stable/mitaka

pip freeze | grep -i inspector
ironic-inspector==3.2.2

 ironic-conductor --version
5.1.0

keep getting the below in ironic_inspector log

2016-08-23 13:30:12.140 1 DEBUG futurist.periodics [-] Submitting periodic function 'ironic_inspector.main.periodic_clean_up' _process_scheduled /var/lib/kolla/venv/local/lib/python2.7/site-packages/futurist/periodics.py:611
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters [-] DBAPIError exception wrapped from (pymysql.err.InternalError) (1054, u"Unknown column 'nodes.finished_at' in 'where clause'") [SQL: u'DELETE FROM nodes WHERE nodes.finished_at IS NOT NULL AND nodes.finish
ed_at < %(finished_at_1)s'] [parameters: {u'finished_at_1': 1471350612.140855}]
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters Traceback (most recent call last):
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters context)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters cursor.execute(statement, parameters)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/cursors.py", line 158, in execute
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters result = self._query(query)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/cursors.py", line 308, in _query
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters conn.query(q)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 820, in query
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 1002, in _read_query_result
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters result.read()
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 1285, in read
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters first_packet = self.connection._read_packet()
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 966, in _read_packet
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters packet.check_error()
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 394, in check_error
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters err.raise_mysql_exception(self._data)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/err.py", line 120, in raise_mysql_exception
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters _check_mysql_exception(errinfo)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/err.py", line 115, in _check_mysql_exception
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters raise InternalError(errno, errorvalue)
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters InternalError: (1054, u"Unknown column 'nodes.finished_at' in 'where clause'")
2016-08-23 13:30:12.144 1 ERROR oslo_db.sqlalchemy.exc_filters

2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main [-] Periodic clean up of node cache failed
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main Traceback (most recent call last):
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/ironic_inspector/main.py", line 299, in periodic_clean_up
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main if node_cache.clean_up():
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/ironic_inspector/node_cache.py", line 548, in clean_up
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main db.Node.finished_at < status_keep_threshold).delete()
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/query.py", line 3048, in delete
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main delete_op.exec_()
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 1127, in exec_
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main self._do_exec()
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 1311, in _do_exec
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main mapper=self.mapper)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/orm/session.py", line 1034, in execute
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main bind, close_with_result=True).execute(clause, params or {})
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main return meth(self, multiparams, params)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main return connection._execute_clauseelement(self, multiparams, params)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main compiled_sql, distilled_params
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main context)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1337, in _handle_dbapi_exception
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main util.raise_from_cause(newraise, exc_info)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/util/compat.py", line 200, in raise_from_cause
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main reraise(type(exception), exception, tb=exc_tb, cause=cause)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main context)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/sqlalchemy/engine/default.py", line 450, in do_execute
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main cursor.execute(statement, parameters)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/cursors.py", line 158, in execute
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main result = self._query(query)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/cursors.py", line 308, in _query
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main conn.query(q)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 820, in query
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main self._affected_rows = self._read_query_result(unbuffered=unbuffered)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 1002, in _read_query_result
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main result.read()
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 1285, in read
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main first_packet = self.connection._read_packet()
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 966, in _read_packet
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main packet.check_error()
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/connections.py", line 394, in check_error
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main err.raise_mysql_exception(self._data)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/err.py", line 120, in raise_mysql_exception
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main _check_mysql_exception(errinfo)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main File "/var/lib/kolla/venv/local/lib/python2.7/site-packages/pymysql/err.py", line 115, in _check_mysql_exception
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main raise InternalError(errno, errorvalue)
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main DBError: (pymysql.err.InternalError) (1054, u"Unknown column 'nodes.finished_at' in 'where clause'") [SQL: u'DELETE FROM nodes WHERE nodes.finished_at IS NOT NULL AND nodes.finished_at < %(finished_at_1)s'] [parameter
s: {u'finished_at_1': 1471350612.140855}]
2016-08-23 13:30:12.146 1 ERROR ironic_inspector.main

Waldemar Znoinski (wznoinsk)
Changed in ironic-inspector:
assignee: nobody → Waldemar Znoinski (wznoinsk)
Revision history for this message
Jay Faulkner (jason-oldos) wrote :

That column is added in the initial DB setup: https://github.com/openstack/ironic-inspector/blob/master/ironic_inspector/migrations/versions/578f84f38d_inital_db_schema.py

Can you add more information about how/when you see this? As it is I can't see how this is possible.

Changed in ironic-inspector:
status: New → Incomplete
Revision history for this message
milan k (vetrisko) wrote :

Seems this needs confirming from the reporter

Revision history for this message
kimbarbel (kimbarbel) wrote :
Download full text (3.8 KiB)

Hi,
I had the same error, my nodes table look like this:

MariaDB [ironic]> describe nodes;
+------------------------+--------------+------+-----+---------+----------------+
| Field | Type | Null | Key | Default | Extra |
 +------------------------+--------------+------+-----+---------+----------------+
| created_at | datetime | YES | | NULL | |
| updated_at | datetime | YES | | NULL | |
| id | int(11) | NO | PRI | NULL | auto_increment |
| uuid | varchar(36) | YES | UNI | NULL | |
| instance_uuid | varchar(36) | YES | UNI | NULL | |
| name | varchar(255) | YES | UNI | NULL | |
| chassis_id | int(11) | YES | MUL | NULL | |
| power_state | varchar(15) | YES | | NULL | |
| target_power_state | varchar(15) | YES | | NULL | |
| provision_state | varchar(15) | YES | | NULL | |
| target_provision_state | varchar(15) | YES | | NULL | |
| provision_updated_at | datetime | YES | | NULL | |
| last_error | text | YES | | NULL | |
| instance_info | text | YES | | NULL | |
| properties | text | YES | | NULL | |
| driver | varchar(255) | YES | | NULL | |
| driver_info | text | YES | | NULL | |
| driver_internal_info | text | YES | | NULL | |
| clean_step | text | YES | | NULL | |
| resource_class | varchar(80) | YES | | NULL | |
| raid_config | text | YES | | NULL | |
| target_raid_config | text | YES | | NULL | |
| reservation | varchar(255) | YES | | NULL | |
| conductor_affinity | int(11) | YES | MUL | NULL | |
| maintenance | tinyint(1) | YES | | NULL | |
| maintenance_reason | text | YES | | NULL | |
| console_enabled | tinyint(1) | YES | | NULL | |
| inspection_finished_at | datetime | YES | | NULL | |
| inspection_started_at | datetime | YES | | NULL | |
| extra | text | YES | | NULL | |
| boot_interface | varchar(255) | YES | | NULL | |
| console_interface | varchar(255) | YES | | NULL | |
| deploy_interface | varchar(255) | YES | | NUL...

Read more...

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.