Description of problem:


virt-customize --selinux-relabel on a f30 VM ends unexpectedly due to oom


Version-Release number of selected component (if applicable):

1.40.2-4.fc30.x86_64

How reproducible:

100%

Additional info:

[  15.3] SELinux relabelling
libguestfs: trace: is_file "/usr/sbin/load_policy" "followsymlinks:true"

guestfsd: <= is_file (0x25) request length 72 bytes
chroot: /sysroot: running 'is_file: /usr/sbin/load_policy'
libguestfs: trace: is_file = 1
libguestfs: trace: is_file "/etc/selinux/config" "followsymlinks:true"
guestfsd: => is_file (0x25) took 0.00 secs
guestfsd: <= is_file (0x25) request length 68 bytes
chroot: /sysroot: running 'is_file: /etc/selinux/config'
libguestfs: trace: is_file = 1
libguestfs: trace: feature_available "selinuxrelabel"
libguestfs: trace: internal_feature_available "selinuxrelabel"
guestfsd: => is_file (0x25) took 0.00 secs
guestfsd: <= internal_feature_available (0x1ca) request length 60 bytes
guestfsd: => internal_feature_available (0x1ca) took 0.00 secs
libguestfs: trace: internal_feature_available = 0
libguestfs: trace: feature_available = 1
libguestfs: trace: aug_init "/" 48
guestfsd: <= aug_init (0x10) request length 52 bytes
libguestfs: trace: aug_init = 0
libguestfs: trace: aug_rm "/augeas/load/*["/etc/selinux/config/" !~ regexp('^') + glob(incl) + regexp('/.*')]"
guestfsd: => aug_init (0x10) took 0.45 secs
guestfsd: <= aug_rm (0x16) request length 128 bytes
libguestfs: trace: aug_rm = 1538
libguestfs: trace: aug_load
guestfsd: => aug_rm (0x16) took 0.01 secs
guestfsd: <= aug_load (0x1b) request length 40 bytes
libguestfs: trace: aug_load = 0
libguestfs: trace: aug_ls "/files/etc/selinux/config"
guestfsd: => aug_load (0x1b) took 0.04 secs
guestfsd: <= aug_ls (0x1c) request length 72 bytes
libguestfs: trace: aug_ls = ["/files/etc/selinux/config/#comment[1]", "/files/etc/selinux/config/#comment[2]", "/files/etc/selinux/config/#comment[3]", "/files/etc/selinux/config/#comment[4]", "/files/etc/selinux/config/#comment[5]", "/files/etc/selinux/config/#comment[6]", "/files/etc/selinux/config/#comment[7]", "/files/etc/selinux/config/#comment[8]", "/files/etc/selinux/config/#comment[9]", "/files/etc/selinux/config/SELINUX", "/files/etc/selinux/config/SELINUXTYPE"]
libguestfs: trace: aug_get "/files/etc/selinux/config/SELINUXTYPE"
guestfsd: => aug_ls (0x1c) took 0.00 secs
guestfsd: <= aug_get (0x13) request length 84 bytes
guestfsd: => aug_get (0x13) took 0.00 secs
libguestfs: trace: aug_get = "targeted"
libguestfs: trace: aug_close
guestfsd: <= aug_close (0x1a) request length 40 bytes
libguestfs: trace: aug_close = 0
libguestfs: trace: grep "vdagentd.\pid" "/etc/selinux/targeted/contexts/files/file_contexts" "fixed:true"
guestfsd: => aug_close (0x1a) took 0.01 secs
guestfsd: <= grep (0x97) request length 132 bytes
commandrvf: stdout=y stderr=y flags=0x20004
commandrvf: grep -F vdagentd.\pid
libguestfs: trace: grep = []
libguestfs: trace: selinux_relabel "/etc/selinux/targeted/contexts/files/file_contexts" "/" "force:true"
guestfsd: => grep (0x97) took 0.00 secs
guestfsd: <= selinux_relabel (0x1d3) request length 108 bytes
commandrvf: stdout=n stderr=y flags=0x0
commandrvf: setfiles -m
usage:  setfiles [-diIDlmnpqvFW] [-e excludedir] [-r alt_root_path] spec_file pathname...
usage:  setfiles [-diIDlmnpqvFW] [-e excludedir] [-r alt_root_path] spec_file -f filename
usage:  setfiles -s [-diIDlmnpqvFW] spec_file
usage:  setfiles -c policyfile spec_file
commandrvf: stdout=n stderr=y flags=0x0
commandrvf: setfiles -F -e /sysroot/dev -e /sysroot/proc -e /sysroot/selinux -e /sysroot/sys -m -r /sysroot -v /sysroot/etc/selinux/targeted/contexts/files/file_contexts /sysroot/
Can't stat exclude path "/sysroot/selinux", No such file or directory - ignoring.
[  121.049427] setfiles invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0
[  121.050819] CPU: 0 PID: 540 Comm: setfiles Not tainted 5.1.20-300.fc30.x86_64+debug #1
[  121.051833] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS ?-20190731_050339-eff5788c21134714b96e25976602540b-3.fc30 04/01/2014
[  121.053440] Call Trace:
[  121.053758]  dump_stack+0x85/0xc0
[  121.054206]  dump_header+0x51/0x4c8
[  121.054662]  ? _raw_spin_unlock_irqrestore+0x4b/0x60
[  121.055315]  ? lockdep_hardirqs_on+0xf0/0x180
[  121.055868]  oom_kill_process.cold+0xb/0x10
[  121.056443]  out_of_memory+0x1d4/0x560
[  121.056916]  __alloc_pages_slowpath+0xccf/0x1030
[  121.057547]  __alloc_pages_nodemask+0x37f/0x400
[  121.058119]  pagecache_get_page+0xad/0x3c0
[  121.058682]  filemap_fault+0x5a7/0xcd0
[  121.059153]  ? find_held_lock+0x32/0x90
[  121.059640]  ? ext4_filemap_fault+0x28/0x42
[  121.060204]  ext4_filemap_fault+0x30/0x42
[  121.060719]  __do_fault+0x36/0x1f0
[  121.061180]  __handle_mm_fault+0x1055/0x1730
[  121.061733]  handle_mm_fault+0x18a/0x390
[  121.062270]  do_user_addr_fault+0x1f9/0x480
[  121.062808]  do_page_fault+0x33/0x210
[  121.063312]  ? async_page_fault+0x8/0x30
[  121.063806]  async_page_fault+0x1e/0x30
[  121.064329] RIP: 0033:0x7fae70998900
[  121.064779] Code: Bad RIP value.
[  121.065186] RSP: 002b:00007fff7f7bf8f8 EFLAGS: 00010206
[  121.065873] RAX: 0000000000000000 RBX: 00005638003addc0 RCX: 00005637fed92f4e
[  121.066798] RDX: 00007fae70b4e99a RSI: 0000000000000000 RDI: 00005638003addd0
[  121.067705] RBP: 00000000ffffffff R08: 0000000000000000 R09: 0000000000000001
[  121.068595] R10: 0000000000000000 R11: 00007fff7f7ba8b8 R12: 0000000000000000
[  121.069519] R13: 00000000000010b5 R14: 00007fae7059d518 R15: 000000000000000f
[  121.070477] Mem-Info:
[  121.070776] active_anon:28208 inactive_anon:13 isolated_anon:0
[  121.070776]  active_file:13 inactive_file:19 isolated_file:0
[  121.070776]  unevictable:0 dirty:0 writeback:0 unstable:0
[  121.070776]  slab_reclaimable:133751 slab_unreclaimable:4419
[  121.070776]  mapped:1 shmem:30 pagetables:119 bounce:0
[  121.070776]  free:9525 free_pcp:171 free_cma:0
[  121.074833] Node 0 active_anon:112832kB inactive_anon:52kB active_file:52kB inactive_file:76kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:4kB dirty:0kB writeback:0kB shmem:120kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? yes
[  121.078166] Node 0 DMA free:3508kB min:788kB low:984kB high:1180kB active_anon:708kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB writepending:0kB present:15992kB managed:15908kB mlocked:0kB kernel_stack:0kB pagetables:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB
[  121.081494] lowmem_reserve[]: 0 681 681 681 681
[  121.082069] Node 0 DMA32 free:34592kB min:34628kB low:43284kB high:51940kB active_anon:112124kB inactive_anon:52kB active_file:52kB inactive_file:76kB unevictable:0kB writepending:0kB present:770040kB managed:709392kB mlocked:0kB kernel_stack:992kB pagetables:476kB bounce:0kB free_pcp:684kB local_pcp:684kB free_cma:0kB
[  121.085649] lowmem_reserve[]: 0 0 0 0 0
[  121.086163] Node 0 DMA: 9*4kB (UME) 26*8kB (UME) 22*16kB (UM) 13*32kB (UM) 7*64kB (UME) 2*128kB (ME) 1*256kB (U) 1*512kB (E) 1*1024kB (E) 0*2048kB 0*4096kB = 3508kB
[  121.088080] Node 0 DMA32: 836*4kB (UME) 1416*8kB (UME) 1245*16kB (UME) 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 34592kB
[  121.089740] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1048576kB
[  121.090860] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[  121.091962] 59 total pagecache pages
[  121.092423] 0 pages in swap cache
[  121.092888] Swap cache stats: add 0, delete 0, find 0/0
[  121.093575] Free swap  = 0kB
[  121.093961] Total swap = 0kB
[  121.094332] 196508 pages RAM
[  121.094733] 0 pages HighMem/MovableOnly
[  121.095239] 15183 pages reserved
[  121.095674] 0 pages cma reserved
[  121.096119] 0 pages hwpoisoned
[  121.096524] Tasks state (memory values in pages):
[  121.097152] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
[  121.098360] [    234]     0   234     7536      316    81920        0         -1000 systemd-udevd
[  121.099668] [    288]     0   288     3803      477    65536        0             0 dhclient
[  121.100770] [    293]     0   293    21987       68    61440        0             0 lvmetad
[  121.101860] [    327]     0   327    42202    18025   249856        0             0 guestfsd
[  121.102946] [    540]     0   540    10472     9225   126976        0             0 setfiles
[  121.104043] oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/,task=guestfsd,pid=327,uid=0
[  121.105939] Out of memory: Killed process 327 (guestfsd) total-vm:168808kB, anon-rss:72100kB, file-rss:0kB, shmem-rss:0kB
[  121.132080] oom_reaper: reaped process 327 (guestfsd), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
/init: line 255:   327 Killed                  $cmd
+ sync
+ test '' = 1
+ reboot -f
Rebooting.
[  121.217447] Unregister pv shared memory for cpu 0
[  121.218328] sd 2:0:1:0: [sdb] Synchronizing SCSI cache
[  121.219262] sd 2:0:0:0: [sda] Synchronizing SCSI cache
[  121.220636] reboot: Restarting system
[  121.221138] reboot: machine restart
libguestfs: child_cleanup: 0x563fe0a374f0: child process died
libguestfs: calling virDomainDestroy flags=0
libguestfs: trace: selinux_relabel = -1 (error)
virt-customize: error: libguestfs error: appliance closed the connection 
unexpectedly, see earlier error messages

If reporting bugs, run virt-customize with debugging enabled and include 
the complete output:

  virt-customize -v -x [...]
libguestfs: trace: close
libguestfs: closing guestfs handle 0x563fe0a374f0 (state 0)
libguestfs: command: run: rm
libguestfs: command: run: \ -rf /tmp/libguestfsMHahl5
libguestfs: command: run: rm
libguestfs: command: run: \ -rf /run/user/1000/libguestfslSm3Ef