Hello,
Now I'm checking Austine Release version of nova.
And I encounter the below problem.
Problem: when I tries to euca-run-instance -t m1.small -k testkey ami-tiny,
Nova-scheduler issued an error "Database is locked"(attached).
Few seconds later, nova-compute issued an same error(also attached).
After I checked the behavior, about both cnova-compute and nova-scheduler,
nova.service.report_state cause this problem. Also, additional information
is that, in case of scheduler, calling reporting_state got successful twice/
3rd just after euca-run-instance.
My next plan is using MySQL instead of sqlite, b/c
this "Database is locked" error seems like typical sqlite error.
But if someone knows solution for it, please let me know.
Thanks in advance,
Kei Masumoto
------------------------------------------------------------------
Kei Masumoto <[email protected]>
Assistant Manager,
Research and Development Hq, NTTData Corp.
tel: +81 50 5546 2301 FAX: +81 3 3532 0491
DEBUG:root:Running cmd: parted --script
/opt/nova-2010.1/nova/../instances/instance-3789518487/disk mkpartfs primary
ext2 20971583s 62914622s
2010-10-24 07:39:40+0900 [-] (root): DEBUG Running cmd: parted --script
/opt/nova-2010.1/nova/../instances/instance-3789518487/disk mkpartfs primary
ext2 20971583s 62914622s
DEBUG:root:Running cmd: dd
if=/opt/nova-2010.1/nova/../instances/instance-3789518487/disk-raw
of=/opt/nova-2010.1/nova/../instances/instance-3789518487/disk bs=512 seek=63
conv=notrunc,fsync
2010-10-24 07:39:46+0900 [-] (root): DEBUG Running cmd: dd
if=/opt/nova-2010.1/nova/../instances/instance-3789518487/disk-raw
of=/opt/nova-2010.1/nova/../instances/instance-3789518487/disk bs=512 seek=63
conv=notrunc,fsync
ERROR:root:model server went away
Traceback (most recent call last):
File "/opt/nova-2010.1/nova/service.py", line 178, in report_state
{'report_count': service_ref['report_count'] + 1})
File "/opt/nova-2010.1/nova/db/api.py", line 109, in service_update
return IMPL.service_update(context, service_id, values)
File "/opt/nova-2010.1/nova/db/sqlalchemy/api.py", line 98, in wrapper
return f(*args, **kwargs)
File "/opt/nova-2010.1/nova/db/sqlalchemy/api.py", line 252, in service_update
service_ref.save(session=session)
File "/opt/nova-2010.1/nova/db/sqlalchemy/models.py", line 66, in save
session.flush()
File "/usr/lib/pymodules/python2.6/sqlalchemy/orm/session.py", line 1346, in
flush
self._flush(objects)
File "/usr/lib/pymodules/python2.6/sqlalchemy/orm/session.py", line 1427, in
_flush
flush_context.execute()
File "/usr/lib/pymodules/python2.6/sqlalchemy/orm/unitofwork.py", line 299,
in execute
rec.execute(self)
File "/usr/lib/pymodules/python2.6/sqlalchemy/orm/unitofwork.py", line 443,
in execute
uow
File "/usr/lib/pymodules/python2.6/sqlalchemy/orm/mapper.py", line 1800, in
_save_obj
execute(statement, params)
File "/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1157, in
execute
params)
File "/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1237, in
_execute_clauseelement
return self.__execute_context(context)
File "/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1268, in
__execute_context
context.parameters[0], context=context)
File "/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1367, in
_cursor_execute
context)
File "/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1360, in
_cursor_execute
context)
File "/usr/lib/pymodules/python2.6/sqlalchemy/engine/default.py", line 288,
in do_execute
cursor.execute(statement, parameters)
OperationalError: (OperationalError) database is locked u'UPDATE services SET
updated_at=?, report_count=? WHERE services.id = ?' ('2010-10-23
22:40:41.095193', 287, 1)
2010-10-24 07:40:46+0900 [-] (root): ERROR model server went away
2010-10-24 07:40:46+0900 [-] Traceback (most recent call last):
2010-10-24 07:40:46+0900 [-] File "/opt/nova-2010.1/nova/service.py", line
178, in report_state
2010-10-24 07:40:46+0900 [-] {'report_count': service_ref['report_count'] +
1})
2010-10-24 07:40:46+0900 [-] File "/opt/nova-2010.1/nova/db/api.py", line
109, in service_update
2010-10-24 07:40:46+0900 [-] return IMPL.service_update(context,
service_id, values)
2010-10-24 07:40:46+0900 [-] File
"/opt/nova-2010.1/nova/db/sqlalchemy/api.py", line 98, in wrapper
2010-10-24 07:40:46+0900 [-] return f(*args, **kwargs)
2010-10-24 07:40:46+0900 [-] File
"/opt/nova-2010.1/nova/db/sqlalchemy/api.py", line 252, in service_update
2010-10-24 07:40:46+0900 [-] service_ref.save(session=session)
2010-10-24 07:40:46+0900 [-] File
"/opt/nova-2010.1/nova/db/sqlalchemy/models.py", line 66, in save
2010-10-24 07:40:46+0900 [-] session.flush()
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/session.py", line 1346, in flush
2010-10-24 07:40:46+0900 [-] self._flush(objects)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/session.py", line 1427, in _flush
2010-10-24 07:40:46+0900 [-] flush_context.execute()
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/unitofwork.py", line 299, in
execute
2010-10-24 07:40:46+0900 [-] rec.execute(self)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/unitofwork.py", line 443, in
execute
2010-10-24 07:40:46+0900 [-] uow
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/mapper.py", line 1800, in _save_obj
2010-10-24 07:40:46+0900 [-] execute(statement, params)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1157, in execute
2010-10-24 07:40:46+0900 [-] params)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1237, in
_execute_clauseelement
2010-10-24 07:40:46+0900 [-] return self.__execute_context(context)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1268, in
__execute_context
2010-10-24 07:40:46+0900 [-] context.parameters[0], context=context)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1367, in
_cursor_execute
2010-10-24 07:40:46+0900 [-] context)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1360, in
_cursor_execute
2010-10-24 07:40:46+0900 [-] context)
2010-10-24 07:40:46+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/default.py", line 288, in
do_execute
2010-10-24 07:40:46+0900 [-] cursor.execute(statement, parameters)
2010-10-24 07:40:46+0900 [-] OperationalError: (OperationalError) database is
locked u'UPDATE services SET updated_at=?, report_count=? WHERE services.id =
?' ('2010-10-23 22:40:41.095193', 287, 1)
libvir: Network Filtererror : internal error Could not get access to ACL tech
driver 'ebiptables'
ERROR:root:instance instance-3789518487: Failed to spawn
Traceback (most recent call last):
File "/opt/nova-2010.1/nova/compute/manager.py", line 92, in run_instance
yield self.driver.spawn(instance_ref)
File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 823,
in _inlineCallbacks
result = g.send(result)
File "/opt/nova-2010.1/nova/virt/libvirt_conn.py", line 234, in spawn
yield self._conn.createXML(xml, 0)
File "/usr/lib/python2.6/dist-packages/libvirt.py", line 1289, in createXML
if ret is None:raise libvirtError('virDomainCreateXML() failed', conn=self)
libvirtError: internal error Could not get access to ACL tech driver
'ebiptables'
2010-10-24 07:40:57+0900 [-] (root): ERROR instance instance-3789518487: Failed
to spawn
2010-10-24 07:40:57+0900 [-] Traceback (most recent call last):
2010-10-24 07:40:57+0900 [-] File "/opt/nova-2010.1/nova/compute/manager.py",
line 92, in run_instance
2010-10-24 07:40:57+0900 [-] yield self.driver.spawn(instance_ref)
2010-10-24 07:40:57+0900 [-] File
"/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 823, in
_inlineCallbacks
2010-10-24 07:40:57+0900 [-] result = g.send(result)
2010-10-24 07:40:57+0900 [-] File
"/opt/nova-2010.1/nova/virt/libvirt_conn.py", line 234, in spawn
2010-10-24 07:40:57+0900 [-] yield self._conn.createXML(xml, 0)
2010-10-24 07:40:57+0900 [-] File
"/usr/lib/python2.6/dist-packages/libvirt.py", line 1289, in createXML
2010-10-24 07:40:57+0900 [-] if ret is None:raise
libvirtError('virDomainCreateXML() failed', conn=self)
2010-10-24 07:40:57+0900 [-] libvirtError: internal error Could not get access
to ACL tech driver 'ebiptables'
libvir: QEMU error : Domain not found: no domain with matching name
'instance-3789518487'
2010-10-24 07:40:57+0900 [-] Unhandled error in Deferred:
2010-10-24 07:40:57+0900 [-] Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py",
line 307, in errback
self._startRunCallbacks(fail)
File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py",
line 354, in _startRunCallbacks
self._runCallbacks()
File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py",
line 371, in _runCallbacks
self.result = callback(self.result, *args, **kw)
File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py",
line 879, in gotResult
_inlineCallbacks(r, g, deferred)
--- <exception caught here> ---
File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py",
line 821, in _inlineCallbacks
result = result.throwExceptionIntoGenerator(g)
File "/usr/lib/python2.6/dist-packages/twisted/python/failure.py",
line 338, in throwExceptionIntoGenerator
return g.throw(self.type, self.value, self.tb)
File "/opt/nova-2010.1/nova/compute/manager.py", line 104, in
run_instance
self._update_state(context, instance_id)
File "/opt/nova-2010.1/nova/compute/manager.py", line 62, in
_update_state
state = self.driver.get_info(instance_ref.name)['state']
File "/opt/nova-2010.1/nova/virt/libvirt_conn.py", line 401, in
get_info
virt_dom = self._conn.lookupByName(instance_name)
File "/usr/lib/python2.6/dist-packages/libvirt.py", line 1442, in
lookupByName
if ret is None:raise libvirtError('virDomainLookupByName() failed',
conn=self)
libvirt.libvirtError: Domain not found: no domain with matching name
'instance-3789518487'
ERROR:root:Recovered model server connection!
2010-10-24 07:40:58+0900 [-] (root): ERROR Recovered model server connection!scheduler
2010-10-24 07:13:05+0900 [-] (root): ERROR model server went away
2010-10-24 07:13:05+0900 [-] Traceback (most recent call last):
2010-10-24 07:13:05+0900 [-] File "/opt/nova-2010.1/nova/service.py", line
178, in report_state
2010-10-24 07:13:05+0900 [-] {'report_count': service_ref['report_count'] +
1})
2010-10-24 07:13:05+0900 [-] File "/opt/nova-2010.1/nova/db/api.py", line
109, in service_update
2010-10-24 07:13:05+0900 [-] return IMPL.service_update(context,
service_id, values)
2010-10-24 07:13:05+0900 [-] File
"/opt/nova-2010.1/nova/db/sqlalchemy/api.py", line 98, in wrapper
2010-10-24 07:13:05+0900 [-] return f(*args, **kwargs)
2010-10-24 07:13:05+0900 [-] File
"/opt/nova-2010.1/nova/db/sqlalchemy/api.py", line 252, in service_update
2010-10-24 07:13:05+0900 [-] service_ref.save(session=session)
2010-10-24 07:13:05+0900 [-] File
"/opt/nova-2010.1/nova/db/sqlalchemy/models.py", line 66, in save
2010-10-24 07:13:05+0900 [-] session.flush()
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/session.py", line 1346, in flush
2010-10-24 07:13:05+0900 [-] self._flush(objects)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/session.py", line 1427, in _flush
2010-10-24 07:13:05+0900 [-] flush_context.execute()
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/unitofwork.py", line 299, in
execute
2010-10-24 07:13:05+0900 [-] rec.execute(self)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/unitofwork.py", line 443, in
execute
2010-10-24 07:13:05+0900 [-] uow
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/orm/mapper.py", line 1800, in _save_obj
2010-10-24 07:13:05+0900 [-] execute(statement, params)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1157, in execute
2010-10-24 07:13:05+0900 [-] params)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1237, in
_execute_clauseelement
2010-10-24 07:13:05+0900 [-] return self.__execute_context(context)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1268, in
__execute_context
2010-10-24 07:13:05+0900 [-] context.parameters[0], context=context)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1367, in
_cursor_execute
2010-10-24 07:13:05+0900 [-] context)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/base.py", line 1360, in
_cursor_execute
2010-10-24 07:13:05+0900 [-] context)
2010-10-24 07:13:05+0900 [-] File
"/usr/lib/pymodules/python2.6/sqlalchemy/engine/default.py", line 288, in
do_execute
2010-10-24 07:13:05+0900 [-] cursor.execute(statement, parameters)
2010-10-24 07:13:05+0900 [-] OperationalError: (OperationalError) database is
locked u'UPDATE services SET updated_at=?, report_count=? WHERE services.id =
?' ('2010-10-23 22:13:00.522920', 130, 3)
ERROR:root:Recovered model server connection!
2010-10-24 07:13:51+0900 [-] (root): ERROR Recovered model server connection!
_______________________________________________
Mailing list: https://launchpad.net/~nova
Post to : [email protected]
Unsubscribe : https://launchpad.net/~nova
More help : https://help.launchpad.net/ListHelp
