lxc instance termination error: permission denied when killing a process

[Andreas Hasenack]

nova-compute-lxc 1:2014.1.1-0ubuntu1
trusty
deployed with the openstack charms for trusty

After going through bug #1205525 and #1352540 to get nova compute configured to use containers (lxc) as hypervisors, I'm hitting a problem when terminating such an instance.

It remains in the ERROR state and nova show shows this backtrace:
| fault | {"message": "Failed to kill process 15767: Permission denied", "code": 500, "details": " File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 290, in decorated_function |
| | return function(self, context, *args, **kwargs) |
| | File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 2251, in terminate_instance |
| | do_terminate_instance(instance, bdms) |
| | File \"/usr/lib/python2.7/dist-packages/nova/openstack/common/lockutils.py\", line 249, in inner |
| | return f(*args, **kwargs) |
| | File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 2249, in do_terminate_instance |
| | self._set_instance_error_state(context, instance['uuid']) |
| | File \"/usr/lib/python2.7/dist-packages/nova/openstack/common/excutils.py\", line 68, in __exit__ |
| | six.reraise(self.type_, self.value, self.tb) |
| | File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 2239, in do_terminate_instance |
| | reservations=reservations) |
| | File \"/usr/lib/python2.7/dist-packages/nova/hooks.py\", line 103, in inner |
| | rv = f(*args, **kwargs) |
| | File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 2209, in _delete_instance |
| | user_id=user_id) |
| | File \"/usr/lib/python2.7/dist-packages/nova/openstack/common/excutils.py\", line 68, in __exit__ |
| | six.reraise(self.type_, self.value, self.tb) |
| | File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 2179, in _delete_instance |
| | self._shutdown_instance(context, db_inst, bdms) |
| | File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 2114, in _shutdown_instance |
| | requested_networks) |
| | File \"/usr/lib/python2.7/dist-packages/nova/openstack/common/excutils.py\", line 68, in __exit__ |
| | six.reraise(self.type_, self.value, self.tb) |
| | File \"/usr/lib/python2.7/dist-packages/nova/compute/manager.py\", line 2104, in _shutdown_instance |
| | block_device_info) |
| | File \"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py\", line 959, in destroy |
| | self._destroy(instance) |
| | File \"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py\", line 916, in _destroy |
| | instance=instance) |
| | File \"/usr/lib/python2.7/dist-packages/nova/openstack/common/excutils.py\", line 68, in __exit__ |
| | six.reraise(self.type_, self.value, self.tb) |
| | File \"/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py\", line 888, in _destroy |
| | virt_dom.destroy() |
| | File \"/usr/lib/python2.7/dist-packages/eventlet/tpool.py\", line 179, in doit |
| | result = proxy_call(self._autowrap, f, *args, **kwargs) |
| | File \"/usr/lib/python2.7/dist-packages/eventlet/tpool.py\", line 139, in proxy_call |
| | rv = execute(f,*args,**kwargs) |
| | File \"/usr/lib/python2.7/dist-packages/eventlet/tpool.py\", line 77, in tworker |
| | rv = meth(*args,**kwargs) |
| | File \"/usr/lib/python2.7/dist-packages/libvirt.py\", line 918, in destroy |
| | if ret == -1: raise libvirtError ('virDomainDestroy() failed', dom=self) |
| | ", "created": "2014-08-04T22:06:11Z"}

The process listing remains like this on that compute node:
nova 23110 0.3 0.3 1752292 62984 ? Ssl 19:49 0:28 /usr/bin/python /usr/bin/nova-compute --config-file=/etc/nova/nova.conf --config-file=/etc/nova/nova-com
root 14153 0.6 0.0 1275720 13272 ? Ssl 22:02 0:04 /usr/bin/qemu-nbd -c /dev/nbd13 /var/lib/nova/instances/e128593c-1756-4d7a-b8c4-51500bb89314/disk
root 14278 0.1 0.0 37212 6628 ? Ss 22:02 0:00 /sbin/init
root 15767 0.0 0.0 10224 2408 ? Ss 22:02 0:00 \_ dhclient -1 -v -pf /run/dhclient.eth0.pid -lf /var/lib/dhcp/dhclient.eth0.leases eth0
message+ 16032 0.0 0.0 39116 1044 ? Ss 22:02 0:00 \_ dbus-daemon --system --fork
root 16072 0.0 0.0 43540 1768 ? Ss 22:02 0:00 \_ /lib/systemd/systemd-logind
root 16156 0.0 0.0 61364 3044 ? Ss 22:02 0:00 \_ /usr/sbin/sshd -D
root 16161 0.0 0.0 4368 660 ? Ss 22:02 0:00 \_ acpid -c /etc/acpi/events -s /var/run/acpid.socket
root 16162 0.0 0.0 23656 880 ? Ss 22:02 0:00 \_ cron
daemon 16165 0.0 0.0 19140 160 ? Ss 22:02 0:00 \_ atd
root 16196 0.0 0.0 19292 808 ? Ss 22:02 0:00 \_ /usr/sbin/irqbalance
syslog 16230 0.0 0.0 260076 1140 ? Ssl 22:02 0:00 \_ rsyslogd
root 19222 0.0 0.0 49572 1348 ? Ss 22:06 0:00 \_ /lib/systemd/systemd-udevd --daemon
root 19225 0.0 0.0 12788 844 pts/0 Ss+ 22:06 0:00 \_ /sbin/getty -8 38400 tty1
root 19245 0.0 0.0 19476 400 ? S 22:06 0:00 \_ upstart-udev-bridge --daemon
root 19248 0.0 0.0 15260 640 ? S 22:06 0:00 \_ upstart-socket-bridge --daemon
root 19251 0.0 0.0 15276 404 ? S 22:06 0:00 \_ upstart-file-bridge --daemon
root 20505 0.0 0.0 12788 884 ? Ss 22:13 0:00 \_ /sbin/getty -8 38400 tty4
root 20507 0.0 0.0 12788 884 ? Ss 22:13 0:00 \_ /sbin/getty -8 38400 tty2
root 20509 0.0 0.0 12788 888 ? Ss 22:13 0:00 \_ /sbin/getty -8 38400 tty3

The init (pid 14278) had as its parents some nova process that created and started the container. That one is gone.

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Stepan G. Fedorov (stfedorov)]

I have the same problem. In dmesg on virtualization host I see lines like next one:

[ 893.703227] type=1400 audit(1442496602.701:39): apparmor="DENIED" operation="signal" profile="/sbin/dhclient" pid=1510 comm="libvirtd" requested_mask="receive" denied_mask="receive" signal=term peer="/usr/sbin/libvirtd"