[systemd-devel] Error handling problems with systemd-machined

[Daniel P. Berrange]

On Wed, Jul 24, 2013 at 02:13:30PM +0100, Daniel P. Berrange wrote:
> I'm working on integrating libvirt with systemd-machined for cgroups
> setup and hitting a number of problems

A further discovery - if I pass "MemoryAccounting=yes" as a scope
property, then the process gets immediately killed by the OOM
killer

Jul 24 14:30:26 localhost systemd[1]: Starting Container lxc-busy3.
Jul 24 14:30:26 localhost systemd[1]: Started Container lxc-busy3.
Jul 24 14:30:26 localhost systemd-machined[14756]: New machine lxc-busy3.
Jul 24 14:30:26 localhost kernel: [ 4326.760834] libvirt_lxc invoked oom-killer: gfp_mask=0xd0, order=0, oom_score_adj=0
Jul 24 14:30:26 localhost kernel: [ 4326.760839] libvirt_lxc cpuset=/ mems_allowed=0
Jul 24 14:30:26 localhost kernel: [ 4326.760841] Pid: 26196, comm: libvirt_lxc Not tainted 3.9.0-0.rc1.git0.1.fc19.x86_64 #1
Jul 24 14:30:26 localhost kernel: [ 4326.760843] Call Trace:
Jul 24 14:30:26 localhost kernel: [ 4326.760852]  [<ffffffff810d2da6>] ? cpuset_print_task_mems_allowed+0x96/0xc0
Jul 24 14:30:26 localhost kernel: [ 4326.760857]  [<ffffffff8163cc20>] dump_header+0x7a/0x1b3
Jul 24 14:30:26 localhost kernel: [ 4326.760860]  [<ffffffff8113242e>] oom_kill_process+0x1be/0x310
Jul 24 14:30:26 localhost kernel: [ 4326.760864]  [<ffffffff811913d5>] __mem_cgroup_try_charge+0xad5/0xb20
Jul 24 14:30:26 localhost kernel: [ 4326.760866]  [<ffffffff81191c80>] ? mem_cgroup_charge_common+0x120/0x120
Jul 24 14:30:26 localhost kernel: [ 4326.760869]  [<ffffffff81191be6>] mem_cgroup_charge_common+0x86/0x120
Jul 24 14:30:26 localhost kernel: [ 4326.760871]  [<ffffffff8119349b>] mem_cgroup_newpage_charge+0x4b/0xb0
Jul 24 14:30:26 localhost kernel: [ 4326.760874]  [<ffffffff8115954c>] handle_pte_fault+0x71c/0xa30
Jul 24 14:30:26 localhost kernel: [ 4326.760877]  [<ffffffff81217039>] ? ext4_file_write+0x99/0x3f0
Jul 24 14:30:26 localhost kernel: [ 4326.760880]  [<ffffffff815223e2>] ? __sys_recvmsg+0x112/0x290
Jul 24 14:30:26 localhost kernel: [ 4326.760882]  [<ffffffff8115a671>] handle_mm_fault+0x291/0x660
Jul 24 14:30:26 localhost kernel: [ 4326.760887]  [<ffffffff816498e1>] __do_page_fault+0x171/0x4f0
Jul 24 14:30:26 localhost kernel: [ 4326.760890]  [<ffffffff811d7bd1>] ? fsnotify+0x241/0x320
Jul 24 14:30:26 localhost kernel: [ 4326.760892]  [<ffffffff81649c6e>] do_page_fault+0xe/0x10
Jul 24 14:30:26 localhost kernel: [ 4326.760894]  [<ffffffff816493aa>] do_async_page_fault+0x2a/0xa0
Jul 24 14:30:26 localhost kernel: [ 4326.760896]  [<ffffffff81646388>] async_page_fault+0x28/0x30
Jul 24 14:30:26 localhost kernel: [ 4326.760899] Task in /machine.slice/machine-lxc\x2dbusy3.scope killed as a result of limit of /machine.slice/machine-lxc\x2dbusy3.scope
Jul 24 14:30:26 localhost kernel: [ 4326.760901] memory: usage 0kB, limit 0kB, failcnt 7
Jul 24 14:30:26 localhost kernel: [ 4326.760920] memory+swap: usage 0kB, limit 9007199254740991kB, failcnt 0
Jul 24 14:30:26 localhost kernel: [ 4326.760921] kmem: usage 0kB, limit 9007199254740991kB, failcnt 0
Jul 24 14:30:26 localhost kernel: [ 4326.760923] Memory cgroup stats for /machine.slice/machine-lxc\x2dbusy3.scope: cache:0KB rss:0KB mapped_file:0KB inactive_anon:0KB active_anon:0KB inactive_file:0KB active_file:0KB unevictable:0KB
Jul 24 14:30:26 localhost kernel: [ 4326.760931] [ pid ]   uid  tgid total_vm      rss nr_ptes swapents oom_score_adj name
Jul 24 14:30:26 localhost kernel: [ 4326.760956] [26196]     0 26196    29225     1732      56        0             0 libvirt_lxc
Jul 24 14:30:26 localhost kernel: [ 4326.760958] Memory cgroup out of memory: Kill process 26196 (libvirt_lxc) score 0 or sacrifice child
Jul 24 14:30:26 localhost kernel: [ 4326.761064] Killed process 26196 (libvirt_lxc) total-vm:116900kB, anon-rss:3256kB, file-rss:3672kB
Jul 24 14:30:26 localhost kernel: [ 4326.776462] virbr0: port 2(veth0) entered disabled state
Jul 24 14:30:26 localhost kernel: [ 4326.777526] device veth0 left promiscuous mode
Jul 24 14:30:26 localhost kernel: [ 4326.777548] virbr0: port 2(veth0) entered disabled state
Jul 24 14:30:26 localhost avahi-daemon[431]: Withdrawing workstation service for veth1.
Jul 24 14:30:26 localhost avahi-daemon[431]: Withdrawing workstation service for veth0.
Jul 24 14:30:26 localhost systemd-machined[14756]: Machine lxc-busy3 terminated.

It looks like when passing MemoryAccount=yes, then systemd is accidentally
initializing the cgroup memory limit to 0 kb, with obvious results.

Regards,
Daniel
-- 
|: http://berrange.com      -o-    http://www.flickr.com/photos/dberrange/ :|
|: http://libvirt.org              -o-             http://virt-manager.org :|
|: http://autobuild.org       -o-         http://search.cpan.org/~danberr/ :|
|: http://entangle-photo.org       -o-       http://live.gnome.org/gtk-vnc :|