XFS: Assertion failed: del->br_blockcount > 0, file: fs/xfs/libxfs/xfs_bmap.c, line: 5124

[Ross Zwisler <ross.zwisler@linux.intel.com>]

I'm able to consistently hit the following XFS assertion with v4.9-rc8 and
xfstest xfs/118 (log is passed through kasan_symbolize.py):

  run fstests xfs/118 at 2016-12-09 14:36:28
  XFS (ram0): Unmounting Filesystem
  XFS (ram0): Mounting V5 Filesystem
  XFS (ram0): Ending clean mount
  XFS: Assertion failed: del->br_blockcount > 0, file: fs/xfs/libxfs/xfs_bmap.c, line: 5124
  ------------[ cut here ]------------
  kernel BUG at fs/xfs/xfs_message.c:113!
  invalid opcode: 0000 [#1] SMP
  Modules linked in: brd nd_pmem dax_pmem nd_btt dax nd_e820 libnvdimm
  CPU: 6 PID: 3146 Comm: xfs_fsr Not tainted 4.9.0-rc8 #2
  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
  task: ffff8800b2eb8000 task.stack: ffffc9000aa3c000
  RIP: 0010:[<ffffffff8150c720>]  [<ffffffff8150c720>] assfail+0x20/0x30
  RSP: 0018:ffffc9000aa3f960  EFLAGS: 00010246
  RAX: 0000000000000000 RBX: ffffc9000aa3fb28 RCX: 0000000000000000
  RDX: 00000000ffffffc0 RSI: 000000000000000a RDI: ffffffff81ec034a
  RBP: ffffc9000aa3f960 R08: 0000000000000000 R09: 0000000000000000
  R10: 000000000000000a R11: f000000000000000 R12: ffff8800b437e1c8
  R13: ffff8800b437e180 R14: 0000000000000000 R15: ffff8800b437e180
  FS:  00007f83b9d57700(0000) GS:ffff880515400000(0000) knlGS:0000000000000000
  CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
  CR2: 00007f83b9d35008 CR3: 00000000b2c20000 CR4: 00000000001406e0
  Stack:
   ffffc9000aa3faa0 ffffffff8149aec4 ffffc9000aa3f980 ffffffff81036a69
   ffffc9000aa3f9a0 ffffc9000aa3fa00 ffff880512ade100 0000000000000000
   ffffc9000aa3fc50 ffffc9000aa3fa1c ffff8800b437e1c8 ffff8800b437e1e8
  Call Trace:
   [<ffffffff8149aec4>] xfs_bmap_del_extent+0x104/0x19d0 fs/xfs/libxfs/xfs_bmap.c:5124
   [<ffffffff8149d028>] __xfs_bunmapi+0x898/0x1290 fs/xfs/libxfs/xfs_bmap.c:5726
   [<ffffffff8149da4b>] xfs_bunmapi+0x2b/0x40 fs/xfs/libxfs/xfs_bmap.c:5827
   [<ffffffff8150656e>] xfs_itruncate_extents+0x27e/0x5f0 fs/xfs/xfs_inode.c:1603
   [<ffffffff81506b01>] xfs_inactive_truncate+0xd1/0x130 fs/xfs/xfs_inode.c:1768
   [<ffffffff815087c4>] xfs_inactive+0x1c4/0x240 fs/xfs/xfs_inode.c:1933
   [<ffffffff81513d48>] xfs_fs_destroy_inode+0xd8/0x2e0 fs/xfs/xfs_super.c:958
   [<ffffffff812b872b>] destroy_inode+0x3b/0x60 fs/inode.c:264
   [<ffffffff812b8875>] evict+0x125/0x180 fs/inode.c:570
   [<     inline     >] iput_final fs/inode.c:1515
   [<ffffffff812b8b37>] iput+0x207/0x2d0 fs/inode.c:1542
   [<ffffffff812b0cc3>] dentry_unlink_inode+0xc3/0x160 fs/dcache.c:343
   [<ffffffff812b1ad6>] __dentry_kill+0xb6/0x160 fs/dcache.c:538
   [<     inline     >] dentry_kill fs/dcache.c:579
   [<ffffffff812b3a7e>] dput+0x2be/0x3e0 fs/dcache.c:791
   [<ffffffff81299a0e>] __fput+0x17e/0x1f0 fs/file_table.c:226
   [<ffffffff81299abe>] ____fput+0xe/0x10 fs/file_table.c:244
   [<ffffffff810d47d0>] task_work_run+0x80/0xa0 kernel/task_work.c:116
   [<     inline     >] tracehook_notify_resume ./include/linux/tracehook.h:191
   [<ffffffff81003315>] exit_to_usermode_loop+0xa5/0xb0 arch/x86/entry/common.c:160
   [<     inline     >] prepare_exit_to_usermode arch/x86/entry/common.c:190
   [<ffffffff81003dc9>] syscall_return_slowpath+0xc9/0x140 arch/x86/entry/common.c:259
   [<ffffffff81b40e22>] entry_SYSCALL_64_fastpath+0xc0/0xc2 arch/x86/entry/entry_64.S:244
  Code: 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 55 48 89 f1 41 89 d0 48 c7 c6 c0 91 f0 81 48 89 fa 31 ff 48 89 e5 e8 b0 f8 ff ff <0f> 0b 0f 1f 40 00 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00
  RIP  [<ffffffff8150c720>] assfail+0x20/0x30 fs/xfs/xfs_message.c:111
   RSP <ffffc9000aa3f960>
  ---[ end trace aa1781e3c0104dbc ]---
  XFS (ram1): Unmounting Filesystem
  systemd-journald[625]: Sent WATCHDOG=1 notification.

Here's the xfstest output, in case that's helpful:

  # ./check xfs/118
  FSTYP         -- xfs (debug)
  PLATFORM      -- Linux/x86_64 lorwyn 4.9.0-rc8
  MKFS_OPTIONS  -- -f -bsize=4096 /dev/ram0
  MOUNT_OPTIONS -- -o context=system_u:object_r:nfs_t:s0 /dev/ram0 /mnt/xfstests_scratch
  
  xfs/118	 - output mismatch (see /root/xfstests/results//xfs/118.out.bad)
      --- tests/xfs/118.out	2016-12-09 14:25:26.996375536 -0700
      +++ /root/xfstests/results//xfs/118.out.bad	2016-12-09 14:36:30.364407590 -0700
      @@ -1,2 +1,3 @@
       QA output created by 118
       Silence is golden
      +./tests/xfs/118: line 95:  3146 Segmentation fault      $XFS_FSR_PROG -vd $SCRATCH_MNT/newfile* >> $seqres.full 2>&1
      ...
      (Run 'diff -u tests/xfs/118.out /root/xfstests/results//xfs/118.out.bad'  to see the entire diff)
  umount: /mnt/xfstests_scratch: target is busy
          (In some cases useful info about processes that
           use the device is found by lsof(8) or fuser(1).)
  _check_xfs_filesystem: filesystem on /dev/ram0 has dirty log (see /root/xfstests/results//xfs/118.full)
  _check_xfs_filesystem: filesystem on /dev/ram0 is inconsistent (c) (see /root/xfstests/results//xfs/118.full)
  _check_xfs_filesystem: filesystem on /dev/ram0 is inconsistent (r) (see /root/xfstests/results//xfs/118.full)
  _check_dmesg: something found in dmesg (see /root/xfstests/results//xfs/118.dmesg)
  Ran: xfs/118
  Failures: xfs/118
  Failed 1 of 1 tests

I initially hit this with a pair of PMEM partitions, but was able to reproduce
it with two 2 GiB BRD ramdisks as my TEST_DEV and SCRATCH_DEV. 

I'm running with xfsprogs v4.8.0 and the following xfstest commit:
	adcc60c  build: allow building with latest xfslibs on 32-bit Linux

Kernel v4.8 is also able to his this same issue.

Thanks,
- Ross