yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1589880] [NEW] report state failed

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: kaka <mingb1989@xxxxxxxxx>
Date: Tue, 07 Jun 2016 09:26:17 -0000
Reply-to: Bug 1589880 <1589880@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Description：
=================
set master database read_only=on when switching master nova database to slave,after that，I check nova service status
# nova-manage service list
Binary           Host                              Zone             Status     State Updated_At
nova-consoleauth 11_120                            internal         enabled    XXX   2016-06-07 08:28:46
nova-conductor   11_120                            internal         enabled    XXX   2016-06-07 08:28:45
nova-cert        11_120                            internal         enabled    XXX   2016-05-17 08:12:10
nova-scheduler   11_120                            internal         enabled    XXX   2016-05-17 08:12:24
nova-compute     11_121                            bx               enabled    XXX   2016-06-07 08:28:49
nova-compute     11_122                            bx               enabled    XXX   2016-06-07 08:28:42
=================

Steps to reproduce
=================
# mysql
MariaDB [nova]> set global read_only=on;
=================

Environment
================
Version：Liberty
openstack-nova-conductor-12.0.0-1.el7.noarch

Logs
================

2016-05-12 11:01:20.343 9198 ERROR oslo.service.loopingcall 
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall [-] Fixed interval looping call 'nova.servicegroup.drivers.db.DbDriver._report_state' failed
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall Traceback (most recent call last):
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 113, in _run_loop
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     result = func(*self.args, **self.kw)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/servicegroup/drivers/db.py", line 87, in _report_state
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     service.service_ref.save()
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 213, in wrapper
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return fn(self, *args, **kwargs)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/objects/service.py", line 250, in save
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     db_service = db.service_update(self._context, self.id, updates)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 153, in service_update
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return IMPL.service_update(context, service_id, values)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 146, in wrapper
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     ectxt.value = e.inner_exc
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 195, in __exit__
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     six.reraise(self.type_, self.value, self.tb)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 136, in wrapper
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return f(*args, **kwargs)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 532, in service_update
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     service_ref.update(values)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 490, in __exit__
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self.rollback()
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     compat.reraise(exc_type, exc_value, exc_tb)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 487, in __exit__
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self.commit()
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 392, in commit
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self._prepare_impl()
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 372, in _prepare_impl
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self.session.flush()
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2004, in flush
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self._flush(objects)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2122, in _flush
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     transaction.rollback(_capture_exception=True)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     compat.reraise(exc_type, exc_value, exc_tb)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2086, in _flush
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     flush_context.execute()
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     rec.execute(self)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     uow
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 170, in save_obj
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     mapper, table, update)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 672, in _emit_update_statements
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     execute(statement, multiparams)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return meth(self, multiparams, params)
2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     return connection._execute_clauseelement(self, multiparams, params)
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     compiled_sql, distilled_params
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     context)
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1335, in _handle_dbapi_exception
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     util.raise_from_cause(newraise, exc_info)
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     reraise(type(exception), exception, tb=exc_tb)
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     context)
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 442, in do_execute
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     cursor.execute(statement, parameters)
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/MySQLdb/cursors.py", line 174, in execute
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     self.errorhandler(self, exc, value)
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     raise errorclass, errorvalue
2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall OperationalError: (_mysql_exceptions.OperationalError) (1290, 'The MariaDB server is running with the --read-only option so it cannot execute this statement') [SQL: u'UPDATE services SET updated_at=%s, report_count=%s, last_seen_up=%s WHERE services.id = %s'] [parameters: (datetime.datetime(2016, 5, 12, 3, 1, 17, 572767), 1189606, datetime.datetime(2016, 5, 12, 3, 1, 17, 571934), 2L)]

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1589880

Title:
  report state failed

Status in OpenStack Compute (nova):
  New

Bug description:
  Description：
  =================
  set master database read_only=on when switching master nova database to slave,after that，I check nova service status
  # nova-manage service list
  Binary           Host                              Zone             Status     State Updated_At
  nova-consoleauth 11_120                            internal         enabled    XXX   2016-06-07 08:28:46
  nova-conductor   11_120                            internal         enabled    XXX   2016-06-07 08:28:45
  nova-cert        11_120                            internal         enabled    XXX   2016-05-17 08:12:10
  nova-scheduler   11_120                            internal         enabled    XXX   2016-05-17 08:12:24
  nova-compute     11_121                            bx               enabled    XXX   2016-06-07 08:28:49
  nova-compute     11_122                            bx               enabled    XXX   2016-06-07 08:28:42
  =================

  Steps to reproduce
  =================
  # mysql
  MariaDB [nova]> set global read_only=on;
  =================

  Environment
  ================
  Version：Liberty
  openstack-nova-conductor-12.0.0-1.el7.noarch

  Logs
  ================

  2016-05-12 11:01:20.343 9198 ERROR oslo.service.loopingcall 
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall [-] Fixed interval looping call 'nova.servicegroup.drivers.db.DbDriver._report_state' failed
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall Traceback (most recent call last):
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_service/loopingcall.py", line 113, in _run_loop
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     result = func(*self.args, **self.kw)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/servicegroup/drivers/db.py", line 87, in _report_state
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     service.service_ref.save()
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_versionedobjects/base.py", line 213, in wrapper
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return fn(self, *args, **kwargs)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/objects/service.py", line 250, in save
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     db_service = db.service_update(self._context, self.id, updates)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/db/api.py", line 153, in service_update
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return IMPL.service_update(context, service_id, values)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 146, in wrapper
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     ectxt.value = e.inner_exc
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 195, in __exit__
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     six.reraise(self.type_, self.value, self.tb)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/oslo_db/api.py", line 136, in wrapper
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return f(*args, **kwargs)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 532, in service_update
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     service_ref.update(values)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 490, in __exit__
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self.rollback()
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     compat.reraise(exc_type, exc_value, exc_tb)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 487, in __exit__
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self.commit()
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 392, in commit
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self._prepare_impl()
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 372, in _prepare_impl
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self.session.flush()
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2004, in flush
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     self._flush(objects)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2122, in _flush
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     transaction.rollback(_capture_exception=True)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/langhelpers.py", line 60, in __exit__
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     compat.reraise(exc_type, exc_value, exc_tb)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 2086, in _flush
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     flush_context.execute()
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 373, in execute
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     rec.execute(self)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/unitofwork.py", line 532, in execute
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     uow
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 170, in save_obj
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     mapper, table, update)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 672, in _emit_update_statements
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     execute(statement, multiparams)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 914, in execute
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall     return meth(self, multiparams, params)
  2016-05-12 11:01:20.473 9178 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 323, in _execute_on_connection
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     return connection._execute_clauseelement(self, multiparams, params)
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1010, in _execute_clauseelement
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     compiled_sql, distilled_params
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1146, in _execute_context
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     context)
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1335, in _handle_dbapi_exception
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     util.raise_from_cause(newraise, exc_info)
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     reraise(type(exception), exception, tb=exc_tb)
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1139, in _execute_context
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     context)
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 442, in do_execute
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     cursor.execute(statement, parameters)
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/MySQLdb/cursors.py", line 174, in execute
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     self.errorhandler(self, exc, value)
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall   File "/usr/lib64/python2.7/site-packages/MySQLdb/connections.py", line 36, in defaulterrorhandler
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall     raise errorclass, errorvalue
  2016-05-12 11:01:17.575 9177 ERROR oslo.service.loopingcall OperationalError: (_mysql_exceptions.OperationalError) (1290, 'The MariaDB server is running with the --read-only option so it cannot execute this statement') [SQL: u'UPDATE services SET updated_at=%s, report_count=%s, last_seen_up=%s WHERE services.id = %s'] [parameters: (datetime.datetime(2016, 5, 12, 3, 1, 17, 572767), 1189606, datetime.datetime(2016, 5, 12, 3, 1, 17, 571934), 2L)]

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1589880/+subscriptions
Follow ups

[Bug 1589880] Re: report state failed
From: Roman Podoliaka, 2016-09-28
[Bug 1589880] Re: report state failed
From: Takashi NATSUME, 2016-06-09