bug#27684: Can't build disk-images or vm-images on core-updates

[Leo Famulari]

Both `guix system disk-image` and `guix system vm-image` fail for me on
core-updates. Read-only VMs seem to work fine. I'm currently checking to
see if it fails when building on GuixSD.

I'm using x86_64-linux on a foreign distro with Linux 4.12.1. The host
filesystem is ext4. I'm building a kernel on GuixSD so I can test it
there.

I changed the value of 'memory-size' to 4096 (4 GB) in (gnu build vm)
for some of my tests, but the problem persists. I also tried using QEMU
without any of the bug-fix patches, but no joy.

Your help is requested! I'll continue debugging, but I'm sort of "in the
dark" right now.

The disk-image build seems to fail at the point shown below (full logs
attached), which occurs after copying files into the image for a while:

[  108.852534] init: page allocation stalls for 10004ms, order:0, 
mode:0x1400040(GFP_NOFS), nodemask=(null)
[  108.853423] init cpuset=/ mems_allowed=0
[  108.853781] CPU: 0 PID: 1 Comm: init Not tainted 4.12.0-gnu #1
[  108.854356] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 
rel-1.10.2-0-g5f4c7b1-prebuilt.qemu-project.org 04/01/2014
[  108.855441] Call Trace:
[  108.855825]  dump_stack+0x63/0x82
[  108.856355]  warn_alloc+0x114/0x1b0
[  108.856838]  __alloc_pages_slowpath+0x91d/0xd90
[  108.857265]  __alloc_pages_nodemask+0x245/0x260
[  108.857937]  alloc_pages_current+0x95/0x140
[  108.858581]  __page_cache_alloc+0xb5/0xc0
[  108.859194]  pagecache_get_page+0x88/0x220
[  108.859582]  ext4_mb_load_buddy_gfp+0x214/0x400
[  108.860030]  ext4_mb_regular_allocator+0x177/0x470
[  108.860460]  ext4_mb_new_blocks+0x619/0xae0
[  108.860846]  ? __kmalloc+0x1c7/0x200
[  108.861171]  ? ext4_find_extent+0x1f1/0x2f0
[  108.861575]  ? ext4_find_extent+0x1f1/0x2f0
[  108.862014]  ext4_ext_map_blocks+0x8d0/0x14c0
[  108.862503]  ext4_map_blocks+0x16e/0x5d0
[  108.862879]  _ext4_get_block+0x92/0x100
[  108.863231]  ext4_get_block+0x16/0x20
[  108.863576]  __block_write_begin_int+0x160/0x5d0
[  108.864007]  ? _ext4_get_block+0x100/0x100
[  108.864389]  ? ext4_write_begin+0x141/0x4c0
[  108.864786]  __block_write_begin+0x11/0x20
[  108.865270]  ext4_write_begin+0x1c4/0x4c0
[  108.865635]  pagecache_write_begin+0x13/0x20
[  108.866043]  __page_symlink+0xab/0xf0
[  108.866382]  ext4_symlink+0x2f3/0x3b0
[  108.866700]  vfs_symlink+0x10a/0x170
[  108.866997]  SyS_symlink+0xd4/0x100
[  108.867293]  entry_SYSCALL_64_fastpath+0x1e/0xa9
[  108.867673] RIP: 0033:0x5fb497
[  108.867964] RSP: 002b:00007ffc1b49fa68 EFLAGS: 00000207 ORIG_RAX: 
0000000000000058
[  108.868641] RAX: ffffffffffffffda RBX: 0000000000000056 RCX: 00000000005fb497
[  108.869575] RDX: 0000000002e33a70 RSI: 00000000011beed0 RDI: 00000000011aa4d0
[  108.870210] RBP: 00007ffc1b49ef70 R08: 0000000000000000 R09: 0000000000000060
[  108.870865] R10: 00007ffc1b49f9d8 R11: 0000000000000207 R12: 00007ffc1b49ef70
[  108.871501] R13: 0000000000000001 R14: 00007ffc1b49ef70 R15: 00000000017850b0
[  108.872610] Mem-Info:
[  108.873076] active_anon:52330 inactive_anon:1271 isolated_anon:0
[  108.873076]  active_file:327 inactive_file:326 isolated_file:0
[  108.873076]  unevictable:0 dirty:0 writeback:0 unstable:0
[  108.873076]  slab_reclaimable:2108 slab_unreclaimable:1497
[  108.873076]  mapped:1227 shmem:1639 pagetables:565 bounce:0
[  108.873076]  free:481 free_pcp:14 free_cma:0
[  108.877937] Node 0 active_anon:209320kB inactive_anon:5084kB 
active_file:1308kB inactive_file:1304kB unevictable:0kB isolated(anon):0kB 
isolated(file):0kB mapped:4908kB dirty:0kB writeback:0kB shmem:6556kB 
shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB 
unstable:0kB all_unreclaimable? yes
[  108.882074] Node 0 DMA32 free:1924kB min:1928kB low:2408kB high:2888kB 
active_anon:209320kB inactive_anon:5084kB active_file:1308kB 
inactive_file:1304kB unevictable:0kB writepending:0kB present:261616kB 
managed:242028kB mlocked:0kB slab_reclaimable:8432kB slab_unreclaimable:5988kB 
kernel_stack:1216kB pagetables:2260kB bounce:0kB free_pcp:56kB local_pcp:56kB 
free_cma:0kB
[  108.885220] lowmem_reserve[]: 0 0 0 0
[  108.885557] Node 0 DMA32: 81*4kB (UME) 34*8kB (ME) 7*16kB (ME) 0*32kB 1*64kB 
(M) 1*128kB (M) 2*256kB (M) 1*512kB (M) 0*1024kB 0*2048kB 0*4096kB = 1924kB
[  108.886783] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 
hugepages_size=2048kB
[  108.887551] 2295 total pagecache pages
[  108.887895] 0 pages in swap cache
[  108.888239] Swap cache stats: add 0, delete 0, find 0/0
[  108.889031] Free swap  = 0kB
[  108.889470] Total swap = 0kB
[  108.890041] 65404 pages RAM
[  108.890468] 0 pages HighMem/MovableOnly
[  108.891062] 4897 pages reserved
[  108.891540] 0 pages cma reserved
[  108.892049] 0 pages hwpoisoned

The vm-image fails in a different way, but also related to memory
allocation:

[   91.369442] init invoked oom-killer: 
gfp_mask=0x14280ca(GFP_HIGHUSER_MOVABLE|__GFP_ZERO), nodemask=(null),  order=0, 
oom_score_adj=0
[   91.371477] init cpuset=/ mems_allowed=0
[   91.372153] CPU: 0 PID: 1 Comm: init Not tainted 4.12.0-gnu #1
[   91.373147] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 
rel-1.10.2-0-g5f4c7b1-prebuilt.qemu-project.org 04/01/2014
[   91.375127] Call Trace:
[   91.375557]  dump_stack+0x63/0x82
[   91.376124]  dump_header+0x97/0x21a
[   91.376668]  out_of_memory+0x333/0x480
[   91.377256]  __alloc_pages_slowpath+0xcbb/0xd90
[   91.377963]  ? n_tty_open+0xd0/0xd0
[   91.378505]  __alloc_pages_nodemask+0x245/0x260
[   91.379200]  alloc_pages_vma+0xa2/0x270
[   91.379825]  __handle_mm_fault+0xc1b/0xfd0
[   91.380467]  handle_mm_fault+0xf3/0x210
[   91.381067]  __do_page_fault+0x240/0x4e0
[   91.381681]  trace_do_page_fault+0x37/0xe0
[   91.382324]  do_async_page_fault+0x19/0x70
[   91.382968]  async_page_fault+0x28/0x30
[   91.383570] RIP: 0033:0x58294f
[   91.384061] RSP: 002b:00007ffde18566f0 EFLAGS: 00010212
[   91.384870] RAX: 0000000000000030 RBX: 0000000046a74000 RCX: 0000000000000030
[   91.385969] RDX: 00007ffde185692d RSI: 0000000000000000 RDI: 0000000046a74004
[   91.387068] RBP: 00007ffde185693a R08: 0000000000000000 R09: 0000000000000000
[   91.388182] R10: 0000000000000004 R11: 000000000000000c R12: 0000000046a73da0
[   91.389279] R13: 0000000046a7bd90 R14: 00007ffde18568b0 R15: 0000000046a73e10
[   91.390411] Mem-Info:
[   91.390776] active_anon:52990 inactive_anon:1285 isolated_anon:0
[   91.390776]  active_file:71 inactive_file:69 isolated_file:0
[   91.390776]  unevictable:0 dirty:7 writeback:0 unstable:0
[   91.390776]  slab_reclaimable:1909 slab_unreclaimable:1525
[   91.390776]  mapped:1227 shmem:1639 pagetables:562 bounce:0
[   91.390776]  free:476 free_pcp:32 free_cma:0
[   91.395603] Node 0 active_anon:211960kB inactive_anon:5140kB 
active_file:284kB inactive_file:276kB unevictable:0kB isolated(anon):0kB 
isolated(file):0kB mapped:4908kB dirty:28kB writeback:0kB shmem:6556kB 
shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB 
unstable:0kB all_unreclaimable? yes
[   91.399747] Node 0 DMA32 free:1904kB min:1928kB low:2408kB high:2888kB 
active_anon:211960kB inactive_anon:5140kB active_file:284kB inactive_file:276kB 
unevictable:0kB writepending:28kB present:261616kB managed:242028kB mlocked:0kB 
slab_reclaimable:7636kB slab_unreclaimable:6100kB kernel_stack:1200kB 
pagetables:2248kB bounce:0kB free_pcp:128kB local_pcp:128kB free_cma:0kB
[   91.404739] lowmem_reserve[]: 0 0 0 0
[   91.405322] Node 0 DMA32: 220*4kB (UE) 128*8kB (UE) 0*16kB 0*32kB 0*64kB 
0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1904kB
[   91.407155] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 
hugepages_size=2048kB
[   91.408485] 1778 total pagecache pages
[   91.409074] 0 pages in swap cache
[   91.409599] Swap cache stats: add 0, delete 0, find 0/0
[   91.410413] Free swap  = 0kB
[   91.410867] Total swap = 0kB
[   91.411327] 65404 pages RAM
[   91.411777] 0 pages HighMem/MovableOnly
[   91.412372] 4897 pages reserved
[   91.412875] 0 pages cma reserved
[   91.413385] 0 pages hwpoisoned
[   91.413868] [ pid ]   uid  tgid total_vm      rss nr_ptes nr_pmds swapents 
oom_score_adj name
[   91.415189] Kernel panic - not syncing: Out of memory and no killable 
processes...
[   91.415189] 
[   91.416579] CPU: 0 PID: 1 Comm: init Not tainted 4.12.0-gnu #1
[   91.417476] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 
rel-1.10.2-0-g5f4c7b1-prebuilt.qemu-project.org 04/01/2014
[   91.419256] Call Trace:
[   91.419661]  dump_stack+0x63/0x82
[   91.420187]  panic+0xe4/0x22d
[   91.420651]  out_of_memory+0x33f/0x480
[   91.421243]  __alloc_pages_slowpath+0xcbb/0xd90
[   91.421949]  ? n_tty_open+0xd0/0xd0
[   91.422498]  __alloc_pages_nodemask+0x245/0x260
[   91.423203]  alloc_pages_vma+0xa2/0x270
[   91.423810]  __handle_mm_fault+0xc1b/0xfd0
[   91.424454]  handle_mm_fault+0xf3/0x210
[   91.425056]  __do_page_fault+0x240/0x4e0
[   91.425674]  trace_do_page_fault+0x37/0xe0
[   91.426284]  do_async_page_fault+0x19/0x70
[   91.426699]  async_page_fault+0x28/0x30
[   91.427306] RIP: 0033:0x58294f
[   91.427797] RSP: 002b:00007ffde18566f0 EFLAGS: 00010212
[   91.428605] RAX: 0000000000000030 RBX: 0000000046a74000 RCX: 0000000000000030
[   91.429673] RDX: 00007ffde185692d RSI: 0000000000000000 RDI: 0000000046a74004
[   91.430765] RBP: 00007ffde185693a R08: 0000000000000000 R09: 0000000000000000
[   91.431872] R10: 0000000000000004 R11: 000000000000000c R12: 0000000046a73da0
[   91.432957] R13: 0000000046a7bd90 R14: 00007ffde18568b0 R15: 0000000046a73e10
[   91.433754] Kernel Offset: 0x6000000 from 0xffffffff81000000 (relocation 
range: 0xffffffff80000000-0xffffffffbfffffff)
[   91.434746] ---[ end Kernel panic - not syncing: Out of memory and no 
killable processes...

core-updates-disk-image.log.xz
Description: Binary data

core-updates-vm-image.log.xz
Description: Binary data

signature.asc
Description: PGP signature