Bug 874539

Summary: [xfs] Bug on invaliding page that is not locked
Product: Red Hat Enterprise Linux 6 Reporter: Boris Ranto <branto>
Component: kernelAssignee: Dave Chinner <dchinner>
Status: CLOSED ERRATA QA Contact: Boris Ranto <branto>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.4CC: bfoster, cmaiolin, dchinner, eguan, esandeen, jcpunk, lczerner, rwheeler, zab
Target Milestone: rcKeywords: Regression
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: kernel-2.6.32-354.el6 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-02-21 06:56:08 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Boris Ranto 2012-11-08 12:02:03 UTC
Description of problem:
In recent rhel6 kernels I'm hitting BUG_ON in block_invalidatepage because the page that it is called with has incorrect locking.

Version-Release number of selected component (if applicable):
kernel-2.6.32-337.el6

How reproducible:
About half of the cases.

Steps to Reproduce:
1. untar kernel sources
2. sync
3. untar another kernel sources
4. sleep for about half a minute
5. tear down the xfs fs (e.g. by ./src/godown from xfstests)
  
Actual results:
The BUG_ON because of the unlocked page.

Expected results:
No BUG_ON.

Additional info:
This is likely a regression from patches for 845233 that touch the writeback logic. I couldn't hit this BUG_ON in -279.el6 kernel.

The call trace:
<4>------------[ cut here ]------------
<2>kernel BUG at fs/buffer.c:1504!
<4>invalid opcode: 0000 [#1] SMP 
<4>last sysfs file: /sys/devices/pci0000:00/0000:00:1f.2/host2/target2:0:0/2:0:0:0/block/sda/dev
<4>CPU 2 
<4>Modules linked in: autofs4 sunrpc cpufreq_ondemand acpi_cpufreq freq_table mperf ipv6 xfs exportfs microcode i2c_i801 sg iTCO_wdt iTCO_vendor_support shpchp e1000e snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm snd_timer snd soundcore snd_page_alloc xhci_hcd ext4 mbcache jbd2 sr_mod cdrom sd_mod crc_t10dif firewire_ohci firewire_core crc_itu_t ahci nouveau ttm drm_kms_helper drm i2c_algo_bit i2c_core mxm_wmi video output wmi dm_mirror dm_region_hash dm_log dm_mod [last unloaded: scsi_wait_scan]
<4>
<4>Pid: 11653, comm: flush-8:0 Not tainted 2.6.32-337.el6.x86_64 #1                  /DX79SI
<4>RIP: 0010:[<ffffffff811b6336>]  [<ffffffff811b6336>] block_invalidatepage+0xf6/0x100
<4>RSP: 0018:ffff88005d27d8a0  EFLAGS: 00010246
<4>RAX: 004000000000282c RBX: ffffea00041b1640 RCX: 0000000000000000
<4>RDX: 000000000000002b RSI: 0000000000000000 RDI: ffffea00041b1640
<4>RBP: ffff88005d27d8e0 R08: 0000000000000000 R09: fea31e33287f2402
<4>R10: 0000000000000000 R11: ffff88013ee1f268 R12: 0000000000000000
<4>R13: ffff88013ee22d88 R14: 0000000000000000 R15: 0000000000000000
<4>FS:  0000000000000000(0000) GS:ffff880028240000(0000) knlGS:0000000000000000
<4>CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
<4>CR2: 00007f2f8f5bb000 CR3: 0000000218c9f000 CR4: 00000000000407e0
<4>DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
<4>DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
<4>Process flush-8:0 (pid: 11653, threadinfo ffff88005d27c000, task ffff880089b48ae0)
<4>Stack:
<4> ffff88012ef7f168 0000000300000001 ffff88012ef7f168 ffffea00041b1640
<4><d> 0000000000000000 ffff88013ee22d88 0000000000000000 0000000000000001
<4><d> ffff88005d27d910 ffffffffa04270e4 ffffea00041b1640 ffff88013ee22d88
<4>Call Trace:
<4> [<ffffffffa04270e4>] xfs_vm_invalidatepage+0x44/0x90 [xfs]
<4> [<ffffffffa0427470>] xfs_aops_discard_page+0x60/0x160 [xfs]
<4> [<ffffffffa0428641>] xfs_vm_writepage+0x4e1/0x5b0 [xfs]
<4> [<ffffffff8112c737>] __writepage+0x17/0x40
<4> [<ffffffff8112da49>] write_cache_pages+0x1c9/0x4b0
<4> [<ffffffff8112ebd5>] ? pagevec_lookup_tag+0x25/0x40
<4> [<ffffffff8112c720>] ? __writepage+0x0/0x40
<4> [<ffffffff8112dd54>] generic_writepages+0x24/0x30
<4> [<ffffffffa04276cd>] xfs_vm_writepages+0x5d/0x80 [xfs]
<4> [<ffffffff8112dd81>] do_writepages+0x21/0x40
<4> [<ffffffff811ac2ed>] writeback_single_inode+0xdd/0x290
<4> [<ffffffff811ac6fe>] writeback_sb_inodes+0xce/0x180
<4> [<ffffffff811ac85b>] writeback_inodes_wb+0xab/0x1b0
<4> [<ffffffff811acbfb>] wb_writeback+0x29b/0x3f0
<4> [<ffffffff8150c2f0>] ? thread_return+0x4e/0x76e
<4> [<ffffffff81081902>] ? del_timer_sync+0x22/0x30
<4> [<ffffffff811acee9>] wb_do_writeback+0x199/0x240
<4> [<ffffffff811acff3>] bdi_writeback_task+0x63/0x1b0
<4> [<ffffffff81096867>] ? bit_waitqueue+0x17/0xd0
<4> [<ffffffff8113c810>] ? bdi_start_fn+0x0/0x100
<4> [<ffffffff8113c896>] bdi_start_fn+0x86/0x100
<4> [<ffffffff8113c810>] ? bdi_start_fn+0x0/0x100
<4> [<ffffffff81096636>] kthread+0x96/0xa0
<4> [<ffffffff8100c0ca>] child_rip+0xa/0x20
<4> [<ffffffff810965a0>] ? kthread+0x0/0xa0
<4> [<ffffffff8100c0c0>] ? child_rip+0x0/0x20
<4>Code: 8b 5d d8 4c 8b 65 e0 4c 8b 6d e8 4c 8b 75 f0 4c 8b 7d f8 c9 c3 31 f6 48 89 df e8 f6 28 f6 ff eb de 4c 89 e7 e8 dc f9 ff ff eb 8c <0f> 0b eb fe 66 0f 1f 44 00 00 55 48 89 e5 48 83 ec 10 48 89 1c 
<1>RIP  [<ffffffff811b6336>] block_invalidatepage+0xf6/0x100
<4> RSP <ffff88005d27d8a0>

The code at line 1504 of fs/buffer.c is BUG_ON(!PageLocked(page));.

Comment 2 Dave Chinner 2012-11-09 00:19:10 UTC
I hit this on an upstream kernel earlier this week doing similar shutdown-for-log-recovery testing (using compilebench). I know what the problem is and I was working on a fix yesterday, but I haven't come up with a satisfactory solution yet.

The problem is that we are cancelling writeback and invalidating the page after it has already been marked for writeback and unlocked. Then the transaction reservation for EOF size updates fails, and we try to abort and invalidate the page. The error handling in this case is all wrong, and that's where the BUG is hit. I hope to have a fix sorted and upstream by early next week.

-Dave.

Comment 3 RHEL Program Management 2012-11-11 23:40:36 UTC
This request was evaluated by Red Hat Product Management for
inclusion in a Red Hat Enterprise Linux release.  Product
Management has requested further review of this request by
Red Hat Engineering, for potential inclusion in a Red Hat
Enterprise Linux release for currently deployed products.
This request is not yet committed for inclusion in a release.

Comment 4 Dave Chinner 2012-11-12 01:00:48 UTC
Upstream patch for review is here:

http://marc.info/?l=linux-xfs&m=135268137325214&w=2

Just about to back port it to RHEL6.4 now....

-Dave.

Comment 7 Jarod Wilson 2013-01-15 21:46:01 UTC
Patch(es)

Comment 13 errata-xmlrpc 2013-02-21 06:56:08 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

http://rhn.redhat.com/errata/RHSA-2013-0496.html