Null pointer dereference while at ACL limit on v5 XFS

Michael L. Semon
2014-06-23T21:48:45Z

At the ACL limit of v5-superblock XFS--with a directory filled with both default
and access ACL entries--I'm getting a null pointer dereference on x86 after
creating the directory successfully.

Disclaimer: There's some current issues on 32-bit x86 that, for instance, can
make badblocks see phantom bad blocks on a read test. My apologies in advance
if this turns out to be a false alarm bug report.

My first encounter with this issue involved fsstress. Here's part of a `crash`
session from the fsstress run.

root@oldsvrhw:/mnt/crashdump/xfs-fsstress-max-acl-2# crash vmlinux System.map vmcore
crash 7.0.4
# setup was snipped.
DEBUG KERNEL: vmlinux
DUMPFILE: vmcore
CPUS: 1
DATE: Fri Jun 20 13:04:23 2014
UPTIME: 00:29:49
LOAD AVERAGE: 1.06, 1.56, 0.75
TASKS: 78
NODENAME: oldsvrhw
RELEASE: 3.16.0-rc1+
VERSION: #1 SMP Thu Jun 19 20:10:57 EDT 2014
MACHINE: i686 (730 Mhz)
MEMORY: 510.4 MB
PANIC: "Oops: 0000 [#1] SMP DEBUG_PAGEALLOC" (check log for details)
PID: 41
COMMAND: "kworker/0:1H"
TASK: de8f2ac0 [THREAD_INFO: de92e000]
CPU: 0
STATE: TASK_RUNNING (PANIC)

crash> dmesg
# ### excerpt:

# ### mounted $SCRATCH_DEV, applied ACLs to $SCRATCH_MNT/test_dir
[ 1499.886170] XFS (hdc5): Mounting V5 Filesystem
[ 1500.057759] XFS (hdc5): Ending clean mount

# ### ran `fsstress -d $SCRATCH_MNT/test-dir/a -n 10000 -p 16`
# ### BTW, does fsstress trash the existing directory before a run?
[ 1654.043846] fsstress (610) used greatest stack depth: 4956 bytes left
[ 1654.063619] fsstress (615) used greatest stack depth: 4920 bytes left
[ 1654.082220] fsstress (623) used greatest stack depth: 4820 bytes left
[ 1654.087344] fsstress (611) used greatest stack depth: 4800 bytes left
[ 1654.094295] fsstress (614) used greatest stack depth: 4784 bytes left
[ 1654.191650] fsstress (608) used greatest stack depth: 4768 bytes left
[ 1663.452036] perf interrupt took too long (2537 > 2500), lowering kernel.perf_event_max_sample_rate to 50000

# ### This was OK, so I hit Ctrl-c, then ran this (not in child directory):
# ### ran `fsstress -d $SCRATCH_MNT/test-dir -n 10000 -p 16`
[ 1789.338622] BUG: unable to handle kernel NULL pointer dereference at 0000000c
[ 1789.338842] IP: [<c1263048>] xfs_ail_check+0x58/0xc0
[ 1789.338994] *pde = 00000000
[ 1789.339042] Oops: 0000 [#1] SMP DEBUG_PAGEALLOC
[ 1789.339042] CPU: 0 PID: 41 Comm: kworker/0:1H Not tainted 3.16.0-rc1+ #1
[ 1789.339042] Hardware name: Dell Computer Corporation L733r /CA810E , BIOS A14 09/05/2001
[ 1789.339042] Workqueue: xfslogd xfs_buf_iodone_work
[ 1789.339042] task: de8f2ac0 ti: de92e000 task.ti: de92e000
[ 1789.339042] EIP: 0060:[<c1263048>] EFLAGS: 00010286 CPU: 0
[ 1789.339042] EIP is at xfs_ail_check+0x58/0xc0
[ 1789.339042] EAX: 00000000 EBX: dde37370 ECX: 0000330a EDX: 0000330a
[ 1789.339042] ESI: 00000001 EDI: 00000001 EBP: de92fc9c ESP: de92fc90
[ 1789.339042] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
[ 1789.339042] CR0: 8005003b CR2: 0000000c CR3: 1c8ef000 CR4: 000007d0
[ 1789.339042] Stack:
[ 1789.339042] dde37370 ddc4ea80 00000001 de92fcac c12630c3 dde37370 00000012 de92fd04
[ 1789.339042] c1263d1d 00000000 00000001 00000000 00000000 ddc4ea88 de92fd38 dc8bba28
[ 1789.339042] ddc4ea80 00000000 0000330a de92fd44 0000001f 00000001 00000012 00003362
[ 1789.339042] Call Trace:
[ 1789.339042] [<c12630c3>] xfs_ail_delete+0x13/0x60
[ 1789.339042] [<c1263d1d>] xfs_trans_ail_update_bulk+0xad/0x3c0
[ 1789.339042] [<c11fbd35>] xfs_trans_committed_bulk+0x255/0x300
[ 1789.339042] [<c125dcac>] xlog_cil_committed+0x3c/0x160
[ 1789.339042] [<c1259f8c>] xlog_state_do_callback+0x17c/0x380
[ 1789.339042] [<c125a253>] xlog_state_done_syncing+0xc3/0xe0
[ 1789.339042] [<c125a2de>] xlog_iodone+0x6e/0x100
[ 1789.339042] [<c11dd08b>] xfs_buf_iodone_work+0x5b/0xe0
[ 1789.339042] [<c1055bc5>] process_one_work+0x1b5/0x570
[ 1789.339042] [<c1055b48>] ? process_one_work+0x138/0x570
[ 1789.339042] [<c10560e5>] ? worker_thread+0x165/0x470
[ 1789.339042] [<c1056077>] worker_thread+0xf7/0x470
[ 1789.339042] [<c1055f80>] ? process_one_work+0x570/0x570
[ 1789.339042] [<c105d061>] kthread+0xa1/0xc0
[ 1789.339042] [<c108509b>] ? trace_hardirqs_on+0xb/0x10
[ 1789.339042] [<c1500ae1>] ret_from_kernel_thread+0x21/0x30
[ 1789.339042] [<c105cfc0>] ? insert_kthread_work+0x80/0x80
[ 1789.339042] Code: c1 b8 d8 9e 62 c1 e8 a8 00 f9 ff 8b 43 04 39 c6 74 10 8b 7b 0c 39 78 0c 8b 53 08 8b 48 08 74 43 73 45 8b 03 39 c6 74 24 8b 73 0c <39> 70 0c 8b 53 08 8b 48 08 74 4d 73 14 b9 38 00 00 00 ba e3 a3
[ 1789.339042] EIP: [<c1263048>] xfs_ail_check+0x58/0xc0 SS:ESP 0068:de92fc90
[ 1789.339042] CR2: 000000000000000c

Since then, I've been trying out different ways of reproducing this
message.

# ------ shortest way found so far ------

For a seed file, use this URL...

https://docs.google.com/file/d/0B41268QKoNjtMEU5UUZvMXF6ZzQ

Hopefully, the order will go like this (from memory):

# get the seed file, and
xz -d max_acl_file.xz

mkfs.xfs -f -m crc=1 $SCRATCH_DEV
mount $SCRATCH_DEV $SCRATCH_MNT

mkdir $SCRATCH_MNT/acl-dir

setfacl --set-file=max_acl_file $SCRATCH_MNT/acl-dir

cd $SCRATCH_MNT/acl-dir

# or `touch a b c; mkdir d e f`
mkdir a b c
sync

rm -rv ./*
sync

# ----------------------------------------

That's as short as I can get it...if it works. If not, keep trying
different things. The tests need not be heavy: A few seconds worth
of fs_mark should populate the directory sufficiently. The `rm -rv ./*`
is key. sync is not required, the oops will happen on its own.

This seems to happen only at a point where one or both ACL limits
have been hit. I'm only guessing that when a default entry is made, space
is allocated for the access entry, and vice versa.

Thanks!

Michael