[Linux-cachefs] Issues

Edward "Koko" Konetzko konetzed at quixoticagony.com
Fri May 22 18:03:56 UTC 2009


David Howells wrote:
>
>
> Can you add the attached patch to get some more debugging info?
>
> David
> ---
> diff --git a/fs/cachefiles/interface.c b/fs/cachefiles/interface.c
> index 1e96234..0a195e3 100644
> --- a/fs/cachefiles/interface.c
> +++ b/fs/cachefiles/interface.c
> @@ -401,6 +401,8 @@ static int cachefiles_attr_changed(struct fscache_object *_object)
>  	if (oi_size == ni_size)
>  		return 0;
>  
> +	kdebug("- change i_size %llx -> %llx", oi_size, ni_size);
> +
>  	newattrs.ia_size = ni_size;
>  	newattrs.ia_valid = ATTR_SIZE;
>  
>   
Patch applied here is the output from everything dmesg from start of 
copy till the error showed up.

[cp    ] ==> cachefiles_alloc_object({dm-0},ffff88003580c618,)
[cp    ] ==> cachefiles_cook_key(,22)
[cp    ] max: 45
[cp    ] acc: 010014
[cp    ] acc: 010000
[cp    ] acc: 00fd00
[cp    ] acc: e5c100
[cp    ] acc: 730068
[cp    ] acc: 007ee7
[cp    ] acc: 2f0317
[cp    ] acc: 00001a
[cp    ] <== cachefiles_cook_key() = ffff88003edc6c00 38
[cp    ] <== cachefiles_alloc_object() = ffff8800358eb080 [ffff880031c0abe0]
[cp    ] ==> cachefiles_alloc_object({dm-0},ffff88003580c4b0,)
[cp    ] ==> cachefiles_cook_key(,66)
[cp    ] max: 101
[cp    ] acc: 000040
[cp    ] acc: 000000
[cp    ] acc: 000000
[cp    ] acc: fd0000
[cp    ] acc: 000000
[cp    ] acc: 000000
[cp    ] acc: 000000
[cp    ] acc: 000000
[cp    ] acc: c00000
[cp    ] acc: 000000
[cp    ] acc: 008000
[cp    ] acc: 800000
[cp    ] acc: b80000
[cp    ] acc: 00000b
[cp    ] acc: 00ea60
[cp    ] acc: 753000
[cp    ] acc: 600000
[cp    ] acc: 0000ea
[cp    ] acc: 000000
[cp    ] acc: 000100
[cp    ] acc: 000000
[cp    ] acc: 000000
[cp    ] <== cachefiles_cook_key() = ffff88003c039940 94
[cp    ] <== cachefiles_alloc_object() = ffff8800358eb1c0 [ffff880031c0abc0]
[cp    ] ==> cachefiles_alloc_object({dm-0},ffff88003580c4f8,)
[cp    ] ==> cachefiles_cook_key(,14)
[cp    ] max: 33
[cp    ] acc: 00000c
[cp    ] acc: 000000
[cp    ] acc: 000000
[cp    ] acc: 010a00
[cp    ] acc: 004786
[cp    ] <== cachefiles_cook_key() = ffff8800358ef580 26
[cp    ] <== cachefiles_alloc_object() = ffff8800358eb300 [ffff880031c0ae60]
[cp    ] ==> cachefiles_alloc_object({dm-0},ffff88003580c540,)
[cp    ] ==> cachefiles_cook_key(,5)
[cp    ] max: 18
[cp    ] <== cachefiles_cook_key() = ffff880031c0ae40 13
[cp    ] <== cachefiles_alloc_object() = ffff8800358eb440 [ffff880031c0aea0]
[cp    ] ==> cachefiles_grab_object({OBJ1,1})
[kslowd] ==> cachefiles_grab_object({OBJ1,2})
[kslowd] ==> cachefiles_grab_object({OBJ2,1})
[kslowd] ==> cachefiles_put_object({OBJ1,3})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_grab_object({OBJ2,2})
[kslowd] ==> cachefiles_grab_object({OBJ3,1})
[kslowd] ==> cachefiles_put_object({OBJ2,3})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_grab_object({OBJ3,2})
[kslowd] ==> cachefiles_grab_object({OBJ4,1})
[kslowd] ==> cachefiles_put_object({OBJ3,3})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_lookup_object({OBJ4})
[kslowd] ==> cachefiles_walk_to_object({ffff88003cd4db40},, at 4a,)
[kslowd] lookup '@4a'
[kslowd] next -> ffff88003cd43b00 positive
[kslowd] advance
[kslowd] lookup 'I03nfs'
[kslowd] next -> ffff88003cca9240 positive
[kslowd] validate 'I03nfs'
[kslowd] ==> cachefiles_check_object_xattr(ffff8800358eb440,#5)
[kslowd] checkaux FSDEF.netfs #4
[kslowd] <== cachefiles_check_object_xattr() = 0
[kslowd] ==> cachefiles_mark_object_active(,ffff8800358eb440)
[kslowd] <== cachefiles_mark_object_active()
[kslowd] === OBTAINED_OBJECT ===
[kslowd] <== cachefiles_walk_to_object() = 0 [5990955]
[kslowd] <== cachefiles_lookup_object() [0]
[kslowd] ==> cachefiles_lookup_complete({OBJ4,ffff880031c0aea0})
[kslowd] ==> cachefiles_grab_object({OBJ3,2})
[kslowd] ==> cachefiles_put_object({OBJ3,3})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_put_object({OBJ4,2})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_lookup_object({OBJ3})
[kslowd] ==> cachefiles_walk_to_object({ffff88003cca9240},, at e4,)
[kslowd] lookup '@e4'
[kslowd] next -> ffff88003cca9840 positive
[kslowd] advance
[kslowd] lookup 'Jc000000000000Eg06u40'
[kslowd] next -> ffff88003cd4c200 positive
[kslowd] validate 'Jc000000000000Eg06u40'
[kslowd] ==> cachefiles_check_object_xattr(ffff8800358eb300,#1)
[kslowd] <== cachefiles_check_object_xattr() = 0
[kslowd] ==> cachefiles_mark_object_active(,ffff8800358eb300)
[kslowd] <== cachefiles_mark_object_active()
[kslowd] === OBTAINED_OBJECT ===
[kslowd] <== cachefiles_walk_to_object() = 0 [5990957]
[kslowd] <== cachefiles_lookup_object() [0]
[kslowd] ==> cachefiles_lookup_complete({OBJ3,ffff880031c0ae60})
[kslowd] ==> cachefiles_grab_object({OBJ2,2})
[kslowd] ==> cachefiles_put_object({OBJ2,3})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_put_object({OBJ3,2})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_lookup_object({OBJ2})
[kslowd] ==> cachefiles_walk_to_object({ffff88003cd4c200},, at fa,)
[kslowd] lookup '@fa'
[kslowd] next -> ffff88003cd4c140 positive
[kslowd] advance
[kslowd] lookup 
'J01000000000000g-0000000000000000000M00000080000w000Kb000wFe000jt000oG3000000040000000000'
[kslowd] next -> ffff88003cd4c080 positive
[kslowd] validate 
'J01000000000000g-0000000000000000000M00000080000w000Kb000wFe000jt000oG3000000040000000000'
[kslowd] ==> cachefiles_check_object_xattr(ffff8800358eb1c0,#1)
[kslowd] <== cachefiles_check_object_xattr() = 0
[kslowd] ==> cachefiles_mark_object_active(,ffff8800358eb1c0)
[kslowd] <== cachefiles_mark_object_active()
[kslowd] === OBTAINED_OBJECT ===
[kslowd] <== cachefiles_walk_to_object() = 0 [5990981]
[kslowd] <== cachefiles_lookup_object() [0]
[kslowd] ==> cachefiles_lookup_complete({OBJ2,ffff880031c0abc0})
[kslowd] ==> cachefiles_grab_object({OBJ1,2})
[kslowd] ==> cachefiles_put_object({OBJ1,3})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_put_object({OBJ2,2})
[kslowd] <== cachefiles_put_object()
[kslowd] ==> cachefiles_lookup_object({OBJ1})
[kslowd] ==> cachefiles_walk_to_object({ffff88003cd4c080},, at 5c,)
[kslowd] lookup '@5c'
[kslowd] next -> ffff88002ae15680 positive
[kslowd] advance
[kslowd] lookup 'Ek0g000g00Qf004sVE1MsDX70ncMbq000'
[kslowd] next -> ffff88002ae51440 positive
[kslowd] validate 'Ek0g000g00Qf004sVE1MsDX70ncMbq000'
[kslowd] ==> cachefiles_check_object_xattr(ffff8800358eb080,#49)
[kslowd] checkaux NFS.fh #48
[kslowd] <== cachefiles_check_object_xattr() = 0
[kslowd] ==> cachefiles_mark_object_active(,ffff8800358eb080)
[kslowd] <== cachefiles_mark_object_active()
[kslowd] === OBTAINED_OBJECT ===
[kslowd] <== cachefiles_walk_to_object() = 0 [6088901]
[kslowd] ==> cachefiles_attr_changed({OBJ1},[1024])
[kslowd] <== cachefiles_lookup_object() [0]
[kslowd] ==> cachefiles_lookup_complete({OBJ1,ffff880031c0abe0})
[kslowd] ==> cachefiles_put_object({OBJ1,2})
[kslowd] <== cachefiles_put_object()
[cp    ] ==> cachefiles_read_or_alloc_pages({OBJ1,1},,1,,)
[cp    ] 0 -> 5d6800
[cp    ] ==> cachefiles_read_backing_file()
[cp    ] read back ffffe2000085bf68{0,1}
[cp    ] - new ffffe2000085bf30
[cp    ] - monitor add
[cp    ] out
[cp    ] <== cachefiles_read_backing_file() = 0
[cp    ] <== cachefiles_read_or_alloc_pages() = 0 [nr=0 empty]
[syslog] ==> cachefiles_read_waiter({0},3,0,{ffffe2000085bf30,0})
[syslog] --- monitor ffffe2000085bf30 100000000020028 ---
[events] ==> cachefiles_read_copier({ino=6088901})
[events] - copy {0}
[events] <== cachefiles_read_copier()
[cp    ] ==> cachefiles_alloc_object({dm-0},ffff88003580c5d0,)
[cp    ] ==> cachefiles_cook_key(,22)
[cp    ] max: 45
[cp    ] acc: 010014
[cp    ] acc: 010000
[cp    ] acc: 00fd00
[cp    ] acc: e5c100
[cp    ] acc: 700068
[cp    ] acc: 007ee7
[cp    ] acc: 2f0314
[cp    ] acc: 00001a
[cp    ] <== cachefiles_cook_key() = ffff880026cb5b40 38
[cp    ] <== cachefiles_alloc_object() = ffff8800358eb580 [ffff880031c0abe0]
[cp    ] ==> cachefiles_grab_object({OBJ5,1})
[kslowd] ==> cachefiles_lookup_object({OBJ5})
[kslowd] ==> cachefiles_walk_to_object({ffff88003cd4c080},, at 56,)
[kslowd] lookup '@56'
[kslowd] next -> ffff880024160cc0 positive
[kslowd] advance
[kslowd] lookup 'Ek0g000g00Qf004sVE10sDX70kcMbq000'
[kslowd] next -> ffff88002417c5c0 positive
[kslowd] validate 'Ek0g000g00Qf004sVE10sDX70kcMbq000'
[kslowd] ==> cachefiles_check_object_xattr(ffff8800358eb580,#49)
[kslowd] checkaux NFS.fh #48
[kslowd] <== cachefiles_check_object_xattr() = 0
[kslowd] ==> cachefiles_mark_object_active(,ffff8800358eb580)
[kslowd] <== cachefiles_mark_object_active()
[kslowd] === OBTAINED_OBJECT ===
[kslowd] <== cachefiles_walk_to_object() = 0 [6088903]
[kslowd] ==> cachefiles_attr_changed({OBJ5},[1620])
[kslowd] - change i_size 1000 -> 654
[cp    ] ==> cachefiles_read_or_alloc_pages({OBJ5,1},,1,,)
[cp    ] 0 -> 5d5808
[cp    ] ==> cachefiles_read_backing_file()
[cp    ] read back ffffe2000085bef8{0,1}
[cp    ] - present ffffe200007d9930
[cp    ] - not ready ffffe200007d9930{100000000000821}
[cp    ] - monitor add
[cp    ] out
[cp    ] <== cachefiles_read_backing_file() = 0
[cp    ] <== cachefiles_read_or_alloc_pages() = 0 [nr=0 empty]
[kslowd] ==> cachefiles_read_waiter({0},3,0,{ffffe200007d9930,0})
[kslowd] --- monitor ffffe200007d9930 100000000000830 ---
Pid: 2060, comm: kslowd Not tainted 2.6.30-rc6-dh #3
Call Trace:
 [<ffffffffa027cc96>] ? cachefiles_read_waiter+0xd9/0x147 [cachefiles]
 [<ffffffff8022bb3b>] ? __wake_up_common+0x3f/0x71
 [<ffffffff8022cbb2>] ? __wake_up+0x30/0x44
 [<ffffffff8024a3fb>] ? __wake_up_bit+0x28/0x2d
 [<ffffffffa003a793>] ? ext3_truncate+0x4d7/0x8ed [ext3]
 [<ffffffff802c827a>] ? __getblk+0x25/0x209
 [<ffffffff802c827a>] ? __getblk+0x25/0x209
 [<ffffffff802915c9>] ? unmap_mapping_range+0x59/0x1ff
 [<ffffffff8022cbb2>] ? __wake_up+0x30/0x44
 [<ffffffff80293550>] ? vmtruncate+0xc2/0xe2
 [<ffffffff802bd67b>] ? inode_setattr+0x22/0x10a
 [<ffffffffa003baa5>] ? ext3_setattr+0x17b/0x1e6 [ext3]
 [<ffffffff802bd8e9>] ? notify_change+0x186/0x2c9
 [<ffffffffa0278a04>] ? cachefiles_attr_changed+0x159/0x1f3 [cachefiles]
 [<ffffffff8024a411>] ? wake_up_bit+0x11/0x22
 [<ffffffffa0278fa5>] ? cachefiles_lookup_object+0xcf/0x12a [cachefiles]
 [<ffffffffa0269165>] ? fscache_lookup_object+0x110/0x122 [fscache]
 [<ffffffffa026989a>] ? fscache_object_slow_work_execute+0x567/0x65f 
[fscache]
 [<ffffffff8027e102>] ? slow_work_thread+0x285/0x43a
 [<ffffffff8024a422>] ? autoremove_wake_function+0x0/0x2e
 [<ffffffff8027de7d>] ? slow_work_thread+0x0/0x43a
 [<ffffffff8024a2f3>] ? kthread+0x54/0x81
 [<ffffffff8020c93a>] ? child_rip+0xa/0x20
 [<ffffffff8024a29f>] ? kthread+0x0/0x81
 [<ffffffff8020c930>] ? child_rip+0x0/0x20
[events] ==> cachefiles_read_copier({ino=6088903})
[events] - copy {0}
CacheFiles: I/O Error: Readpage failed on backing file 100000000000830
FS-Cache: Cache cachefiles stopped due to I/O error
[events] <== cachefiles_read_copier()
[kslowd] <== cachefiles_attr_changed() = 0
[kslowd] <== cachefiles_lookup_object() [0]
[kslowd] ==> cachefiles_lookup_complete({OBJ5,ffff880031c0abe0})
[kslowd] ==> cachefiles_put_object({OBJ5,2})
[kslowd] <== cachefiles_put_object()




More information about the Linux-cachefs mailing list