Re: [patch 0/9] writeback data integrity and other fixes (take 3)

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 01:47:15AM +1100, npiggin@suse.de wrote:
> OK, I'm happier with this patchset now. Note that I've taken your patch
> and mangled it a bit at the end of the series.
> 
> This one survives and seems to run OK here, but I'm mainly doing dumb
> stress testing with a handful of filesystems, and data-io error injection
> testing. There are a lot of combinations of ways this function can operate
> and interact obviously, so it would be helpful to get more review.
> 
> Chris, would you possibly have time to run your btrfs tests that are
> sensitive to problems in this code? I could provide you a single patch
> rollup against mainline if it helps.

BTW. XFS seems to be doing something interesting with my simple sync
test case with IO error injection. I map a file MAP_SHARED into a number of
processes, which then each run a loop that dirties the memory then calls
msync(MS_SYNC) on the range.

ext2 mostly reports -EIO back to userspace when a failure is injected AFAIKS.
ext3 (ordered) doesn't until a lot of errors have been injected, but eventually
reports -EIO and shuts down the filesystem. reiserfs seems to report failure
more consistently.

I haven't seen any -EIO failures from XFS... maybe I'm just not doing the
right thing, or there is a caveat I'm not aware of.

All fault injections I noticed had a trace like this:
FAULT_INJECTION: forcing a failure
Call Trace:
9f9cd758:  [<6019f1de>] random32+0xe/0x20
9f9cd768:  [<601a31b9>] should_fail+0xd9/0x130
9f9cd798:  [<6018d0c4>] generic_make_request+0x304/0x4e0
9f9cd7a8:  [<60062301>] mempool_alloc+0x51/0x130
9f9cd858:  [<6018e6bf>] submit_bio+0x4f/0xe0
9f9cd8a8:  [<60165505>] xfs_submit_ioend_bio+0x25/0x40
9f9cd8c8:  [<6016603c>] xfs_submit_ioend+0xbc/0xf0
9f9cd908:  [<60166bf9>] xfs_page_state_convert+0x3d9/0x6a0
9f9cd928:  [<6005d515>] delayacct_end+0x95/0xb0
9f9cda08:  [<60166ffd>] xfs_vm_writepage+0x6d/0x110
9f9cda18:  [<6006618b>] set_page_dirty+0x4b/0xd0
9f9cda58:  [<60066115>] __writepage+0x15/0x40
9f9cda78:  [<60066775>] write_cache_pages+0x255/0x470
9f9cda90:  [<60066100>] __writepage+0x0/0x40
9f9cdb98:  [<600669b0>] generic_writepages+0x20/0x30
9f9cdba8:  [<60165ba3>] xfs_vm_writepages+0x53/0x70
9f9cdbd8:  [<600669eb>] do_writepages+0x2b/0x40
9f9cdbf8:  [<6006004c>] __filemap_fdatawrite_range+0x5c/0x70
9f9cdc58:  [<6006026a>] filemap_fdatawrite+0x1a/0x20
9f9cdc68:  [<600a7a05>] do_fsync+0x45/0xe0
9f9cdc98:  [<6007794b>] sys_msync+0x14b/0x1d0
9f9cdcf8:  [<60019a70>] handle_syscall+0x50/0x80
9f9cdd18:  [<6002a10f>] userspace+0x44f/0x510
9f9cdfc8:  [<60016792>] fork_handler+0x62/0x70

And the kernel would sometimes say this:
Buffer I/O error on device ram0, logical block 279
lost page write due to I/O error on ram0
Buffer I/O error on device ram0, logical block 379
lost page write due to I/O error on ram0
Buffer I/O error on device ram0, logical block 389
lost page write due to I/O error on ram0


I think I also saw a slab bug when running dbench with fault injection on.
Running latest Linus kernel.

bash-3.1# dbench -t10 -c ../client.txt 8
dbench version 3.04 - Copyright Andrew Tridgell 1999-2004

Running for 10 seconds with load '../client.txt' and minimum warmup 2 secs
8 clients started
FAULT_INJECTION: forcing a failure
Call Trace:
9e7bb548:  [<601623ae>] random32+0xe/0x20
9e7bb558:  [<60166389>] should_fail+0xd9/0x130
9e7bb588:  [<60150294>] generic_make_request+0x304/0x4e0
9e7bb598:  [<60062301>] mempool_alloc+0x51/0x130
9e7bb648:  [<6015188f>] submit_bio+0x4f/0xe0
9e7bb698:  [<6012b440>] _xfs_buf_ioapply+0x180/0x2a0
9e7bb6a0:  [<6002f600>] default_wake_function+0x0/0x10
9e7bb6f8:  [<6012bae1>] xfs_buf_iorequest+0x31/0x90
9e7bb718:  [<60112f75>] xlog_bdstrat_cb+0x45/0x50
9e7bb738:  [<60114135>] xlog_sync+0x195/0x440
9e7bb778:  [<60114491>] xlog_state_release_iclog+0xb1/0xc0
9e7bb7a8:  [<60114ca9>] xlog_write+0x539/0x550
9e7bb858:  [<60114e60>] xfs_log_write+0x40/0x60
9e7bb888:  [<6011fbaa>] _xfs_trans_commit+0x19a/0x360
9e7bb8b8:  [<600838e2>] poison_obj+0x42/0x60
9e7bb8d0:  [<60082cb3>] dbg_redzone1+0x13/0x30
9e7bb8e8:  [<60083999>] cache_alloc_debugcheck_after+0x99/0x1c0
9e7bb918:  [<6008517b>] kmem_cache_alloc+0x8b/0x100
9e7bb958:  [<60128084>] kmem_zone_alloc+0x74/0xe0
9e7bb998:  [<60082ad9>] kmem_cache_size+0x9/0x10
9e7bb9a8:  [<60128124>] kmem_zone_zalloc+0x34/0x50
9e7bb9e8:  [<60121e8b>] xfs_dir_ialloc+0x13b/0x2e0
9e7bba58:  [<601f534b>] __down_write+0xb/0x10
9e7bbaa8:  [<60125b9e>] xfs_mkdir+0x37e/0x4b0
9e7bbb38:  [<601f5589>] _spin_unlock+0x9/0x10
9e7bbb78:  [<601301a4>] xfs_vn_mknod+0xf4/0x1a0
9e7bbbd8:  [<6013025e>] xfs_vn_mkdir+0xe/0x10
9e7bbbe8:  [<60091010>] vfs_mkdir+0x90/0xc0
9e7bbc18:  [<600934d6>] sys_mkdirat+0x106/0x120
9e7bbc88:  [<6008629b>] filp_close+0x4b/0x80
9e7bbce8:  [<60093503>] sys_mkdir+0x13/0x20
9e7bbcf8:  [<60019a70>] handle_syscall+0x50/0x80
9e7bbd18:  [<6002a10f>] userspace+0x44f/0x510
9e7bbfc8:  [<60016792>] fork_handler+0x62/0x70

I/O error in filesystem ("ram0") meta-data dev ram0 block 0x8002c       ("xlog_i
odone") error 5 buf count 32768
xfs_force_shutdown(ram0,0x2) called from line 1056 of file /home/npiggin/usr/src
/linux-2.6/fs/xfs/xfs_log.c.  Return address = 0x000000006011370d
Filesystem "ram0": Log I/O Error Detected.  Shutting down filesystem: ram0
Please umount the filesystem, and rectify the problem(s)
xfs_force_shutdown(ram0,0x2) called from line 818 of file /home/npiggin/usr/src/
linux-2.6/fs/xfs/xfs_log.c.  Return address = 0x0000000060114e7d
slab error in verify_redzone_free(): cache `xfs_log_ticket': double free detecte
d
Call Trace:
9e7bb998:  [<6008372f>] __slab_error+0x1f/0x30
9e7bb9a8:  [<60083cae>] cache_free_debugcheck+0x1ee/0x240
9e7bb9b0:  [<60112ef0>] xlog_ticket_put+0x10/0x20
9e7bb9e8:  [<60083f70>] kmem_cache_free+0x50/0xc0
9e7bba18:  [<60112ef0>] xlog_ticket_put+0x10/0x20
9e7bba28:  [<60114dc9>] xfs_log_done+0x59/0xb0
9e7bba68:  [<6011f5de>] xfs_trans_cancel+0x7e/0x140
9e7bbaa8:  [<60125a1e>] xfs_mkdir+0x1fe/0x4b0
9e7bbb38:  [<601f5589>] _spin_unlock+0x9/0x10
9e7bbb78:  [<601301a4>] xfs_vn_mknod+0xf4/0x1a0
9e7bbbd8:  [<6013025e>] xfs_vn_mkdir+0xe/0x10
9e7bbbe8:  [<60091010>] vfs_mkdir+0x90/0xc0
9e7bbc18:  [<600934d6>] sys_mkdirat+0x106/0x120
9e7bbc88:  [<6008629b>] filp_close+0x4b/0x80
9e7bbce8:  [<60093503>] sys_mkdir+0x13/0x20
9e7bbcf8:  [<60019a70>] handle_syscall+0x50/0x80
9e7bbd18:  [<6002a10f>] userspace+0x44f/0x510
9e7bbfc8:  [<60016792>] fork_handler+0x62/0x70

000000009e0d4ec0: redzone 1:0x9f911029d74e35b, redzone 2:0x9f911029d74e35b.
(3) open ./clients/client1 failed for handle 16385 (No such file or directory)
(4) ERROR: handle 16385 was not found
Child failed with status 1

(kernel died soon afterwards)

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Tue, Oct 28, 2008 at 04:39:53PM +0100, Nick Piggin wrote:
> On Wed, Oct 29, 2008 at 01:47:15AM +1100, npiggin@suse.de wrote:
> > OK, I'm happier with this patchset now. Note that I've taken your patch
> > and mangled it a bit at the end of the series.
> > 
> > This one survives and seems to run OK here, but I'm mainly doing dumb
> > stress testing with a handful of filesystems, and data-io error injection
> > testing. There are a lot of combinations of ways this function can operate
> > and interact obviously, so it would be helpful to get more review.
> > 
> > Chris, would you possibly have time to run your btrfs tests that are
> > sensitive to problems in this code? I could provide you a single patch
> > rollup against mainline if it helps.
> 
> BTW. XFS seems to be doing something interesting with my simple sync
> test case with IO error injection. I map a file MAP_SHARED into a number of
> processes, which then each run a loop that dirties the memory then calls
> msync(MS_SYNC) on the range.
> 
> ext2 mostly reports -EIO back to userspace when a failure is injected AFAIKS.
> ext3 (ordered) doesn't until a lot of errors have been injected, but eventually
> reports -EIO and shuts down the filesystem. reiserfs seems to report failure
> more consistently.
> 
> I haven't seen any -EIO failures from XFS... maybe I'm just not doing the
> right thing, or there is a caveat I'm not aware of.
> 
> All fault injections I noticed had a trace like this:
> FAULT_INJECTION: forcing a failure
> Call Trace:
> 9f9cd758:  [<6019f1de>] random32+0xe/0x20
> 9f9cd768:  [<601a31b9>] should_fail+0xd9/0x130
> 9f9cd798:  [<6018d0c4>] generic_make_request+0x304/0x4e0
> 9f9cd7a8:  [<60062301>] mempool_alloc+0x51/0x130
> 9f9cd858:  [<6018e6bf>] submit_bio+0x4f/0xe0
> 9f9cd8a8:  [<60165505>] xfs_submit_ioend_bio+0x25/0x40
> 9f9cd8c8:  [<6016603c>] xfs_submit_ioend+0xbc/0xf0
> 9f9cd908:  [<60166bf9>] xfs_page_state_convert+0x3d9/0x6a0
> 9f9cd928:  [<6005d515>] delayacct_end+0x95/0xb0
> 9f9cda08:  [<60166ffd>] xfs_vm_writepage+0x6d/0x110
> 9f9cda18:  [<6006618b>] set_page_dirty+0x4b/0xd0
> 9f9cda58:  [<60066115>] __writepage+0x15/0x40
> 9f9cda78:  [<60066775>] write_cache_pages+0x255/0x470
> 9f9cda90:  [<60066100>] __writepage+0x0/0x40
> 9f9cdb98:  [<600669b0>] generic_writepages+0x20/0x30
> 9f9cdba8:  [<60165ba3>] xfs_vm_writepages+0x53/0x70
> 9f9cdbd8:  [<600669eb>] do_writepages+0x2b/0x40
> 9f9cdbf8:  [<6006004c>] __filemap_fdatawrite_range+0x5c/0x70
> 9f9cdc58:  [<6006026a>] filemap_fdatawrite+0x1a/0x20
> 9f9cdc68:  [<600a7a05>] do_fsync+0x45/0xe0
> 9f9cdc98:  [<6007794b>] sys_msync+0x14b/0x1d0
> 9f9cdcf8:  [<60019a70>] handle_syscall+0x50/0x80
> 9f9cdd18:  [<6002a10f>] userspace+0x44f/0x510
> 9f9cdfc8:  [<60016792>] fork_handler+0x62/0x70

XFS reports bio errors through the I/O completion path, not the
submission path.

> And the kernel would sometimes say this:
> Buffer I/O error on device ram0, logical block 279
> lost page write due to I/O error on ram0
> Buffer I/O error on device ram0, logical block 379
> lost page write due to I/O error on ram0
> Buffer I/O error on device ram0, logical block 389
> lost page write due to I/O error on ram0

Yes - that's coming from end_buffer_async_write() when an error is
reported in bio completion. This does:

 465                 set_bit(AS_EIO, &page->mapping->flags);
 466                 set_buffer_write_io_error(bh);
 467                 clear_buffer_uptodate(bh);
 468                 SetPageError(page);

Hmmmm - do_fsync() calls filemap_fdatawait() which ends up in
wait_on_page_writeback_range() which is appears to be checking the
mapping flags for errors. I wonder why that error is not being
propagated then? AFAICT both XFS and the fsync code are doing the
right thing but somewhere the error has gone missing...

> I think I also saw a slab bug when running dbench with fault injection on.
> Running latest Linus kernel.
> 
> bash-3.1# dbench -t10 -c ../client.txt 8
> dbench version 3.04 - Copyright Andrew Tridgell 1999-2004
> 
> Running for 10 seconds with load '../client.txt' and minimum warmup 2 secs
> 8 clients started
> FAULT_INJECTION: forcing a failure
> Call Trace:
> 9e7bb548:  [<601623ae>] random32+0xe/0x20
> 9e7bb558:  [<60166389>] should_fail+0xd9/0x130
> 9e7bb588:  [<60150294>] generic_make_request+0x304/0x4e0
> 9e7bb598:  [<60062301>] mempool_alloc+0x51/0x130
> 9e7bb648:  [<6015188f>] submit_bio+0x4f/0xe0
> 9e7bb698:  [<6012b440>] _xfs_buf_ioapply+0x180/0x2a0
> 9e7bb6a0:  [<6002f600>] default_wake_function+0x0/0x10
> 9e7bb6f8:  [<6012bae1>] xfs_buf_iorequest+0x31/0x90
> 9e7bb718:  [<60112f75>] xlog_bdstrat_cb+0x45/0x50
> 9e7bb738:  [<60114135>] xlog_sync+0x195/0x440
> 9e7bb778:  [<60114491>] xlog_state_release_iclog+0xb1/0xc0
> 9e7bb7a8:  [<60114ca9>] xlog_write+0x539/0x550
> 9e7bb858:  [<60114e60>] xfs_log_write+0x40/0x60
> 9e7bb888:  [<6011fbaa>] _xfs_trans_commit+0x19a/0x360
> 9e7bb8b8:  [<600838e2>] poison_obj+0x42/0x60
> 9e7bb8d0:  [<60082cb3>] dbg_redzone1+0x13/0x30
> 9e7bb8e8:  [<60083999>] cache_alloc_debugcheck_after+0x99/0x1c0
> 9e7bb918:  [<6008517b>] kmem_cache_alloc+0x8b/0x100
> 9e7bb958:  [<60128084>] kmem_zone_alloc+0x74/0xe0
> 9e7bb998:  [<60082ad9>] kmem_cache_size+0x9/0x10
> 9e7bb9a8:  [<60128124>] kmem_zone_zalloc+0x34/0x50
> 9e7bb9e8:  [<60121e8b>] xfs_dir_ialloc+0x13b/0x2e0
> 9e7bba58:  [<601f534b>] __down_write+0xb/0x10
> 9e7bbaa8:  [<60125b9e>] xfs_mkdir+0x37e/0x4b0
> 9e7bbb38:  [<601f5589>] _spin_unlock+0x9/0x10
> 9e7bbb78:  [<601301a4>] xfs_vn_mknod+0xf4/0x1a0
> 9e7bbbd8:  [<6013025e>] xfs_vn_mkdir+0xe/0x10
> 9e7bbbe8:  [<60091010>] vfs_mkdir+0x90/0xc0
> 9e7bbc18:  [<600934d6>] sys_mkdirat+0x106/0x120
> 9e7bbc88:  [<6008629b>] filp_close+0x4b/0x80
> 9e7bbce8:  [<60093503>] sys_mkdir+0x13/0x20
> 9e7bbcf8:  [<60019a70>] handle_syscall+0x50/0x80
> 9e7bbd18:  [<6002a10f>] userspace+0x44f/0x510
> 9e7bbfc8:  [<60016792>] fork_handler+0x62/0x70
> 
> I/O error in filesystem ("ram0") meta-data dev ram0 block 0x8002c       ("xlog_i
> odone") error 5 buf count 32768
> xfs_force_shutdown(ram0,0x2) called from line 1056 of file /home/npiggin/usr/src
> /linux-2.6/fs/xfs/xfs_log.c.  Return address = 0x000000006011370d
> Filesystem "ram0": Log I/O Error Detected.  Shutting down filesystem: ram0
> Please umount the filesystem, and rectify the problem(s)
> xfs_force_shutdown(ram0,0x2) called from line 818 of file /home/npiggin/usr/src/
> linux-2.6/fs/xfs/xfs_log.c.  Return address = 0x0000000060114e7d
> slab error in verify_redzone_free(): cache `xfs_log_ticket': double free detecte
> d
> Call Trace:
> 9e7bb998:  [<6008372f>] __slab_error+0x1f/0x30
> 9e7bb9a8:  [<60083cae>] cache_free_debugcheck+0x1ee/0x240
> 9e7bb9b0:  [<60112ef0>] xlog_ticket_put+0x10/0x20
> 9e7bb9e8:  [<60083f70>] kmem_cache_free+0x50/0xc0
> 9e7bba18:  [<60112ef0>] xlog_ticket_put+0x10/0x20
> 9e7bba28:  [<60114dc9>] xfs_log_done+0x59/0xb0
> 9e7bba68:  [<6011f5de>] xfs_trans_cancel+0x7e/0x140
> 9e7bbaa8:  [<60125a1e>] xfs_mkdir+0x1fe/0x4b0
> 9e7bbb38:  [<601f5589>] _spin_unlock+0x9/0x10
> 9e7bbb78:  [<601301a4>] xfs_vn_mknod+0xf4/0x1a0
> 9e7bbbd8:  [<6013025e>] xfs_vn_mkdir+0xe/0x10
> 9e7bbbe8:  [<60091010>] vfs_mkdir+0x90/0xc0
> 9e7bbc18:  [<600934d6>] sys_mkdirat+0x106/0x120
> 9e7bbc88:  [<6008629b>] filp_close+0x4b/0x80
> 9e7bbce8:  [<60093503>] sys_mkdir+0x13/0x20
> 9e7bbcf8:  [<60019a70>] handle_syscall+0x50/0x80
> 9e7bbd18:  [<6002a10f>] userspace+0x44f/0x510
> 9e7bbfc8:  [<60016792>] fork_handler+0x62/0x70

Now that is interesting.

We've got a rolling transaction in progress, and the commit of the
first part of the transaction has got the I/O error.  That frees the
transaction structure used during that commit, as well as the
ticket.

However, before we committed the initial transaction, we duplicated
the transaction structure to allow the transaction to continue to
track all the dirty objects in the first commit. That included
duplicating the pointer to the ticket.

Then the EIO is returned to mkdir code with the duplicated
transaction, which is then cancelled, and that frees the transaction
and the ticket it holds. However, we'd already freed the ticket.

Ok, we're only seeing this problem now because I recently modified
the ticket allocation to use a slab instead of a roll-your-own free
list structure that wouldn't have been poisoned. Nice to know that
this change did more than just remove code. ;)

This might take a little while to fix - a lot of code needs
auditing - but thanks for reporting the problem.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 09:27:46AM +1100, Dave Chinner wrote:
> On Tue, Oct 28, 2008 at 04:39:53PM +0100, Nick Piggin wrote:
> > On Wed, Oct 29, 2008 at 01:47:15AM +1100, npiggin@suse.de wrote:
> > I haven't seen any -EIO failures from XFS... maybe I'm just not doing the
> > right thing, or there is a caveat I'm not aware of.
> > 
> > All fault injections I noticed had a trace like this:
[...]
> 
> XFS reports bio errors through the I/O completion path, not the
> submission path.

Right, that's just to give you an indication of where it's failing...

 
> > And the kernel would sometimes say this:
> > Buffer I/O error on device ram0, logical block 279
> > lost page write due to I/O error on ram0
> > Buffer I/O error on device ram0, logical block 379
> > lost page write due to I/O error on ram0
> > Buffer I/O error on device ram0, logical block 389
> > lost page write due to I/O error on ram0
> 
> Yes - that's coming from end_buffer_async_write() when an error is
> reported in bio completion. This does:
> 
>  465                 set_bit(AS_EIO, &page->mapping->flags);
>  466                 set_buffer_write_io_error(bh);
>  467                 clear_buffer_uptodate(bh);
>  468                 SetPageError(page);
> 
> Hmmmm - do_fsync() calls filemap_fdatawait() which ends up in
> wait_on_page_writeback_range() which is appears to be checking the
> mapping flags for errors. I wonder why that error is not being
> propagated then? AFAICT both XFS and the fsync code are doing the
> right thing but somewhere the error has gone missing...

Yeah, I couldn't immediately see why nothing comes out. I'll do a bit
more digging.

 
> > I think I also saw a slab bug when running dbench with fault injection on.
> > Running latest Linus kernel.
[...]
>
> Now that is interesting.
> 
> We've got a rolling transaction in progress, and the commit of the
> first part of the transaction has got the I/O error.  That frees the
> transaction structure used during that commit, as well as the
> ticket.
> 
> However, before we committed the initial transaction, we duplicated
> the transaction structure to allow the transaction to continue to
> track all the dirty objects in the first commit. That included
> duplicating the pointer to the ticket.
> 
> Then the EIO is returned to mkdir code with the duplicated
> transaction, which is then cancelled, and that frees the transaction
> and the ticket it holds. However, we'd already freed the ticket.
> 
> Ok, we're only seeing this problem now because I recently modified
> the ticket allocation to use a slab instead of a roll-your-own free
> list structure that wouldn't have been poisoned. Nice to know that
> this change did more than just remove code. ;)
> 
> This might take a little while to fix - a lot of code needs
> auditing - but thanks for reporting the problem.

No problem, hope it helps.

Thanks,
Nick

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 09:27:46AM +1100, Dave Chinner wrote:
> On Tue, Oct 28, 2008 at 04:39:53PM +0100, Nick Piggin wrote:
> > 
> > I haven't seen any -EIO failures from XFS... maybe I'm just not doing the
> > right thing, or there is a caveat I'm not aware of.
> > 
> > All fault injections I noticed had a trace like this:
> > FAULT_INJECTION: forcing a failure
> > Call Trace:
> > 9f9cd758:  [<6019f1de>] random32+0xe/0x20
> > 9f9cd768:  [<601a31b9>] should_fail+0xd9/0x130
> > 9f9cd798:  [<6018d0c4>] generic_make_request+0x304/0x4e0
> > 9f9cd7a8:  [<60062301>] mempool_alloc+0x51/0x130
> > 9f9cd858:  [<6018e6bf>] submit_bio+0x4f/0xe0
> > 9f9cd8a8:  [<60165505>] xfs_submit_ioend_bio+0x25/0x40
> > 9f9cd8c8:  [<6016603c>] xfs_submit_ioend+0xbc/0xf0
> > 9f9cd908:  [<60166bf9>] xfs_page_state_convert+0x3d9/0x6a0
> > 9f9cd928:  [<6005d515>] delayacct_end+0x95/0xb0
> > 9f9cda08:  [<60166ffd>] xfs_vm_writepage+0x6d/0x110
> > 9f9cda18:  [<6006618b>] set_page_dirty+0x4b/0xd0
> > 9f9cda58:  [<60066115>] __writepage+0x15/0x40
> > 9f9cda78:  [<60066775>] write_cache_pages+0x255/0x470
> > 9f9cda90:  [<60066100>] __writepage+0x0/0x40
> > 9f9cdb98:  [<600669b0>] generic_writepages+0x20/0x30
> > 9f9cdba8:  [<60165ba3>] xfs_vm_writepages+0x53/0x70
> > 9f9cdbd8:  [<600669eb>] do_writepages+0x2b/0x40
> > 9f9cdbf8:  [<6006004c>] __filemap_fdatawrite_range+0x5c/0x70
> > 9f9cdc58:  [<6006026a>] filemap_fdatawrite+0x1a/0x20
> > 9f9cdc68:  [<600a7a05>] do_fsync+0x45/0xe0
> > 9f9cdc98:  [<6007794b>] sys_msync+0x14b/0x1d0
> > 9f9cdcf8:  [<60019a70>] handle_syscall+0x50/0x80
> > 9f9cdd18:  [<6002a10f>] userspace+0x44f/0x510
> > 9f9cdfc8:  [<60016792>] fork_handler+0x62/0x70
> 
> XFS reports bio errors through the I/O completion path, not the
> submission path.
> 
> > And the kernel would sometimes say this:
> > Buffer I/O error on device ram0, logical block 279
> > lost page write due to I/O error on ram0
> > Buffer I/O error on device ram0, logical block 379
> > lost page write due to I/O error on ram0
> > Buffer I/O error on device ram0, logical block 389
> > lost page write due to I/O error on ram0
> 
> Yes - that's coming from end_buffer_async_write() when an error is
> reported in bio completion. This does:
> 
>  465                 set_bit(AS_EIO, &page->mapping->flags);
>  466                 set_buffer_write_io_error(bh);
>  467                 clear_buffer_uptodate(bh);
>  468                 SetPageError(page);
> 
> Hmmmm - do_fsync() calls filemap_fdatawait() which ends up in
> wait_on_page_writeback_range() which is appears to be checking the
> mapping flags for errors. I wonder why that error is not being
> propagated then? AFAICT both XFS and the fsync code are doing the
> right thing but somewhere the error has gone missing...

This one-liner has it reporting EIO errors like a champion. I
don't know if you'll actually need to put this into the
linux API layer or not, but anyway the root cause of the problem
AFAIKS is this.
--

XFS: fix fsync errors not being propogated back to userspace.
---
Index: linux-2.6/fs/xfs/xfs_vnodeops.c
===================================================================
--- linux-2.6.orig/fs/xfs/xfs_vnodeops.c
+++ linux-2.6/fs/xfs/xfs_vnodeops.c
@@ -715,7 +715,7 @@ xfs_fsync(
 	/* capture size updates in I/O completion before writing the inode. */
 	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
 	if (error)
-		return XFS_ERROR(error);
+		return XFS_ERROR(-error);
 
 	/*
 	 * We always need to make sure that the required inode state is safe on

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 01:16:53AM +0100, Nick Piggin wrote:
> On Wed, Oct 29, 2008 at 09:27:46AM +1100, Dave Chinner wrote:
> > On Tue, Oct 28, 2008 at 04:39:53PM +0100, Nick Piggin wrote:
> > Yes - that's coming from end_buffer_async_write() when an error is
> > reported in bio completion. This does:
> > 
> >  465                 set_bit(AS_EIO, &page->mapping->flags);
> >  466                 set_buffer_write_io_error(bh);
> >  467                 clear_buffer_uptodate(bh);
> >  468                 SetPageError(page);
> > 
> > Hmmmm - do_fsync() calls filemap_fdatawait() which ends up in
> > wait_on_page_writeback_range() which is appears to be checking the
> > mapping flags for errors. I wonder why that error is not being
> > propagated then? AFAICT both XFS and the fsync code are doing the
> > right thing but somewhere the error has gone missing...
> 
> This one-liner has it reporting EIO errors like a champion. I
> don't know if you'll actually need to put this into the
> linux API layer or not, but anyway the root cause of the problem
> AFAIKS is this.
> --
> 
> XFS: fix fsync errors not being propogated back to userspace.
> ---
> Index: linux-2.6/fs/xfs/xfs_vnodeops.c
> ===================================================================
> --- linux-2.6.orig/fs/xfs/xfs_vnodeops.c
> +++ linux-2.6/fs/xfs/xfs_vnodeops.c
> @@ -715,7 +715,7 @@ xfs_fsync(
>  	/* capture size updates in I/O completion before writing the inode. */
>  	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
>  	if (error)
> -		return XFS_ERROR(error);
> +		return XFS_ERROR(-error);

<groan>

Yeah, that'd do it. Good catch. I can't believe I recently fixed a
bug that touched these lines of code without noticing the inversion.
Sometimes I wonder if we should just conver the entire of XFS to
return negative errors - mistakes in handling negative error numbers
in the core XFS code happen all the time.

FWIW, the core issue here is that we've got to do the
filemap_fdatawait() call in the ->fsync method because ->fsync
gets called before we've waited for the data I/O to complete.
XFS updates inode state on I/O completion, so we *must* wait
for data I/O to complete before logging the inode changes. I
think btrfs has the same problem....

Thanks again, Nick.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 02:16:45PM +1100, Dave Chinner wrote:
> On Wed, Oct 29, 2008 at 01:16:53AM +0100, Nick Piggin wrote:
> > XFS: fix fsync errors not being propogated back to userspace.
> > ---
> > Index: linux-2.6/fs/xfs/xfs_vnodeops.c
> > ===================================================================
> > --- linux-2.6.orig/fs/xfs/xfs_vnodeops.c
> > +++ linux-2.6/fs/xfs/xfs_vnodeops.c
> > @@ -715,7 +715,7 @@ xfs_fsync(
> >  	/* capture size updates in I/O completion before writing the inode. */
> >  	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
> >  	if (error)
> > -		return XFS_ERROR(error);
> > +		return XFS_ERROR(-error);
> 
> <groan>
> 
> Yeah, that'd do it. Good catch. I can't believe I recently fixed a
> bug that touched these lines of code without noticing the inversion.
> Sometimes I wonder if we should just conver the entire of XFS to
> return negative errors - mistakes in handling negative error numbers
> in the core XFS code happen all the time.

Ok, I was right - these problems happen all the time. The above call
should really call xfs_flush_pages() to do the flush and wait. I
note that xfs_flush_pages() returns negative errors, and all the
callers expect positive errors. I bet the same occurs for
xfs_flushinval_pages() and xfs_tosspages() which are the wrappers
that core XFS code is supposed to be using for flushing and
invalidating file ranges....

I'll write up a patch that covers all of these.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 02:26:01PM +1100, Dave Chinner wrote:
> On Wed, Oct 29, 2008 at 02:16:45PM +1100, Dave Chinner wrote:
> > On Wed, Oct 29, 2008 at 01:16:53AM +0100, Nick Piggin wrote:
> > > XFS: fix fsync errors not being propogated back to userspace.
> > > ---
> > > Index: linux-2.6/fs/xfs/xfs_vnodeops.c
> > > ===================================================================
> > > --- linux-2.6.orig/fs/xfs/xfs_vnodeops.c
> > > +++ linux-2.6/fs/xfs/xfs_vnodeops.c
> > > @@ -715,7 +715,7 @@ xfs_fsync(
> > >  	/* capture size updates in I/O completion before writing the inode. */
> > >  	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
> > >  	if (error)
> > > -		return XFS_ERROR(error);
> > > +		return XFS_ERROR(-error);
> > 
> > <groan>
> > 
> > Yeah, that'd do it. Good catch. I can't believe I recently fixed a
> > bug that touched these lines of code without noticing the inversion.
> > Sometimes I wonder if we should just conver the entire of XFS to
> > return negative errors - mistakes in handling negative error numbers
> > in the core XFS code happen all the time.
> 
> Ok, I was right - these problems happen all the time. The above call
> should really call xfs_flush_pages() to do the flush and wait. I
> note that xfs_flush_pages() returns negative errors, and all the
> callers expect positive errors. I bet the same occurs for
> xfs_flushinval_pages() and xfs_tosspages() which are the wrappers
> that core XFS code is supposed to be using for flushing and
> invalidating file ranges....

Just be careful -- in your xfs_flush_pages, I think after the first
filemap_fdatawrite, the mapping may no longer be tagged with
PAGECACHE_TAG_DIRTY, so you may not pick up those writeback ones
you need to wait on.

Might need a different variant, or we could just bite the bullet and
push through the ->fsync conversion so you get full control of the
writeout.

BTW. the Linux pagecache APIs should support range operations quite
nicely for these. Any reason not to use them (it looks like the
wrappers can take ranges)?

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 05:11:12AM +0100, Nick Piggin wrote:
> On Wed, Oct 29, 2008 at 02:26:01PM +1100, Dave Chinner wrote:
> > On Wed, Oct 29, 2008 at 02:16:45PM +1100, Dave Chinner wrote:
> > > On Wed, Oct 29, 2008 at 01:16:53AM +0100, Nick Piggin wrote:
> > > > XFS: fix fsync errors not being propogated back to userspace.
> > > > ---
> > > > Index: linux-2.6/fs/xfs/xfs_vnodeops.c
> > > > ===================================================================
> > > > --- linux-2.6.orig/fs/xfs/xfs_vnodeops.c
> > > > +++ linux-2.6/fs/xfs/xfs_vnodeops.c
> > > > @@ -715,7 +715,7 @@ xfs_fsync(
> > > >  	/* capture size updates in I/O completion before writing the inode. */
> > > >  	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
> > > >  	if (error)
> > > > -		return XFS_ERROR(error);
> > > > +		return XFS_ERROR(-error);
> > > 
> > > <groan>
> > > 
> > > Yeah, that'd do it. Good catch. I can't believe I recently fixed a
> > > bug that touched these lines of code without noticing the inversion.
> > > Sometimes I wonder if we should just conver the entire of XFS to
> > > return negative errors - mistakes in handling negative error numbers
> > > in the core XFS code happen all the time.
> > 
> > Ok, I was right - these problems happen all the time. The above call
> > should really call xfs_flush_pages() to do the flush and wait. I
> > note that xfs_flush_pages() returns negative errors, and all the
> > callers expect positive errors. I bet the same occurs for
> > xfs_flushinval_pages() and xfs_tosspages() which are the wrappers
> > that core XFS code is supposed to be using for flushing and
> > invalidating file ranges....
> 
> Just be careful -- in your xfs_flush_pages, I think after the first
> filemap_fdatawrite, the mapping may no longer be tagged with
> PAGECACHE_TAG_DIRTY, so you may not pick up those writeback ones
> you need to wait on.

Yes, I realised this as soon as I looked at the code.
I added xfs_wait_on_pages() to do this wait. ;)

> Might need a different variant, or we could just bite the bullet and
> push through the ->fsync conversion so you get full control of the
> writeout.

Not important right now, though....

> BTW. the Linux pagecache APIs should support range operations quite
> nicely for these. Any reason not to use them (it looks like the
> wrappers can take ranges)?

Because I haven't got around to modifying these wrappers now that
the range primitives are in place - XFS inherited the range
operations from Irix and have sat unimplemented since being ported
to Linux.

The patch below should fix this entire class of error value screwup
in XFS. I've just started running it through XFSQA, so it's not
really tested yet.

FWIW, your entire patch series made it through XFSQA without any new
regressions, so it looks good from that POV.

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

XFS: fix error inversion problems with data flushing

XFS gets the sign of the error wrong in several places when
gathering the error from generic linux functions. These functions
return negative error values, while the core XFS code returns
positive error values. Hence when XFS inverts the error to be
returned to the VFS, it can incorrectly invert a negative
error and this error will be ignored by the syscall return.

Fix all the problems related to calling filemap_* functions.

Problem initially identified by Nick Piggin in xfs_fsync().

Signed-off-by: Dave Chinner <david@fromorbit.com>
---
 fs/xfs/linux-2.6/xfs_fs_subr.c |   23 ++++++++++++++++++++---
 fs/xfs/linux-2.6/xfs_lrw.c     |    2 +-
 fs/xfs/linux-2.6/xfs_super.c   |   13 +++++++++----
 fs/xfs/xfs_vnodeops.c          |    2 +-
 fs/xfs/xfs_vnodeops.h          |    1 +
 5 files changed, 32 insertions(+), 9 deletions(-)

diff --git a/fs/xfs/linux-2.6/xfs_fs_subr.c b/fs/xfs/linux-2.6/xfs_fs_subr.c
index 36caa6d..5aeb777 100644
--- a/fs/xfs/linux-2.6/xfs_fs_subr.c
+++ b/fs/xfs/linux-2.6/xfs_fs_subr.c
@@ -24,6 +24,10 @@ int  fs_noerr(void) { return 0; }
 int  fs_nosys(void) { return ENOSYS; }
 void fs_noval(void) { return; }
 
+/*
+ * note: all filemap functions return negative error codes. These
+ * need to be inverted before returning to the xfs core functions.
+ */
 void
 xfs_tosspages(
 	xfs_inode_t	*ip,
@@ -53,7 +57,7 @@ xfs_flushinval_pages(
 		if (!ret)
 			truncate_inode_pages(mapping, first);
 	}
-	return ret;
+	return -ret;
 }
 
 int
@@ -72,10 +76,23 @@ xfs_flush_pages(
 		xfs_iflags_clear(ip, XFS_ITRUNCATED);
 		ret = filemap_fdatawrite(mapping);
 		if (flags & XFS_B_ASYNC)
-			return ret;
+			return -ret;
 		ret2 = filemap_fdatawait(mapping);
 		if (!ret)
 			ret = ret2;
 	}
-	return ret;
+	return -ret;
+}
+
+int
+xfs_wait_on_pages(
+	xfs_inode_t	*ip,
+	xfs_off_t	first,
+	xfs_off_t	last)
+{
+	struct address_space *mapping = VFS_I(ip)->i_mapping;
+
+	if (mapping_tagged(mapping, PAGECACHE_TAG_WRITEBACK))
+		return -filemap_fdatawait(mapping);
+	return 0;
 }
diff --git a/fs/xfs/linux-2.6/xfs_lrw.c b/fs/xfs/linux-2.6/xfs_lrw.c
index 1957e53..4959c87 100644
--- a/fs/xfs/linux-2.6/xfs_lrw.c
+++ b/fs/xfs/linux-2.6/xfs_lrw.c
@@ -243,7 +243,7 @@ xfs_read(
 
 	if (unlikely(ioflags & IO_ISDIRECT)) {
 		if (inode->i_mapping->nrpages)
-			ret = xfs_flushinval_pages(ip, (*offset & PAGE_CACHE_MASK),
+			ret = -xfs_flushinval_pages(ip, (*offset & PAGE_CACHE_MASK),
 						    -1, FI_REMAPF_LOCKED);
 		mutex_unlock(&inode->i_mutex);
 		if (ret) {
diff --git a/fs/xfs/linux-2.6/xfs_super.c b/fs/xfs/linux-2.6/xfs_super.c
index 9dc977d..c5cfc1e 100644
--- a/fs/xfs/linux-2.6/xfs_super.c
+++ b/fs/xfs/linux-2.6/xfs_super.c
@@ -1012,21 +1012,26 @@ xfs_fs_write_inode(
 	struct inode		*inode,
 	int			sync)
 {
+	struct xfs_inode	*ip = XFS_I(inode);
 	int			error = 0;
 	int			flags = 0;
 
-	xfs_itrace_entry(XFS_I(inode));
+	xfs_itrace_entry(ip);
 	if (sync) {
-		filemap_fdatawait(inode->i_mapping);
+		error = xfs_wait_on_pages(ip, 0, -1);
+		if (error)
+			goto out_error;
 		flags |= FLUSH_SYNC;
 	}
-	error = xfs_inode_flush(XFS_I(inode), flags);
+	error = xfs_inode_flush(ip, flags);
+
+out_error:
 	/*
 	 * if we failed to write out the inode then mark
 	 * it dirty again so we'll try again later.
 	 */
 	if (error)
-		xfs_mark_inode_dirty_sync(XFS_I(inode));
+		xfs_mark_inode_dirty_sync(ip);
 
 	return -error;
 }
diff --git a/fs/xfs/xfs_vnodeops.c b/fs/xfs/xfs_vnodeops.c
index 2e2fbd9..5809c42 100644
--- a/fs/xfs/xfs_vnodeops.c
+++ b/fs/xfs/xfs_vnodeops.c
@@ -713,7 +713,7 @@ xfs_fsync(
 		return XFS_ERROR(EIO);
 
 	/* capture size updates in I/O completion before writing the inode. */
-	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
+	error = xfs_wait_on_pages(ip, 0, -1);
 	if (error)
 		return XFS_ERROR(error);
 
diff --git a/fs/xfs/xfs_vnodeops.h b/fs/xfs/xfs_vnodeops.h
index e932a96..f9cd376 100644
--- a/fs/xfs/xfs_vnodeops.h
+++ b/fs/xfs/xfs_vnodeops.h
@@ -78,5 +78,6 @@ int xfs_flushinval_pages(struct xfs_inode *ip, xfs_off_t first,
 		xfs_off_t last, int fiopt);
 int xfs_flush_pages(struct xfs_inode *ip, xfs_off_t first,
 		xfs_off_t last, uint64_t flags, int fiopt);
+int xfs_wait_on_pages(struct xfs_inode *ip, xfs_off_t first, xfs_off_t last);
 
 #endif /* _XFS_VNODEOPS_H */

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 03:57:07PM +1100, Dave Chinner wrote:
> On Wed, Oct 29, 2008 at 05:11:12AM +0100, Nick Piggin wrote:
> > Just be careful -- in your xfs_flush_pages, I think after the first
> > filemap_fdatawrite, the mapping may no longer be tagged with
> > PAGECACHE_TAG_DIRTY, so you may not pick up those writeback ones
> > you need to wait on.
> 
> Yes, I realised this as soon as I looked at the code.
> I added xfs_wait_on_pages() to do this wait. ;)
 
Oh good.


> > Might need a different variant, or we could just bite the bullet and
> > push through the ->fsync conversion so you get full control of the
> > writeout.
> 
> Not important right now, though....

OK.

 
> > BTW. the Linux pagecache APIs should support range operations quite
> > nicely for these. Any reason not to use them (it looks like the
> > wrappers can take ranges)?
> 
> Because I haven't got around to modifying these wrappers now that
> the range primitives are in place - XFS inherited the range
> operations from Irix and have sat unimplemented since being ported
> to Linux.

OK, fair enough. Just something easy to stick on a todo list somewhere ;)
Probably doesn't make much difference now, but we might start seeing
apps using range syncs.
 

> The patch below should fix this entire class of error value screwup
> in XFS. I've just started running it through XFSQA, so it's not
> really tested yet.

I'll sanity check it by running it through my basic fault injection
tests here.


> FWIW, your entire patch series made it through XFSQA without any new
> regressions, so it looks good from that POV.

Thanks, very good to know.

> 
> Cheers,
> 
> Dave.
> -- 
> Dave Chinner
> david@fromorbit.com
> 
> XFS: fix error inversion problems with data flushing
> 
> XFS gets the sign of the error wrong in several places when
> gathering the error from generic linux functions. These functions
> return negative error values, while the core XFS code returns
> positive error values. Hence when XFS inverts the error to be
> returned to the VFS, it can incorrectly invert a negative
> error and this error will be ignored by the syscall return.
> 
> Fix all the problems related to calling filemap_* functions.
> 
> Problem initially identified by Nick Piggin in xfs_fsync().
> 
> Signed-off-by: Dave Chinner <david@fromorbit.com>
> ---
>  fs/xfs/linux-2.6/xfs_fs_subr.c |   23 ++++++++++++++++++++---
>  fs/xfs/linux-2.6/xfs_lrw.c     |    2 +-
>  fs/xfs/linux-2.6/xfs_super.c   |   13 +++++++++----
>  fs/xfs/xfs_vnodeops.c          |    2 +-
>  fs/xfs/xfs_vnodeops.h          |    1 +
>  5 files changed, 32 insertions(+), 9 deletions(-)
> 
> diff --git a/fs/xfs/linux-2.6/xfs_fs_subr.c b/fs/xfs/linux-2.6/xfs_fs_subr.c
> index 36caa6d..5aeb777 100644
> --- a/fs/xfs/linux-2.6/xfs_fs_subr.c
> +++ b/fs/xfs/linux-2.6/xfs_fs_subr.c
> @@ -24,6 +24,10 @@ int  fs_noerr(void) { return 0; }
>  int  fs_nosys(void) { return ENOSYS; }
>  void fs_noval(void) { return; }
>  
> +/*
> + * note: all filemap functions return negative error codes. These
> + * need to be inverted before returning to the xfs core functions.
> + */
>  void
>  xfs_tosspages(
>  	xfs_inode_t	*ip,
> @@ -53,7 +57,7 @@ xfs_flushinval_pages(
>  		if (!ret)
>  			truncate_inode_pages(mapping, first);
>  	}
> -	return ret;
> +	return -ret;
>  }
>  
>  int
> @@ -72,10 +76,23 @@ xfs_flush_pages(
>  		xfs_iflags_clear(ip, XFS_ITRUNCATED);
>  		ret = filemap_fdatawrite(mapping);
>  		if (flags & XFS_B_ASYNC)
> -			return ret;
> +			return -ret;
>  		ret2 = filemap_fdatawait(mapping);
>  		if (!ret)
>  			ret = ret2;
>  	}
> -	return ret;
> +	return -ret;
> +}
> +
> +int
> +xfs_wait_on_pages(
> +	xfs_inode_t	*ip,
> +	xfs_off_t	first,
> +	xfs_off_t	last)
> +{
> +	struct address_space *mapping = VFS_I(ip)->i_mapping;
> +
> +	if (mapping_tagged(mapping, PAGECACHE_TAG_WRITEBACK))
> +		return -filemap_fdatawait(mapping);
> +	return 0;
>  }
> diff --git a/fs/xfs/linux-2.6/xfs_lrw.c b/fs/xfs/linux-2.6/xfs_lrw.c
> index 1957e53..4959c87 100644
> --- a/fs/xfs/linux-2.6/xfs_lrw.c
> +++ b/fs/xfs/linux-2.6/xfs_lrw.c
> @@ -243,7 +243,7 @@ xfs_read(
>  
>  	if (unlikely(ioflags & IO_ISDIRECT)) {
>  		if (inode->i_mapping->nrpages)
> -			ret = xfs_flushinval_pages(ip, (*offset & PAGE_CACHE_MASK),
> +			ret = -xfs_flushinval_pages(ip, (*offset & PAGE_CACHE_MASK),
>  						    -1, FI_REMAPF_LOCKED);
>  		mutex_unlock(&inode->i_mutex);
>  		if (ret) {
> diff --git a/fs/xfs/linux-2.6/xfs_super.c b/fs/xfs/linux-2.6/xfs_super.c
> index 9dc977d..c5cfc1e 100644
> --- a/fs/xfs/linux-2.6/xfs_super.c
> +++ b/fs/xfs/linux-2.6/xfs_super.c
> @@ -1012,21 +1012,26 @@ xfs_fs_write_inode(
>  	struct inode		*inode,
>  	int			sync)
>  {
> +	struct xfs_inode	*ip = XFS_I(inode);
>  	int			error = 0;
>  	int			flags = 0;
>  
> -	xfs_itrace_entry(XFS_I(inode));
> +	xfs_itrace_entry(ip);
>  	if (sync) {
> -		filemap_fdatawait(inode->i_mapping);
> +		error = xfs_wait_on_pages(ip, 0, -1);
> +		if (error)
> +			goto out_error;
>  		flags |= FLUSH_SYNC;
>  	}
> -	error = xfs_inode_flush(XFS_I(inode), flags);
> +	error = xfs_inode_flush(ip, flags);
> +
> +out_error:
>  	/*
>  	 * if we failed to write out the inode then mark
>  	 * it dirty again so we'll try again later.
>  	 */
>  	if (error)
> -		xfs_mark_inode_dirty_sync(XFS_I(inode));
> +		xfs_mark_inode_dirty_sync(ip);
>  
>  	return -error;
>  }
> diff --git a/fs/xfs/xfs_vnodeops.c b/fs/xfs/xfs_vnodeops.c
> index 2e2fbd9..5809c42 100644
> --- a/fs/xfs/xfs_vnodeops.c
> +++ b/fs/xfs/xfs_vnodeops.c
> @@ -713,7 +713,7 @@ xfs_fsync(
>  		return XFS_ERROR(EIO);
>  
>  	/* capture size updates in I/O completion before writing the inode. */
> -	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
> +	error = xfs_wait_on_pages(ip, 0, -1);
>  	if (error)
>  		return XFS_ERROR(error);
>  
> diff --git a/fs/xfs/xfs_vnodeops.h b/fs/xfs/xfs_vnodeops.h
> index e932a96..f9cd376 100644
> --- a/fs/xfs/xfs_vnodeops.h
> +++ b/fs/xfs/xfs_vnodeops.h
> @@ -78,5 +78,6 @@ int xfs_flushinval_pages(struct xfs_inode *ip, xfs_off_t first,
>  		xfs_off_t last, int fiopt);
>  int xfs_flush_pages(struct xfs_inode *ip, xfs_off_t first,
>  		xfs_off_t last, uint64_t flags, int fiopt);
> +int xfs_wait_on_pages(struct xfs_inode *ip, xfs_off_t first, xfs_off_t last);
>  
>  #endif /* _XFS_VNODEOPS_H */

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Christoph Hellwig]

On Wed, Oct 29, 2008 at 02:26:01PM +1100, Dave Chinner wrote:
> Ok, I was right - these problems happen all the time. The above call
> should really call xfs_flush_pages() to do the flush and wait. I
> note that xfs_flush_pages() returns negative errors, and all the
> callers expect positive errors. I bet the same occurs for
> xfs_flushinval_pages() and xfs_tosspages() which are the wrappers
> that core XFS code is supposed to be using for flushing and
> invalidating file ranges....
> 
> I'll write up a patch that covers all of these.

Can you also merge xfs_fsync into xfs_file_fsync while you're at it?
The split newer made any sense as xfs_fsync is as Linux-specific as it
gets and shouldn't be in the pseudo OS-independent layer.

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 05:13:26AM -0400, Christoph Hellwig wrote:
> On Wed, Oct 29, 2008 at 02:26:01PM +1100, Dave Chinner wrote:
> > Ok, I was right - these problems happen all the time. The above call
> > should really call xfs_flush_pages() to do the flush and wait. I
> > note that xfs_flush_pages() returns negative errors, and all the
> > callers expect positive errors. I bet the same occurs for
> > xfs_flushinval_pages() and xfs_tosspages() which are the wrappers
> > that core XFS code is supposed to be using for flushing and
> > invalidating file ranges....
> > 
> > I'll write up a patch that covers all of these.
> 
> Can you also merge xfs_fsync into xfs_file_fsync while you're at it?
> The split newer made any sense as xfs_fsync is as Linux-specific as it
> gets and shouldn't be in the pseudo OS-independent layer.

I'll do that as a separate patch - it's not really part of a "fix
error value inversion" bug fix....

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Christoph Hellwig]

On Thu, Oct 30, 2008 at 08:42:02AM +1100, Dave Chinner wrote:
> I'll do that as a separate patch - it's not really part of a "fix
> error value inversion" bug fix....

Well it is kindof.  Because we'd call Linux library functions directly
from the method we skip to places that need sign conversion and could
possibly go wrong.  But if you want a separate patch that's fine with
me too.

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 05:45:03PM -0400, Christoph Hellwig wrote:
> On Thu, Oct 30, 2008 at 08:42:02AM +1100, Dave Chinner wrote:
> > I'll do that as a separate patch - it's not really part of a "fix
> > error value inversion" bug fix....
> 
> Well it is kindof.  Because we'd call Linux library functions directly
> from the method we skip to places that need sign conversion and could
> possibly go wrong.  But if you want a separate patch that's fine with
> me too.

Well, the patch I posted to fix the sign problems covered the
xfs_flush_pages() and xfs_flushinval_pages() functions that we
returning negative errors to core code, and none of the core code
inverted that before returning it to functions that inverted it.
That's a general problem that affected truncate, direct I/O,
getbmap, etc, as well as fsync...

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 02:16:45PM +1100, Dave Chinner wrote:
> On Wed, Oct 29, 2008 at 01:16:53AM +0100, Nick Piggin wrote:
> > On Wed, Oct 29, 2008 at 09:27:46AM +1100, Dave Chinner wrote:
> > > On Tue, Oct 28, 2008 at 04:39:53PM +0100, Nick Piggin wrote:
> > > Yes - that's coming from end_buffer_async_write() when an error is
> > > reported in bio completion. This does:
> > > 
> > >  465                 set_bit(AS_EIO, &page->mapping->flags);
> > >  466                 set_buffer_write_io_error(bh);
> > >  467                 clear_buffer_uptodate(bh);
> > >  468                 SetPageError(page);
> > > 
> > > Hmmmm - do_fsync() calls filemap_fdatawait() which ends up in
> > > wait_on_page_writeback_range() which is appears to be checking the
> > > mapping flags for errors. I wonder why that error is not being
> > > propagated then? AFAICT both XFS and the fsync code are doing the
> > > right thing but somewhere the error has gone missing...
> > 
> > This one-liner has it reporting EIO errors like a champion. I
> > don't know if you'll actually need to put this into the
> > linux API layer or not, but anyway the root cause of the problem
> > AFAIKS is this.
> > --
> > 
> > XFS: fix fsync errors not being propogated back to userspace.
> > ---
> > Index: linux-2.6/fs/xfs/xfs_vnodeops.c
> > ===================================================================
> > --- linux-2.6.orig/fs/xfs/xfs_vnodeops.c
> > +++ linux-2.6/fs/xfs/xfs_vnodeops.c
> > @@ -715,7 +715,7 @@ xfs_fsync(
> >  	/* capture size updates in I/O completion before writing the inode. */
> >  	error = filemap_fdatawait(VFS_I(ip)->i_mapping);
> >  	if (error)
> > -		return XFS_ERROR(error);
> > +		return XFS_ERROR(-error);
> 
> <groan>
> 
> Yeah, that'd do it. Good catch. I can't believe I recently fixed a
> bug that touched these lines of code without noticing the inversion.
> Sometimes I wonder if we should just conver the entire of XFS to
> return negative errors - mistakes in handling negative error numbers
> in the core XFS code happen all the time.

Heh, yeah it seems a bit tricky. BTW. feel free to add
Signed-off-by: Nick Piggin <npiggin@suse.de>
if you would like to merge it, or alternatively if you fix it another
way then I can rerun the test in 2 minutes if it is not 100% obviously
correct.

BTW. XFS seems to really be a lot more consistent than ext3 (ordered)
in reporting EIO with this change in place. I don't know why exactly,
but in ext3 I can see hundreds or thousands of failures injected in this
manner:

FAULT_INJECTION: forcing a failure
Call Trace:
9ebe17f8:  [<6019f34e>] random32+0xe/0x20
9ebe1808:  [<601a3329>] should_fail+0xd9/0x130
9ebe1838:  [<6018d234>] generic_make_request+0x304/0x4e0
9ebe1848:  [<600622e1>] mempool_alloc+0x51/0x130
9ebe18f8:  [<6018e82f>] submit_bio+0x4f/0xe0
9ebe1948:  [<600a8969>] submit_bh+0xd9/0x130
9ebe1978:  [<600aab08>] __block_write_full_page+0x198/0x310
9ebe1988:  [<600a8487>] alloc_buffer_head+0x37/0x50
9ebe19a0:  [<600f6ec0>] ext3_get_block+0x0/0x110
9ebe19d8:  [<600f6ec0>] ext3_get_block+0x0/0x110
9ebe19e8:  [<600aad48>] block_write_full_page+0xc8/0x100
9ebe1a38:  [<600f8951>] ext3_ordered_writepage+0xd1/0x180
9ebe1a48:  [<6006616b>] set_page_dirty+0x4b/0xd0
9ebe1a88:  [<600660f5>] __writepage+0x15/0x40
9ebe1aa8:  [<60066755>] write_cache_pages+0x255/0x470
9ebe1ac0:  [<600660e0>] __writepage+0x0/0x40
9ebe1bc8:  [<60066990>] generic_writepages+0x20/0x30
9ebe1bd8:  [<600669db>] do_writepages+0x3b/0x40
9ebe1bf8:  [<6006006c>] __filemap_fdatawrite_range+0x5c/0x70
9ebe1c58:  [<6006028a>] filemap_fdatawrite+0x1a/0x20
9ebe1c68:  [<600a7a15>] do_fsync+0x45/0xe0
9ebe1c98:  [<6007792b>] sys_msync+0x14b/0x1d0
9ebe1cf8:  [<60019a70>] handle_syscall+0x50/0x80
9ebe1d18:  [<6002a10f>] userspace+0x44f/0x510
9ebe1fc8:  [<60016792>] fork_handler+0x62/0x70

Buffer I/O error on device ram0, logical block 8228
lost page write due to I/O error on ram0

But eventually the filesystem aborts when we get a journal writing error,
and sometimes I see a single EIO to msync, sometimes not (cc ext3 list).

Wheras XFS reports a lot more EIOs as it goes...

If ext3 guys have any suggestions, I could test them out.

 
> FWIW, the core issue here is that we've got to do the
> filemap_fdatawait() call in the ->fsync method because ->fsync
> gets called before we've waited for the data I/O to complete.
> XFS updates inode state on I/O completion, so we *must* wait
> for data I/O to complete before logging the inode changes. I
> think btrfs has the same problem....

Interesting. Does that mean you can do without the final filemap_fdatawait?
Can you do the first fdatawait without i_mutex held?

There was some talk IIRC about moving all this logic into the filesystem
to provide more flexibility here. If there is still enough interest,
we should get that moving...


> Thanks again, Nick.

No problem.

Thanks,
Nick

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 05:00:14AM +0100, Nick Piggin wrote:
> On Wed, Oct 29, 2008 at 02:16:45PM +1100, Dave Chinner wrote:
> > FWIW, the core issue here is that we've got to do the
> > filemap_fdatawait() call in the ->fsync method because ->fsync
> > gets called before we've waited for the data I/O to complete.
> > XFS updates inode state on I/O completion, so we *must* wait
> > for data I/O to complete before logging the inode changes. I
> > think btrfs has the same problem....
> 
> Interesting. Does that mean you can do without the final filemap_fdatawait?

We could, yes.

> Can you do the first fdatawait without i_mutex held?

I don't see why not - I/O completion is only touching the XFS inode.
XFS has it's own inode locks for I/O and inode exclusion, and the
mapping tree lock protects the tree walk that the fdatawait is
doing...

> There was some talk IIRC about moving all this logic into the filesystem
> to provide more flexibility here. If there is still enough interest,
> we should get that moving...

It would simplify some of the code in XFS, that's for sure ;)

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Christoph Hellwig]

On Wed, Oct 29, 2008 at 02:16:45PM +1100, Dave Chinner wrote:
> Yeah, that'd do it. Good catch. I can't believe I recently fixed a
> bug that touched these lines of code without noticing the inversion.
> Sometimes I wonder if we should just conver the entire of XFS to
> return negative errors - mistakes in handling negative error numbers
> in the core XFS code happen all the time.
> 
> FWIW, the core issue here is that we've got to do the
> filemap_fdatawait() call in the ->fsync method because ->fsync
> gets called before we've waited for the data I/O to complete.
> XFS updates inode state on I/O completion, so we *must* wait
> for data I/O to complete before logging the inode changes. I
> think btrfs has the same problem....

Yes.  I have patches to fix this by changing what ->fsync does and
how it's called.  I really need to get them out on the list.

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 05:12:03AM -0400, Christoph Hellwig wrote:
> On Wed, Oct 29, 2008 at 02:16:45PM +1100, Dave Chinner wrote:
> > Yeah, that'd do it. Good catch. I can't believe I recently fixed a
> > bug that touched these lines of code without noticing the inversion.
> > Sometimes I wonder if we should just conver the entire of XFS to
> > return negative errors - mistakes in handling negative error numbers
> > in the core XFS code happen all the time.
> > 
> > FWIW, the core issue here is that we've got to do the
> > filemap_fdatawait() call in the ->fsync method because ->fsync
> > gets called before we've waited for the data I/O to complete.
> > XFS updates inode state on I/O completion, so we *must* wait
> > for data I/O to complete before logging the inode changes. I
> > think btrfs has the same problem....
> 
> Yes.  I have patches to fix this by changing what ->fsync does and
> how it's called.  I really need to get them out on the list.

Please do.

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Christoph Hellwig]

On Wed, Oct 29, 2008 at 10:21:43AM +0100, Nick Piggin wrote:
> Please do.

Well, there's one stumling block I haven't made progress on yet:

I've changed the prototype of ->fsync to lose the dentry as we should
always have a valid file struct.  Except that nfsd doesn't on
directories.  So I either need to fake up a file there, or bail out
and add a ->dir_sync export operation that needs just a dentry.

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 05:44:17AM -0400, Christoph Hellwig wrote:
> On Wed, Oct 29, 2008 at 10:21:43AM +0100, Nick Piggin wrote:
> > Please do.
> 
> Well, there's one stumling block I haven't made progress on yet:
> 
> I've changed the prototype of ->fsync to lose the dentry as we should
> always have a valid file struct.  Except that nfsd doesn't on
> directories.  So I either need to fake up a file there, or bail out
> and add a ->dir_sync export operation that needs just a dentry.

OK. I don't know much about hthat code, but I would think nfsd
should look as close to the syscall layer as possible. I guess
there must be something prohibitive (some protocol semantics?).

Is there anything that particularly makes it a file operation
as opposed to an inode operation?

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Jamie Lokier]

Nick Piggin wrote:
> On Wed, Oct 29, 2008 at 05:44:17AM -0400, Christoph Hellwig wrote:
> > On Wed, Oct 29, 2008 at 10:21:43AM +0100, Nick Piggin wrote:
> > > Please do.
> > 
> > Well, there's one stumling block I haven't made progress on yet:
> > 
> > I've changed the prototype of ->fsync to lose the dentry as we should
> > always have a valid file struct.  Except that nfsd doesn't on
> > directories.  So I either need to fake up a file there, or bail out
> > and add a ->dir_sync export operation that needs just a dentry.
> 
> OK. I don't know much about hthat code, but I would think nfsd
> should look as close to the syscall layer as possible. I guess
> there must be something prohibitive (some protocol semantics?).
> 
> Is there anything that particularly makes it a file operation
> as opposed to an inode operation?

In principle, is fsync() required to flush all dirty data written
through any file descriptor ever, or just dirty data written through
the file descriptor used for fsync()?

-- Jamie

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Ric Wheeler]

Jamie Lokier wrote:
> Nick Piggin wrote:
>   
>> On Wed, Oct 29, 2008 at 05:44:17AM -0400, Christoph Hellwig wrote:
>>     
>>> On Wed, Oct 29, 2008 at 10:21:43AM +0100, Nick Piggin wrote:
>>>       
>>>> Please do.
>>>>         
>>> Well, there's one stumling block I haven't made progress on yet:
>>>
>>> I've changed the prototype of ->fsync to lose the dentry as we should
>>> always have a valid file struct.  Except that nfsd doesn't on
>>> directories.  So I either need to fake up a file there, or bail out
>>> and add a ->dir_sync export operation that needs just a dentry.
>>>       
>> OK. I don't know much about hthat code, but I would think nfsd
>> should look as close to the syscall layer as possible. I guess
>> there must be something prohibitive (some protocol semantics?).
>>
>> Is there anything that particularly makes it a file operation
>> as opposed to an inode operation?
>>     
>
> In principle, is fsync() required to flush all dirty data written
> through any file descriptor ever, or just dirty data written through
> the file descriptor used for fsync()?
>
> -- Jamie
> --
>   

Is a pointer to what seems to be the official posix spec for this - it 
is definitely per file descriptor, not per file system, etc...

What can happen by side effect (depending on the implementation) is that 
you can actually force out all data for any file. I found that you can 
approach non-fsync speeds for an fsync per file workload by simply 
writing all of the files out, then going back and fsync'ing them one at 
a time (last file first makes a bit of a difference). With that 
technique, you do get the hard promise of full data integrity and high 
speed. This is useful when you want to do bulk writes (tar, etc)

ric

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Chris Mason]

On Wed, 2008-10-29 at 09:32 -0400, Ric Wheeler wrote:
> Jamie Lokier wrote:

> >> Is there anything that particularly makes it a file operation
> >> as opposed to an inode operation?
> >>     
> >
> > In principle, is fsync() required to flush all dirty data written
> > through any file descriptor ever, or just dirty data written through
> > the file descriptor used for fsync()?
> >
> > -- Jamie
> > --
> >   
> http://www.opengroup.org/onlinepubs/009695399/functions/fsync.html
> 
> Is a pointer to what seems to be the official posix spec for this - it 
> is definitely per file descriptor, not per file system, etc...
> 

Maybe I'm reading Jamie's question wrong, but I think he's saying:

/* open exactly the same file twice */
fd = open("file");
fd2 = open("file");

write(fd, "stuff")
write(fd2, "more stuff")
fsync(fd);

Does the fsync promise "more stuff" will be on disk?  I think the answer
should be yes.

-chris

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Nick Piggin]

On Wed, Oct 29, 2008 at 10:56:36AM -0400, Chris Mason wrote:
> On Wed, 2008-10-29 at 09:32 -0400, Ric Wheeler wrote:
> > Jamie Lokier wrote:
> 
> > >> Is there anything that particularly makes it a file operation
> > >> as opposed to an inode operation?
> > >>     
> > >
> > > In principle, is fsync() required to flush all dirty data written
> > > through any file descriptor ever, or just dirty data written through
> > > the file descriptor used for fsync()?
> > >
> > > -- Jamie
> > > --
> > >   
> > http://www.opengroup.org/onlinepubs/009695399/functions/fsync.html
> > 
> > Is a pointer to what seems to be the official posix spec for this - it 
> > is definitely per file descriptor, not per file system, etc...
> > 
> 
> Maybe I'm reading Jamie's question wrong, but I think he's saying:
> 
> /* open exactly the same file twice */
> fd = open("file");
> fd2 = open("file");
> 
> write(fd, "stuff")
> write(fd2, "more stuff")
> fsync(fd);
> 
> Does the fsync promise "more stuff" will be on disk?  I think the answer
> should be yes.

I think so. And this is in the context of making ->fsync an inode
operation and avoid the NFS NULL-file problem... I don't think there
is any fd specific metadata that fsync has to deal with? Any other
reasons it has to be a file operation?

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[jim owens]

Nick Piggin wrote:
> On Wed, Oct 29, 2008 at 10:56:36AM -0400, Chris Mason wrote:
>> On Wed, 2008-10-29 at 09:32 -0400, Ric Wheeler wrote:
>>> Jamie Lokier wrote:
>>>>> Is there anything that particularly makes it a file operation
>>>>> as opposed to an inode operation?
>>>>>     
>>>> In principle, is fsync() required to flush all dirty data written
>>>> through any file descriptor ever, or just dirty data written through
>>>> the file descriptor used for fsync()?
>>>>
>>>> -- Jamie
>>>> --
>>>>   
>>> http://www.opengroup.org/onlinepubs/009695399/functions/fsync.html
>>>
>>> Is a pointer to what seems to be the official posix spec for this - it 
>>> is definitely per file descriptor, not per file system, etc...
>>>
>> Maybe I'm reading Jamie's question wrong, but I think he's saying:
>>
>> /* open exactly the same file twice */
>> fd = open("file");
>> fd2 = open("file");
>>
>> write(fd, "stuff")
>> write(fd2, "more stuff")
>> fsync(fd);
>>
>> Does the fsync promise "more stuff" will be on disk?  I think the answer
>> should be yes.
> 
> I think so. And this is in the context of making ->fsync an inode
> operation and avoid the NFS NULL-file problem... I don't think there
> is any fd specific metadata that fsync has to deal with? Any other
> reasons it has to be a file operation?

NO, or at least *not the posix definition*.  It is normal
in unix-like operating systems to always flush everything
dirty on the inode no matter what stream it arrived on.

Flushing everything is permitted but not the requirement so
applications must not expect this is *promised* or they
will not be portable.  It is only guaranteed that "stuff"
in this example will be on disk.

AFAIK the fsync semantic comes from the days of dinosaurs,
mainframes, and minicomputers... when a lot of operating
systems had user-space libraries that buffered the I/O.
On fsync(fd), the "fd2" data would still be in user-space.

jim

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Jim Rees]

jim owens wrote:

  AFAIK the fsync semantic comes from the days of dinosaurs,
  mainframes, and minicomputers... when a lot of operating
  systems had user-space libraries that buffered the I/O.
  On fsync(fd), the "fd2" data would still be in user-space.

User space buffering happens in stdio, which is above the system call
level.  It's been that way since fsync() was first introduced, and is still
that way today.

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 12:22:35PM +0000, Jamie Lokier wrote:
> Nick Piggin wrote:
> > On Wed, Oct 29, 2008 at 05:44:17AM -0400, Christoph Hellwig wrote:
> > > On Wed, Oct 29, 2008 at 10:21:43AM +0100, Nick Piggin wrote:
> > > > Please do.
> > > 
> > > Well, there's one stumling block I haven't made progress on yet:
> > > 
> > > I've changed the prototype of ->fsync to lose the dentry as we should
> > > always have a valid file struct.  Except that nfsd doesn't on
> > > directories.  So I either need to fake up a file there, or bail out
> > > and add a ->dir_sync export operation that needs just a dentry.
> > 
> > OK. I don't know much about hthat code, but I would think nfsd
> > should look as close to the syscall layer as possible. I guess
> > there must be something prohibitive (some protocol semantics?).
> > 
> > Is there anything that particularly makes it a file operation
> > as opposed to an inode operation?
> 
> In principle, is fsync() required to flush all dirty data written
> through any file descriptor ever, or just dirty data written through
> the file descriptor used for fsync()?

fsync() is required to flush the data that is dirty at the time of the
call, as well as any associated metadata needed to reference that data. It
doesn't matter who wrote the data in the first place....

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

Re: [patch 0/9] writeback data integrity and other fixes (take 3)

[Dave Chinner]

On Wed, Oct 29, 2008 at 09:27:46AM +1100, Dave Chinner wrote:
> On Tue, Oct 28, 2008 at 04:39:53PM +0100, Nick Piggin wrote:
> > On Wed, Oct 29, 2008 at 01:47:15AM +1100, npiggin@suse.de wrote:
> > I think I also saw a slab bug when running dbench with fault injection on.
> > Running latest Linus kernel.
.....
> > xfs_force_shutdown(ram0,0x2) called from line 1056 of file /home/npiggin/usr/src
> > /linux-2.6/fs/xfs/xfs_log.c.  Return address = 0x000000006011370d
> > Filesystem "ram0": Log I/O Error Detected.  Shutting down filesystem: ram0
> > Please umount the filesystem, and rectify the problem(s)
> > xfs_force_shutdown(ram0,0x2) called from line 818 of file /home/npiggin/usr/src/
> > linux-2.6/fs/xfs/xfs_log.c.  Return address = 0x0000000060114e7d
> > slab error in verify_redzone_free(): cache `xfs_log_ticket': double free detecte
> > d
....
> Now that is interesting.
> 
> We've got a rolling transaction in progress, and the commit of the
> first part of the transaction has got the I/O error.  That frees the
> transaction structure used during that commit, as well as the
> ticket.
> 
> However, before we committed the initial transaction, we duplicated
> the transaction structure to allow the transaction to continue to
> track all the dirty objects in the first commit. That included
> duplicating the pointer to the ticket.
> 
> Then the EIO is returned to mkdir code with the duplicated
> transaction, which is then cancelled, and that frees the transaction
> and the ticket it holds. However, we'd already freed the ticket.
> 
> Ok, we're only seeing this problem now because I recently modified
> the ticket allocation to use a slab instead of a roll-your-own free
> list structure that wouldn't have been poisoned. Nice to know that
> this change did more than just remove code. ;)
> 
> This might take a little while to fix - a lot of code needs
> auditing - but thanks for reporting the problem.

The patch below should fix this problem. It's about 10% of the way
through XFSQA, which means there's nothing obviously bad about it,
but it will need many more eyes on it before we decide if this is
the best way to fix the problem....

Cheers,

Dave.
-- 
Dave Chinner
david@fromorbit.com

XFS: Fix double free of log tickets

When an I/O error occurs during an intermediate commit on a rolling
transaction, xfs_trans_commit() will free the transaction structure
and the related ticket. However, the duplicate transaction that
gets used as the transaction continues still contains a pointer
to the ticket. Hence when the duplicate transaction is cancelled
and freed, we free the ticket a second time.

Add reference counting to the ticket so that we hold an extra
reference to the ticket over the transaction commit. We drop the
extra reference once we have checked that the transaction commit
did not return an error, thus avoiding a double free on commit
error.

Credit to Nick Piggin for tripping over the problem.

Signed-off-by: Dave Chinner <david@fromorbit.com>
---
 fs/xfs/xfs_bmap.c     |   10 ++++++++--
 fs/xfs/xfs_inode.c    |   10 ++++++++--
 fs/xfs/xfs_log.c      |   39 +++++++++++++++++++++++++--------------
 fs/xfs/xfs_log.h      |    4 ++++
 fs/xfs/xfs_log_priv.h |    1 +
 fs/xfs/xfs_trans.c    |    9 ++++++++-
 fs/xfs/xfs_utils.c    |    6 ++++++
 fs/xfs/xfs_vnodeops.c |    6 ++++++
 8 files changed, 66 insertions(+), 19 deletions(-)

diff --git a/fs/xfs/xfs_bmap.c b/fs/xfs/xfs_bmap.c
index db28905..c391221 100644
--- a/fs/xfs/xfs_bmap.c
+++ b/fs/xfs/xfs_bmap.c
@@ -4292,9 +4292,15 @@ xfs_bmap_finish(
 	 * We have a new transaction, so we should return committed=1,
 	 * even though we're returning an error.
 	 */
-	if (error) {
+	if (error)
 		return error;
-	}
+
+	/*
+	 * transaction commit worked ok so we can drop the extra ticket
+	 * reference that we gained in xfs_trans_dup()
+	 */
+	xfs_log_ticket_put(ntp->t_ticket);
+
 	if ((error = xfs_trans_reserve(ntp, 0, logres, 0, XFS_TRANS_PERM_LOG_RES,
 			logcount)))
 		return error;
diff --git a/fs/xfs/xfs_inode.c b/fs/xfs/xfs_inode.c
index cd52282..b977100 100644
--- a/fs/xfs/xfs_inode.c
+++ b/fs/xfs/xfs_inode.c
@@ -1782,8 +1782,14 @@ xfs_itruncate_finish(
 		xfs_trans_ijoin(ntp, ip, XFS_ILOCK_EXCL | XFS_IOLOCK_EXCL);
 		xfs_trans_ihold(ntp, ip);
 
-		if (!error)
-			error = xfs_trans_reserve(ntp, 0,
+		if (error)
+			return error;
+		/*
+		 * transaction commit worked ok so we can drop the extra ticket
+		 * reference that we gained in xfs_trans_dup()
+		 */
+		xfs_log_ticket_put(ntp->t_ticket);
+		error = xfs_trans_reserve(ntp, 0,
 					XFS_ITRUNCATE_LOG_RES(mp), 0,
 					XFS_TRANS_PERM_LOG_RES,
 					XFS_ITRUNCATE_LOG_COUNT);
diff --git a/fs/xfs/xfs_log.c b/fs/xfs/xfs_log.c
index cc1e789..9aecefd 100644
--- a/fs/xfs/xfs_log.c
+++ b/fs/xfs/xfs_log.c
@@ -100,12 +100,11 @@ STATIC void xlog_ungrant_log_space(xlog_t	 *log,
 
 
 /* local ticket functions */
-STATIC xlog_ticket_t	*xlog_ticket_get(xlog_t *log,
+STATIC xlog_ticket_t	*xlog_ticket_alloc(xlog_t *log,
 					 int	unit_bytes,
 					 int	count,
 					 char	clientid,
 					 uint	flags);
-STATIC void		xlog_ticket_put(xlog_t *log, xlog_ticket_t *ticket);
 
 #if defined(DEBUG)
 STATIC void	xlog_verify_dest_ptr(xlog_t *log, __psint_t ptr);
@@ -360,7 +359,7 @@ xfs_log_done(xfs_mount_t	*mp,
 		 */
 		xlog_trace_loggrant(log, ticket, "xfs_log_done: (non-permanent)");
 		xlog_ungrant_log_space(log, ticket);
-		xlog_ticket_put(log, ticket);
+		xfs_log_ticket_put(ticket);
 	} else {
 		xlog_trace_loggrant(log, ticket, "xfs_log_done: (permanent)");
 		xlog_regrant_reserve_log_space(log, ticket);
@@ -514,7 +513,7 @@ xfs_log_reserve(xfs_mount_t	 *mp,
 		retval = xlog_regrant_write_log_space(log, internal_ticket);
 	} else {
 		/* may sleep if need to allocate more tickets */
-		internal_ticket = xlog_ticket_get(log, unit_bytes, cnt,
+		internal_ticket = xlog_ticket_alloc(log, unit_bytes, cnt,
 						  client, flags);
 		if (!internal_ticket)
 			return XFS_ERROR(ENOMEM);
@@ -749,7 +748,7 @@ xfs_log_unmount_write(xfs_mount_t *mp)
 		if (tic) {
 			xlog_trace_loggrant(log, tic, "unmount rec");
 			xlog_ungrant_log_space(log, tic);
-			xlog_ticket_put(log, tic);
+			xfs_log_ticket_put(tic);
 		}
 	} else {
 		/*
@@ -3223,22 +3222,33 @@ xlog_state_want_sync(xlog_t *log, xlog_in_core_t *iclog)
  */
 
 /*
- * Free a used ticket.
+ * Free a used ticket when it's refcount falls to zero.
  */
-STATIC void
-xlog_ticket_put(xlog_t		*log,
-		xlog_ticket_t	*ticket)
+void
+xfs_log_ticket_put(
+	xlog_ticket_t	*ticket)
 {
-	sv_destroy(&ticket->t_wait);
-	kmem_zone_free(xfs_log_ticket_zone, ticket);
-}	/* xlog_ticket_put */
+	ASSERT(atomic_read(&ticket->t_ref) > 0);
+	if (atomic_dec_and_test(&ticket->t_ref)) {
+		sv_destroy(&ticket->t_wait);
+		kmem_zone_free(xfs_log_ticket_zone, ticket);
+	}
+}
 
+xlog_ticket_t *
+xfs_log_ticket_get(
+	xlog_ticket_t	*ticket)
+{
+	ASSERT(atomic_read(&ticket->t_ref) > 0);
+	atomic_inc(&ticket->t_ref);
+	return ticket;
+}
 
 /*
  * Allocate and initialise a new log ticket.
  */
 STATIC xlog_ticket_t *
-xlog_ticket_get(xlog_t		*log,
+xlog_ticket_alloc(xlog_t		*log,
 		int		unit_bytes,
 		int		cnt,
 		char		client,
@@ -3309,6 +3319,7 @@ xlog_ticket_get(xlog_t		*log,
 		unit_bytes += 2*BBSIZE;
         }
 
+	atomic_set(&tic->t_ref, 1);
 	tic->t_unit_res		= unit_bytes;
 	tic->t_curr_res		= unit_bytes;
 	tic->t_cnt		= cnt;
@@ -3324,7 +3335,7 @@ xlog_ticket_get(xlog_t		*log,
 	xlog_tic_reset_res(tic);
 
 	return tic;
-}	/* xlog_ticket_get */
+}
 
 
 /******************************************************************************
diff --git a/fs/xfs/xfs_log.h b/fs/xfs/xfs_log.h
index d47b91f..8a3e84e 100644
--- a/fs/xfs/xfs_log.h
+++ b/fs/xfs/xfs_log.h
@@ -134,6 +134,7 @@ typedef struct xfs_log_callback {
 #ifdef __KERNEL__
 /* Log manager interfaces */
 struct xfs_mount;
+struct xlog_ticket;
 xfs_lsn_t xfs_log_done(struct xfs_mount *mp,
 		       xfs_log_ticket_t ticket,
 		       void		**iclog,
@@ -177,6 +178,9 @@ int	  xfs_log_need_covered(struct xfs_mount *mp);
 
 void	  xlog_iodone(struct xfs_buf *);
 
+struct xlog_ticket * xfs_log_ticket_get(struct xlog_ticket *ticket);
+void	  xfs_log_ticket_put(struct xlog_ticket *ticket);
+
 #endif
 
 
diff --git a/fs/xfs/xfs_log_priv.h b/fs/xfs/xfs_log_priv.h
index de7ef6c..b39a198 100644
--- a/fs/xfs/xfs_log_priv.h
+++ b/fs/xfs/xfs_log_priv.h
@@ -245,6 +245,7 @@ typedef struct xlog_ticket {
 	struct xlog_ticket *t_next;	 /*			         :4|8 */
 	struct xlog_ticket *t_prev;	 /*				 :4|8 */
 	xlog_tid_t	   t_tid;	 /* transaction identifier	 : 4  */
+	atomic_t	   t_ref;	 /* ticket reference count       : 4  */
 	int		   t_curr_res;	 /* current reservation in bytes : 4  */
 	int		   t_unit_res;	 /* unit reservation in bytes    : 4  */
 	char		   t_ocnt;	 /* original count		 : 1  */
diff --git a/fs/xfs/xfs_trans.c b/fs/xfs/xfs_trans.c
index ad137ef..8570b82 100644
--- a/fs/xfs/xfs_trans.c
+++ b/fs/xfs/xfs_trans.c
@@ -290,7 +290,7 @@ xfs_trans_dup(
 	ASSERT(tp->t_ticket != NULL);
 
 	ntp->t_flags = XFS_TRANS_PERM_LOG_RES | (tp->t_flags & XFS_TRANS_RESERVE);
-	ntp->t_ticket = tp->t_ticket;
+	ntp->t_ticket = xfs_log_ticket_get(tp->t_ticket);
 	ntp->t_blk_res = tp->t_blk_res - tp->t_blk_res_used;
 	tp->t_blk_res = tp->t_blk_res_used;
 	ntp->t_rtx_res = tp->t_rtx_res - tp->t_rtx_res_used;
@@ -1260,6 +1260,13 @@ xfs_trans_roll(
 	trans = *tpp;
 
 	/*
+	 * transaction commit worked ok so we can drop the extra ticket
+	 * reference that we gained in xfs_trans_dup()
+	 */
+	xfs_log_ticket_put(trans->t_ticket);
+
+
+	/*
 	 * Reserve space in the log for th next transaction.
 	 * This also pushes items in the "AIL", the list of logged items,
 	 * out to disk if they are taking up space at the tail of the log
diff --git a/fs/xfs/xfs_utils.c b/fs/xfs/xfs_utils.c
index 35d4d41..7711449 100644
--- a/fs/xfs/xfs_utils.c
+++ b/fs/xfs/xfs_utils.c
@@ -172,6 +172,12 @@ xfs_dir_ialloc(
 			*ipp = NULL;
 			return code;
 		}
+
+		/*
+		 * transaction commit worked ok so we can drop the extra ticket
+		 * reference that we gained in xfs_trans_dup()
+		 */
+		xfs_log_ticket_put(tp->t_ticket);
 		code = xfs_trans_reserve(tp, 0, log_res, 0,
 					 XFS_TRANS_PERM_LOG_RES, log_count);
 		/*
diff --git a/fs/xfs/xfs_vnodeops.c b/fs/xfs/xfs_vnodeops.c
index 5809c42..f7eea70 100644
--- a/fs/xfs/xfs_vnodeops.c
+++ b/fs/xfs/xfs_vnodeops.c
@@ -1029,6 +1029,12 @@ xfs_inactive_symlink_rmt(
 		goto error0;
 	}
 	/*
+	 * transaction commit worked ok so we can drop the extra ticket
+	 * reference that we gained in xfs_trans_dup()
+	 */
+	xfs_log_ticket_put(tp->t_ticket);
+
+	/*
 	 * Remove the memory for extent descriptions (just bookkeeping).
 	 */
 	if (ip->i_df.if_bytes)