Skip to contentSkip to conversation

WARN_ON_ONCE() during generic/270

DISCUSSION Ross Zwisler 3 participants 3 messages Feb 8, 2017 – Feb 9, 2017 2 messages not in the archive libnvdimm: non-volatile memory device

lore
Share & tools
lore

Ross Zwisler

author
#0 lore raw

I hit the following WARN_ON_ONCE() during generic/270 with xfs (passed through kasan_symbolize.py):

run fstests generic/270 at 2017-02-08 10:56:07
XFS (pmem0p2): Unmounting Filesystem
XFS (pmem0p2): DAX enabled. Warning: EXPERIMENTAL, use at your own risk XFS (pmem0p2): Mounting V5 Filesystem
XFS (pmem0p2): Ending clean mount
XFS (pmem0p2): Quotacheck needed: Please wait.
XFS (pmem0p2): Quotacheck: Done.
XFS (pmem0p2): xlog_verify_grant_tail: space > BBTOB(tail_blocks)

  ------------[ cut here ]------------
  WARNING: CPU: 7 PID: 23652 at fs/xfs/libxfs/xfs_bmap.c:5981[<      none      >] xfs_bmse_shift_one+0x3da/0x4c0 fs/xfs/libxfs/xfs_bmap.c:5981
  Modules linked in: dax_pmem nd_pmem dax nd_btt nd_e820 libnvdimm
  CPU: 4 PID: 23652 Comm: 23288.fsstress. Not tainted 4.10.0-rc7-00065-g926af627 #1
  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
  Call Trace:
  [<     inline     >] __dump_stack lib/dump_stack.c:15
  [<      none      >] dump_stack+0x86/0xc3 lib/dump_stack.c:51
  [<      none      >] __warn+0xcb/0xf0 kernel/panic.c:547
  [<      none      >] warn_slowpath_null+0x1d/0x20 kernel/panic.c:582
  [<      none      >] xfs_bmse_shift_one+0x3da/0x4c0 fs/xfs/libxfs/xfs_bmap.c:5981
  [<      none      >] xfs_bmap_shift_extents+0x305/0x490 fs/xfs/libxfs/xfs_bmap.c:6144
  [<      none      >] xfs_shift_file_space+0x25f/0x320 fs/xfs/xfs_bmap_util.c:1475
  [<      none      >] xfs_insert_file_space+0x5a/0x180 fs/xfs/xfs_bmap_util.c:1548
  [<      none      >] xfs_file_fallocate+0x34c/0x3b0 fs/xfs/xfs_file.c:844
   ?[<      none      >] rcu_sync_lockdep_assert+0x2f/0x60 kernel/rcu/sync.c:68
  [<      none      >] vfs_fallocate+0x15a/0x230 fs/open.c:320
  [<     inline     >] SYSC_fallocate fs/open.c:343
  [<      none      >] SyS_fallocate+0x48/0x80 fs/open.c:337
  [<      none      >] entry_SYSCALL_64_fastpath+0x1f/0xc2 /home/rzwisler/project/linux/arch/x86/entry/entry_64.S:204
  RIP: 0033:0x7f34dc4ff0ca
  RSP: 002b:00007ffcffa58058 EFLAGS: 00000246 ORIG_RAX: 000000000000011d
  RAX: ffffffffffffffda RBX: 0000000000000166 RCX: 00007f34dc4ff0ca
  RDX: 00000000000ba000 RSI: 0000000000000020 RDI: 0000000000000003
  RBP: 0000000000000003 R08: 000000000000007b R09: 00007ffcffa5807c
  R10: 00000000000bc000 R11: 0000000000000246 R12: 00007f34d8000de0
  R13: 00000000ffffffff R14: 000000000000af4a R15: 0000000000000000
  ---[ end trace e24f5d4cbfc216f6 ]---

This trace is with the current linux/master:

commit 926af6273fc6 ("Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net")

though I initially his this issue with a v4.9 kernel. My test setup is a pair of PMEM ramdisks made with the memmap command line parameter, and my test filesystem is mounted with DAX.

This can be reproduced pretty easily by just running generic/270 in a loop.

Thanks,
- Ross

A message that is not in the archive (sent off-list or not yet received): 20170208191156.GA19071-VuQAYsv1563Yd54FQh9/[email protected]

#2 lore raw
Quoted 1 line

To: "Darrick J. Wong" <[email protected]>, [email protected]

[list moved; cc'ing [email protected]]

Quoted 11 lines · Ross Zwisler

I hit the following WARN_ON_ONCE() during generic/270 with xfs (passed through kasan_symbolize.py):

run fstests generic/270 at 2017-02-08 10:56:07
XFS (pmem0p2): Unmounting Filesystem
XFS (pmem0p2): DAX enabled. Warning: EXPERIMENTAL, use at your own risk XFS (pmem0p2): Mounting V5 Filesystem
XFS (pmem0p2): Ending clean mount
XFS (pmem0p2): Quotacheck needed: Please wait.
XFS (pmem0p2): Quotacheck: Done.
XFS (pmem0p2): xlog_verify_grant_tail: space > BBTOB(tail_blocks)

What does xfs_info say about this fs? I guess we're not trying to use rmap here, so there's less metadata to shove through the log.

I'm also wondering which file are we trying to insert-range on, and what its bmap looks like?

--D

Quoted 42 lines
  ------------[ cut here ]------------
  WARNING: CPU: 7 PID: 23652 at fs/xfs/libxfs/xfs_bmap.c:5981[<      none      >] xfs_bmse_shift_one+0x3da/0x4c0 fs/xfs/libxfs/xfs_bmap.c:5981
  Modules linked in: dax_pmem nd_pmem dax nd_btt nd_e820 libnvdimm
  CPU: 4 PID: 23652 Comm: 23288.fsstress. Not tainted 4.10.0-rc7-00065-g926af627 #1
  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
  Call Trace:
  [<     inline     >] __dump_stack lib/dump_stack.c:15
  [<      none      >] dump_stack+0x86/0xc3 lib/dump_stack.c:51
  [<      none      >] __warn+0xcb/0xf0 kernel/panic.c:547
  [<      none      >] warn_slowpath_null+0x1d/0x20 kernel/panic.c:582
  [<      none      >] xfs_bmse_shift_one+0x3da/0x4c0 fs/xfs/libxfs/xfs_bmap.c:5981
  [<      none      >] xfs_bmap_shift_extents+0x305/0x490 fs/xfs/libxfs/xfs_bmap.c:6144
  [<      none      >] xfs_shift_file_space+0x25f/0x320 fs/xfs/xfs_bmap_util.c:1475
  [<      none      >] xfs_insert_file_space+0x5a/0x180 fs/xfs/xfs_bmap_util.c:1548
  [<      none      >] xfs_file_fallocate+0x34c/0x3b0 fs/xfs/xfs_file.c:844
   ?[<      none      >] rcu_sync_lockdep_assert+0x2f/0x60 kernel/rcu/sync.c:68
  [<      none      >] vfs_fallocate+0x15a/0x230 fs/open.c:320
  [<     inline     >] SYSC_fallocate fs/open.c:343
  [<      none      >] SyS_fallocate+0x48/0x80 fs/open.c:337
  [<      none      >] entry_SYSCALL_64_fastpath+0x1f/0xc2 /home/rzwisler/project/linux/arch/x86/entry/entry_64.S:204
  RIP: 0033:0x7f34dc4ff0ca
  RSP: 002b:00007ffcffa58058 EFLAGS: 00000246 ORIG_RAX: 000000000000011d
  RAX: ffffffffffffffda RBX: 0000000000000166 RCX: 00007f34dc4ff0ca
  RDX: 00000000000ba000 RSI: 0000000000000020 RDI: 0000000000000003
  RBP: 0000000000000003 R08: 000000000000007b R09: 00007ffcffa5807c
  R10: 00000000000bc000 R11: 0000000000000246 R12: 00007f34d8000de0
  R13: 00000000ffffffff R14: 000000000000af4a R15: 0000000000000000
  ---[ end trace e24f5d4cbfc216f6 ]---

This trace is with the current linux/master:

commit 926af6273fc6 ("Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net")

though I initially his this issue with a v4.9 kernel. My test setup is a pair of PMEM ramdisks made with the memmap command line parameter, and my test filesystem is mounted with DAX.

This can be reproduced pretty easily by just running generic/270 in a loop.

Thanks,
- Ross

A message that is not in the archive (sent off-list or not yet received): [email protected]

#4 lore raw
Quoted 17 lines · Darrick J. Wong
Quoted 1 line

To: "Darrick J. Wong" <[email protected]>, [email protected]

[list moved; cc'ing [email protected]]

Quoted 11 lines · Ross Zwisler

I hit the following WARN_ON_ONCE() during generic/270 with xfs (passed through kasan_symbolize.py):

run fstests generic/270 at 2017-02-08 10:56:07
XFS (pmem0p2): Unmounting Filesystem
XFS (pmem0p2): DAX enabled. Warning: EXPERIMENTAL, use at your own risk XFS (pmem0p2): Mounting V5 Filesystem
XFS (pmem0p2): Ending clean mount
XFS (pmem0p2): Quotacheck needed: Please wait.
XFS (pmem0p2): Quotacheck: Done.
XFS (pmem0p2): xlog_verify_grant_tail: space > BBTOB(tail_blocks)

Quoted 6 lines

What does xfs_info say about this fs? I guess we're not trying to use rmap here, so there's less metadata to shove through the log.

I'm also wondering which file are we trying to insert-range on, and what its bmap looks like?

I reproduced this with a generic ramdisk (no DAX) and managed to get an ino via a tracepoint and a resulting bmap:

# xfs_io -c "fiemap -v" /mnt/fsstress.19801/p6f/d3/d3be/d4f9/f684
/mnt/fsstress.19801/p6f/d3/d3be/d4f9/f684:
 EXT: FILE-OFFSET      BLOCK-RANGE      TOTAL FLAGS
   0: [0..239]:        hole               240
   1: [240..391]:      794920..795071     152   0x0
   2: [392..871]:      hole               480
   3: [872..903]:      795072..795103      32   0x0
   4: [904..975]:      795104..795175      72   0x1
   5: [976..1780]:     hole               805

Note that this the post-shift bmap. The warning is complaining that extents 3 and 4 are contiguous and thus can be merged. This is unexpected on "insert space" (right shift) because, IIRC, we aren't creating any new extent boundaries that didn't previously exist (as opposed to collapse, which starts by punching a hole and connecting bordering extents).

This isn't really a functional problem, more flagging an unexpected/non-optimal but presumably still correct state. It may be the case that the assumption of never having separate but contiguous extents is not valid and the fix is to simply kill off the warning (perhaps being at or near ENOSPC is a factor here). It's probably worth some investigation to determine why this occurs for sure, however, just in case we have a problem somewhere else...

Brian

Quoted 48 lines

--D

Quoted 37 lines
  ------------[ cut here ]------------
  WARNING: CPU: 7 PID: 23652 at fs/xfs/libxfs/xfs_bmap.c:5981[<      none      >] xfs_bmse_shift_one+0x3da/0x4c0 fs/xfs/libxfs/xfs_bmap.c:5981
  Modules linked in: dax_pmem nd_pmem dax nd_btt nd_e820 libnvdimm
  CPU: 4 PID: 23652 Comm: 23288.fsstress. Not tainted 4.10.0-rc7-00065-g926af627 #1
  Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.1-1.fc24 04/01/2014
  Call Trace:
  [<     inline     >] __dump_stack lib/dump_stack.c:15
  [<      none      >] dump_stack+0x86/0xc3 lib/dump_stack.c:51
  [<      none      >] __warn+0xcb/0xf0 kernel/panic.c:547
  [<      none      >] warn_slowpath_null+0x1d/0x20 kernel/panic.c:582
  [<      none      >] xfs_bmse_shift_one+0x3da/0x4c0 fs/xfs/libxfs/xfs_bmap.c:5981
  [<      none      >] xfs_bmap_shift_extents+0x305/0x490 fs/xfs/libxfs/xfs_bmap.c:6144
  [<      none      >] xfs_shift_file_space+0x25f/0x320 fs/xfs/xfs_bmap_util.c:1475
  [<      none      >] xfs_insert_file_space+0x5a/0x180 fs/xfs/xfs_bmap_util.c:1548
  [<      none      >] xfs_file_fallocate+0x34c/0x3b0 fs/xfs/xfs_file.c:844
   ?[<      none      >] rcu_sync_lockdep_assert+0x2f/0x60 kernel/rcu/sync.c:68
  [<      none      >] vfs_fallocate+0x15a/0x230 fs/open.c:320
  [<     inline     >] SYSC_fallocate fs/open.c:343
  [<      none      >] SyS_fallocate+0x48/0x80 fs/open.c:337
  [<      none      >] entry_SYSCALL_64_fastpath+0x1f/0xc2 /home/rzwisler/project/linux/arch/x86/entry/entry_64.S:204
  RIP: 0033:0x7f34dc4ff0ca
  RSP: 002b:00007ffcffa58058 EFLAGS: 00000246 ORIG_RAX: 000000000000011d
  RAX: ffffffffffffffda RBX: 0000000000000166 RCX: 00007f34dc4ff0ca
  RDX: 00000000000ba000 RSI: 0000000000000020 RDI: 0000000000000003
  RBP: 0000000000000003 R08: 000000000000007b R09: 00007ffcffa5807c
  R10: 00000000000bc000 R11: 0000000000000246 R12: 00007f34d8000de0
  R13: 00000000ffffffff R14: 000000000000af4a R15: 0000000000000000
  ---[ end trace e24f5d4cbfc216f6 ]---

This trace is with the current linux/master:

commit 926af6273fc6 ("Merge git://git.kernel.org/pub/scm/linux/kernel/git/davem/net")

though I initially his this issue with a v4.9 kernel. My test setup is a pair of PMEM ramdisks made with the memmap command line parameter, and my test filesystem is mounted with DAX.

Quoted 5 lines

This can be reproduced pretty easily by just running generic/270 in a loop.

Thanks,
- Ross

--
To unsubscribe from this list: send the line "unsubscribe linux-xfs" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html