| Summary: | Occasional crash in glance-api after creating an instance | ||
|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Angus Salkeld <asalkeld> |
| Component: | openstack-glance | Assignee: | Mark McLoughlin <markmc> |
| Status: | CLOSED NOTABUG | QA Contact: | Fedora Extras Quality Assurance <extras-qa> |
| Severity: | unspecified | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 16 | CC: | akscram, alexander.sakhnov, asalkeld, bfilippov, jonathansteffan, markmc, matt_domsch, mlvov, p, rbryant, rkukura, sdake |
| Target Milestone: | --- | ||
| Target Release: | --- | ||
| Hardware: | x86_64 | ||
| OS: | Linux | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Bug Fix | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2011-12-01 01:03:52 UTC | Type: | --- |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
In /var/log/nova/compute.log is ... 2011-11-22 22:00:22,363 WARNING nova.compute.manager [-] Error during power_state sync: (OperationalError) database is locked (and heaps of sql) this might be the sqlite problem (I'll change over to mysql and report back) I still get the following crash: Nov 29 09:40:36 troll glance-api[29898]: Traceback (most recent call last): Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib/python2.7/site-packages/eventlet/greenpool.py", line 80, in _spawn_n_impl Nov 29 09:40:36 troll glance-api[29898]: func(*args, **kwargs) Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 514, in process_request Nov 29 09:40:36 troll glance-api[29898]: proto = self.protocol(socket, address, self) Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib64/python2.7/SocketServer.py", line 641, in __init__ Nov 29 09:40:36 troll glance-api[29898]: self.finish() Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 456, in finish Nov 29 09:40:36 troll glance-api[29898]: BaseHTTPServer.BaseHTTPRequestHandler.finish(self) Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib64/python2.7/SocketServer.py", line 694, in finish Nov 29 09:40:36 troll glance-api[29898]: self.wfile.flush() Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib64/python2.7/socket.py", line 303, in flush Nov 29 09:40:36 troll glance-api[29898]: self._sock.sendall(view[write_offset:write_offset+buffer_size]) Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib/python2.7/site-packages/eventlet/greenio.py", line 283, in sendall Nov 29 09:40:36 troll glance-api[29898]: tail = self.send(data, flags) Nov 29 09:40:36 troll glance-api[29898]: File "/usr/lib/python2.7/site-packages/eventlet/greenio.py", line 269, in send Nov 29 09:40:36 troll glance-api[29898]: total_sent += fd.send(data[total_sent:], flags) Nov 29 09:40:36 troll glance-api[29898]: error: [Errno 32] Broken pipe (Just to avoid this: http://xkcd.com/979/ :-) According to Angus, the underlying issue here turned out to be that the nova-volumes service was failing on startup because the loopback image based nova-volumes LVM volume group wasn't available. |
Description of problem: After calling: su -c ". ./novarc && euca-run-instances assy1-F15 -k nova_key" asalkeld (from python - pacemaker-cloud) I get a crash in glance-api. After this the VM is unusable (it can't boot). Version-Release number of selected component (if applicable): openstack-glance-2011.3-1.fc16.noarch How reproducible: Occasional Steps to Reproduce: I'll add more as I can (just capturing for now). Note: selinux is permissive [snip from logs] Nov 22 13:38:45 localhost assy1-F16 336: [INFO] starting foo:assy1-F16 Nov 22 13:38:45 localhost assy1-F16 338: [INFO] cmd: su -c ". ./novarc && euca-run-instances assy1-F16 -k nova_key" asalkeld Nov 22 13:38:47 localhost assy1-F16 341: [INFO] cmd out: RESERVATION#011r-0u8kzn12#011foo#011default#012INSTANCE#011i-00000026#011ami-00000020#011#011#011pending#011nova_key (foo, None)#0110#011#011m1.small#0112011-11-22T02:38:46Z#011unknown zone#011ami-00000000#011ami-00000000 Nov 22 13:38:47 localhost assy1-F15 336: [INFO] starting foo:assy1-F15 Nov 22 13:38:47 localhost assy1-F15 336: [INFO] starting foo:assy1-F15 Nov 22 13:38:47 localhost assy1-F15 338: [INFO] cmd: su -c ". ./novarc && euca-run-instances assy1-F15 -k nova_key" asalkeld Nov 22 13:38:47 localhost assy1-F15 338: [INFO] cmd: su -c ". ./novarc && euca-run-instances assy1-F15 -k nova_key" asalkeld Nov 22 13:38:47 localhost dpe[17094]: MAIN [debug] start result: 0 Nov 22 13:38:48 localhost assy1-F15 341: [INFO] cmd out: RESERVATION#011r-97pjyq35#011foo#011default#012INSTANCE#011i-00000027#011ami-00000021#011#011#011pending#011nova_key (foo, None)#0110#011#011m1.small#0112011-11-22T02:38:47Z#011unknown zone#011ami-00000000#011ami-00000000 Nov 22 13:38:48 localhost assy1-F15 341: [INFO] cmd out: RESERVATION#011r-97pjyq35#011foo#011default#012INSTANCE#011i-00000027#011ami-00000021#011#011#011pending#011nova_key (foo, None)#0110#011#011m1.small#0112011-11-22T02:38:47Z#011unknown zone#011ami-00000000#011ami-00000000 Nov 22 13:38:48 localhost dnsmasq[11912]: read /etc/hosts - 2 addresses Nov 22 13:38:48 localhost dnsmasq-dhcp[11912]: read /var/lib/nova/networks/nova-br0.conf Nov 22 13:38:48 localhost dpe[17094]: MAIN [debug] start result: 0 Nov 22 13:38:49 localhost dnsmasq[11912]: read /etc/hosts - 2 addresses Nov 22 13:38:49 localhost dnsmasq-dhcp[11912]: read /var/lib/nova/networks/nova-br0.conf Nov 22 13:38:51 localhost kernel: [364087.941038] type=1400 audit(1321929531.542:36): avc: denied { search } for pid=11720 comm="glance-api" name="images" dev=sda5 ino=3278046 scontext=system_u:system_r:glance_api_t:s0 tcontext=system_u:object_r:virt_image_t:s0 tclass=dir Nov 22 13:38:51 localhost kernel: [364087.941281] type=1400 audit(1321929531.543:37): avc: denied { getattr } for pid=11720 comm="glance-api" path="/var/lib/libvirt/images/assy1-F16.qcow2" dev=sda5 ino=3277382 scontext=system_u:system_r:glance_api_t:s0 tcontext=system_u:object_r:virt_image_t:s0 tclass=file Nov 22 13:38:51 localhost kernel: [364087.941363] type=1400 audit(1321929531.543:38): avc: denied { read } for pid=11720 comm="glance-api" name="assy1-F16.qcow2" dev=sda5 ino=3277382 scontext=system_u:system_r:glance_api_t:s0 tcontext=system_u:object_r:virt_image_t:s0 tclass=file Nov 22 13:38:51 localhost kernel: [364087.941386] type=1400 audit(1321929531.543:39): avc: denied { open } for pid=11720 comm="glance-api" name="assy1-F16.qcow2" dev=sda5 ino=3277382 scontext=system_u:system_r:glance_api_t:s0 tcontext=system_u:object_r:virt_image_t:s0 tclass=file Nov 22 13:38:51 localhost glance-api[11720]: Traceback (most recent call last): Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/greenpool.py", line 80, in _spawn_n_impl Nov 22 13:38:51 localhost glance-api[11720]: func(*args, **kwargs) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 514, in process_request Nov 22 13:38:51 localhost glance-api[11720]: proto = self.protocol(socket, address, self) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib64/python2.7/SocketServer.py", line 641, in __init__ Nov 22 13:38:51 localhost glance-api[11720]: self.finish() Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 456, in finish Nov 22 13:38:51 localhost glance-api[11720]: BaseHTTPServer.BaseHTTPRequestHandler.finish(self) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib64/python2.7/SocketServer.py", line 694, in finish Nov 22 13:38:51 localhost glance-api[11720]: self.wfile.flush() Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib64/python2.7/socket.py", line 303, in flush Nov 22 13:38:51 localhost glance-api[11720]: self._sock.sendall(view[write_offset:write_offset+buffer_size]) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/greenio.py", line 283, in sendall Nov 22 13:38:51 localhost glance-api[11720]: tail = self.send(data, flags) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/greenio.py", line 269, in send Nov 22 13:38:51 localhost glance-api[11720]: total_sent += fd.send(data[total_sent:], flags) Nov 22 13:38:51 localhost glance-api[11720]: error: [Errno 32] Broken pipe Nov 22 13:38:51 localhost glance-api[11720]: Traceback (most recent call last): Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/greenpool.py", line 80, in _spawn_n_impl Nov 22 13:38:51 localhost glance-api[11720]: func(*args, **kwargs) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 514, in process_request Nov 22 13:38:51 localhost glance-api[11720]: proto = self.protocol(socket, address, self) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib64/python2.7/SocketServer.py", line 641, in __init__ Nov 22 13:38:51 localhost glance-api[11720]: self.finish() Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/wsgi.py", line 456, in finish Nov 22 13:38:51 localhost glance-api[11720]: BaseHTTPServer.BaseHTTPRequestHandler.finish(self) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib64/python2.7/SocketServer.py", line 694, in finish Nov 22 13:38:51 localhost glance-api[11720]: self.wfile.flush() Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib64/python2.7/socket.py", line 303, in flush Nov 22 13:38:51 localhost glance-api[11720]: self._sock.sendall(view[write_offset:write_offset+buffer_size]) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/greenio.py", line 283, in sendall Nov 22 13:38:51 localhost glance-api[11720]: tail = self.send(data, flags) Nov 22 13:38:51 localhost glance-api[11720]: File "/usr/lib/python2.7/site-packages/eventlet/greenio.py", line 269, in send Nov 22 13:38:51 localhost glance-api[11720]: total_sent += fd.send(data[total_sent:], flags) Nov 22 13:38:51 localhost glance-api[11720]: error: [Errno 32] Broken pipe Nov 22 13:38:53 localhost kernel: [364089.765577] nbd14: NBD_DISCONNECT Nov 22 13:38:53 localhost kernel: [364089.765703] nbd14: Receive control failed (result -32) Nov 22 13:38:53 localhost kernel: [364089.765837] nbd14: queue cleared Nov 22 13:38:53 localhost kernel: [364089.773628] nbd15: NBD_DISCONNECT Nov 22 13:38:53 localhost kernel: [364089.773779] nbd15: Receive control failed (result -32) Nov 22 13:38:53 localhost kernel: [364089.774379] nbd15: queue cleared