[pnfs] Kernel crash on access dCache NFS
Tigran Mkrtchyan
tigran.mkrtchyan at desy.de
Mon Jun 4 11:39:11 EDT 2007
William A. (Andy) Adamson wrote:
> Hi Tigran
>
> dying in encode_putfh is weird.
>
there is some inconsistency:
tshark shows following on GETDEVICELIST:
Opcode: GETDEVLIST (48)
Status: NFS4_OK (0)
cookie: 1
cookieverf: 0
num devices: 5
device ID: 0
device type: Unknown (36)
device ID: 1
device type: Unknown (1952673792)
device ID: 825700910
device type: Unknown (926166577)
device type: Unknown (158)
device type: Unknown (36)
device type: FILE_SIMPLE (1)
r_netid: <DATA><TRUNCATED>
length: 1952673792
contents: <DATA><TRUNCATED>
nevertheless linux understands it:
decode_getdevicelist: num_dev 5 i 0 cnt 0 id 0 len 36
decode_getdevicelist: num_dev 5 i 1 cnt 1 id 158 len 36
decode_getdevicelist: num_dev 5 i 2 cnt 2 id 78 len 36
decode_getdevicelist: num_dev 5 i 3 cnt 3 id 174 len 36
decode_getdevicelist: num_dev 5 i 4 cnt 4 id 118 len 36
looks like order problem.
Regards,
Tigran
> A couple of questions.
> Have you implemented sessions? (I think you must have, but just to be
> sure...)
> When did you last update the pnfs git tree?
>
> -->Andy
>
> On 6/4/07, *Tigran Mkrtchyan* <tigran.mkrtchyan at desy.de
> <mailto:tigran.mkrtchyan at desy.de>> wrote:
>
>
>
> Hi *,
>
> Last weeks I try to get may code synchronized with draft 10 ( as all of
> us ) and have a trouble which can't solve for now. Linux client crushes.
> 100% reproducible. The symptoms:
>
>
> after mount, client happy and recognize server as pNFS server,
> but any read/write operation ends up with kernel panic. Last operation
> seen by server - LAYOUTGET. I expect GETDEVICEINFO next one ( while I
> return new device id every time ), but client dies.
>
>
> kernel log attached.
>
> kernel used: git-clone git://linux-nfs.org/linux-pnfs.git
> <http://nfs.org/linux-pnfs.git> linux-git
>
>
> tigran at nairi:~/work/linux-git> git pull
> Already up-to-date.
> tigran at nairi:~/work/linux-git> date
> Mon Jun 4 11:51:22 CEST 2007
>
>
>
> Regards,
> Tigran.
>
>
> ________________________________________________________________________
> Tigran Mkrtchyan DESY, IT,
> tigran.mkrtchyan at desy.de
> <mailto:tigran.mkrtchyan at desy.de> Notkestrasse 85,
> Tel: + 49 40 89983946 Hamburg 22607,
> Fax: + 49 40 89984429 Germany.
>
> nfs4filelayout_init: NFSv4 File Layout Driver Registering...
> started cb service!
> allocated session c4e3c880
> expired session found!
> encode_compound: tag=
> nfs4_proc_exchange_id returns 0
> exchange_id succeeded!
> encode_compound: tag=
> fc init returned 0
> bc init returned 0
> sessionid is: 589505332:589505315:589505315:589505315
> create_session succeeded!
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 1
> max_slots: 16
> encode_compound: tag=
> decode_attr_lease_time: file size=90
> decode_attr_maxfilesize: maxfilesize=0
> decode_attr_maxread: maxread=1024
> decode_attr_maxwrite: maxwrite=1024
> bitmap is 0
> decode_fsinfo: xdr returned 0!
> waking up waiters on slot 0
> nfs4_schedule_state_renewal: requeueing work. Lease period = 60
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 2
> max_slots: 16
> encode_compound: tag=
> decode_attr_type: type=02
> decode_attr_change: change attribute=1180875771974
> decode_attr_size: file size=512
> decode_attr_fsid: fsid=(0x11/0x11)
> decode_attr_fileid: fileid=2097415873
> decode_attr_fs_locations: fs_locations done, error = 0
> decode_attr_mode: file mode=0755
> decode_attr_nlink: nlink=10
> decode_attr_owner: nfs_map_name_to_uid failed!
> decode_attr_owner: uid=-2
> decode_attr_group: nfs_map_group_to_gid failed!
> decode_attr_group: gid=-2
> decode_attr_rdev: rdev=(0x0:0x0)
> decode_attr_space_used: space used=512
> decode_attr_time_access: atime=1179839608
> decode_attr_time_metadata: ctime=1179839608
> decode_attr_time_modify: mtime=1180875771
> decode_attr_mounted_on_fileid: fileid=0
> decode_getfattr: xdr returned 0
> waking up waiters on slot 0
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 3
> max_slots: 16
> encode_compound: tag=
> decode_attr_supported: bitmask=0xfcffbfff40edbe3e
> decode_attr_link_support: link support=true
> decode_attr_symlink_support: symlink support=true
> decode_attr_aclsupport: ACLs supported=3
> decode_server_caps: xdr returned 0!
> waking up waiters on slot 0
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 4
> max_slots: 16
> encode_compound: tag=
> decode_attr_lease_time: file size=90
> decode_attr_maxfilesize: maxfilesize=30064771072
> decode_attr_maxread: maxread=4096
> decode_attr_maxwrite: maxwrite=4096
> bitmap is 40000000
> decode_fsinfo: xdr returned 0!
> waking up waiters on slot 0
> NFS: nfs_fhget(0:e/2097415873 ct=1)
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 5
> max_slots: 16
> encode_compound: tag=
> decode_attr_maxlink: maxlink=255
> decode_attr_maxname: maxname=255
> decode_pathconf: xdr returned 0!
> waking up waiters on slot 0
> PNFS: find_pnfs: Searching for 1
> set_pnfs_layoutdriver: Setting pNFS module
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 6
> max_slots: 16
> encode_compound: tag=
> encoding getdevicelist!
> decode_getdevicelist: num_dev 3 i 0 cnt 0 id 0 len 36
> decode_getdevicelist: num_dev 3 i 1 cnt 1 id 166 len 36
> decode_getdevicelist: num_dev 3 i 2 cnt 2 id 132 len 36
> waking up waiters on slot 0
> nfs4_pnfs_getdevlist: err=0, num_devs=3
> decode_device: addr:port string = 172.16.174.1.8.1
> nfs4_pnfs_device_add
> device_create: dev_id=0, ip=ac10ae01, port=2049, rpcclient c7af4600
> device_create: exit err 0 clp c7af4400
> _device_lookup: dev_id=0
> _device_add: dev_id=0, ip=ac10ae01, port=2049
> decode_device: addr:port string = 172.16.174.1.8.4
> nfs4_pnfs_device_add
> device_create: dev_id=166, ip=ac10ae01, port=2052, rpcclient c7af4600
> device_create: exit err 0 clp c7af4400
> _device_lookup: dev_id=166
> _device_add: dev_id=166, ip=ac10ae01, port=2052
> decode_device: addr:port string = 172.16.174.1.8.4
> nfs4_pnfs_device_add
> device_create: dev_id=132, ip=ac10ae01, port=2052, rpcclient c7af4600
> device_create: exit err 0 clp c7af4400
> _device_lookup: dev_id=132
> _device_add: dev_id=132, ip=ac10ae01, port=2052
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 7
> max_slots: 16
> encode_compound: tag=
> waking up waiters on slot 0
> NFS: permission(0:e/2097415873), mask=0x1, res=0
> NFS: atomic_lookup(0:e/2097415873), passwd
> NFS: lookup(//passwd)
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 8
> max_slots: 16
> NFS call lookup passwd
> encode_compound: tag=
> decode_attr_type: type=01
> decode_attr_change: change attribute=1180949279353
> decode_attr_size: file size=0
> decode_attr_fsid: fsid=(0x11/0x11)
> decode_attr_fileid: fileid=2472544295
> decode_attr_fs_locations: fs_locations done, error = 0
> decode_attr_mode: file mode=0644
> decode_attr_nlink: nlink=1
> decode_attr_owner: nfs_map_name_to_uid failed!
> decode_attr_owner: uid=-2
> decode_attr_group: nfs_map_group_to_gid failed!
> decode_attr_group: gid=-2
> decode_attr_rdev: rdev=(0x0:0x0)
> decode_attr_space_used: space used=0
> decode_attr_time_access: atime=1180875771
> decode_attr_time_metadata: ctime=0
> decode_attr_time_modify: mtime=1180949279
> decode_attr_mounted_on_fileid: fileid=0
> decode_getfattr: xdr returned 0
> NFS reply lookup: 0
> waking up waiters on slot 0
> NFS: nfs_fhget(0:e/2472544295 ct=1)
> NFS: dentry_delete(//passwd, 0)
> NFS: permission(0:e/2097415873), mask=0x1, res=0
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 9
> max_slots: 16
> encode_compound: tag=
> decode_attr_type: type=01
> decode_attr_change: change attribute=1180949279353
> decode_attr_size: file size=0
> decode_attr_fsid: fsid=(0x11/0x11)
> decode_attr_fileid: fileid=2472544295
> decode_attr_fs_locations: fs_locations done, error = 0
> decode_attr_mode: file mode=0644
> decode_attr_nlink: nlink=1
> decode_attr_owner: nfs_map_name_to_uid failed!
> decode_attr_owner: uid=-2
> decode_attr_group: nfs_map_group_to_gid failed!
> decode_attr_group: gid=-2
> decode_attr_rdev: rdev=(0x0:0x0)
> decode_attr_space_used: space used=0
> decode_attr_time_access: atime=1180875771
> decode_attr_time_metadata: ctime=0
> decode_attr_time_modify: mtime=1180949279
> decode_attr_mounted_on_fileid: fileid=0
> decode_getfattr: xdr returned 0
> decode_attr_type: type=02
> decode_attr_change: change attribute=1180875771974
> decode_attr_size: file size=512
> decode_attr_fsid: fsid=(0x11/0x11)
> decode_attr_fileid: fileid=2097415873
> decode_attr_fs_locations: fs_locations done, error = 0
> decode_attr_mode: file mode=0755
> decode_attr_nlink: nlink=10
> decode_attr_owner: nfs_map_name_to_uid failed!
> decode_attr_owner: uid=-2
> decode_attr_group: nfs_map_group_to_gid failed!
> decode_attr_group: gid=-2
> decode_attr_rdev: rdev=(0x0:0x0)
> decode_attr_space_used: space used=512
> decode_attr_time_access: atime=1179839608
> decode_attr_time_metadata: ctime=0
> decode_attr_time_modify: mtime=1180875771
> decode_attr_mounted_on_fileid: fileid=0
> decode_getfattr: xdr returned 0
> waking up waiters on slot 0
> NFS: nfs_update_inode(0:e/2097415873 ct=1 info=0xe)
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 10
> max_slots: 16
> encode_compound: tag=
> waking up waiters on slot 0
> NFS: nfs_fhget(0:e/2472544295 ct=2)
> NFS: permission(0:e/-1822423001), mask=0x2, res=0
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 11
> max_slots: 16
> encode_compound: tag=
> decode_attr_type: type=01
> decode_attr_change: change attribute=1180949668548
> decode_attr_size: file size=0
> decode_attr_fsid: fsid=(0x11/0x11)
> decode_attr_fileid: fileid=2472544295
> decode_attr_fs_locations: fs_locations done, error = 0
> decode_attr_mode: file mode=0644
> decode_attr_nlink: nlink=1
> decode_attr_owner: nfs_map_name_to_uid failed!
> decode_attr_owner: uid=-2
> decode_attr_group: nfs_map_group_to_gid failed!
> decode_attr_group: gid=-2
> decode_attr_rdev: rdev=(0x0:0x0)
> decode_attr_space_used: space used=0
> decode_attr_time_access: atime=1180875771
> decode_attr_time_metadata: ctime=0
> decode_attr_time_modify: mtime=1180949668
> decode_attr_mounted_on_fileid: fileid=0
> decode_getfattr: xdr returned 0
> waking up waiters on slot 0
> NFS: nfs_update_inode(0:e/-1822423001 ct=2 info=0xe)
> NFS: mtime change on server for file 0:e/-1822423001
> NFS: change_attr change on server for file 0:e/-1822423001
> NFS: revalidating (0:e/2472544295)
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 12
> max_slots: 16
> encode_compound: tag=
> decode_attr_type: type=01
> decode_attr_change: change attribute=1180949668548
> decode_attr_size: file size=0
> decode_attr_fsid: fsid=(0x11/0x11)
> decode_attr_fileid: fileid=2472544295
> decode_attr_fs_locations: fs_locations done, error = 0
> decode_attr_mode: file mode=0644
> decode_attr_nlink: nlink=1
> decode_attr_owner: nfs_map_name_to_uid failed!
> decode_attr_owner: uid=-2
> decode_attr_group: nfs_map_group_to_gid failed!
> decode_attr_group: gid=-2
> decode_attr_rdev: rdev=(0x0:0x0)
> decode_attr_space_used: space used=0
> decode_attr_time_access: atime=1180875771
> decode_attr_time_metadata: ctime=0
> decode_attr_time_modify: mtime=1180949668
> decode_attr_mounted_on_fileid: fileid=0
> decode_getfattr: xdr returned 0
> waking up waiters on slot 0
> NFS: nfs_update_inode(0:e/-1822423001 ct=2 info=0xe)
> NFS: (0:e/2472544295) revalidation complete
> pnfs_file_write:(//passwd(-1822423001), 941 at 0)
> nfs: write(//passwd(-1822423001), 941 at 0)
> NFS: nfs_updatepage(//passwd 941 at 0)
> NFS: nfs_updatepage returns 0 (isize 941)
> nfs: flush(0:e/-1822423001)
> get_layout:Begin
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 13
> max_slots: 16
> encode_compound: tag=
> encode_pnfs_layoutget: 1st type:1 iomode:2 off:0 len:4294967295 mc:4096
> decode_pnfs_layoutget roff:0 rlen:0 riomode:2, lo_type:1, lo.len:92
> waking up waiters on slot 0
> pnfs_inject_layout Begin
> pnfs_inject_layout Alloc'ing layout
> NFS_FILELAYOUT: allocating layout
> pnfs_inject_layout Calling set layout
> filelayout_set_layout set_layout_map Begin
> DEBUG: filelayout_set_layout: type 2 stripe_unit 4096 file_size 0
> devs 1
> DEBUG: filelayout_set_layout: dev 0 len 26990
> virtual_update_layout end (err:0) state 0
> below_threshold wthresh: 4294967295
> pnfs_try_to_write_data:Begin
> below_threshold wthresh: 4294967295
> pnfs_try_to_write_data Utilizing pNFS I/O
> pnfs_writepages: Writing ino:2472544295 941 at 0
> virtual_update_layout: Using cached layout for 941 at 0)
> pnfs_writepages: Calling layout driver (how 4) write with 1 pages
> nfs4_pnfs_dserver_get: offset=0, count=941, si=0, dsi=0, num_devs=1,
> stripe_unit=4096
> _device_lookup: dev_id=0
> nfs4_pnfs_dserver_get: dev_id=0, idx=0, offset=0, count=941
> filelayout_write_pagelist set wb_devid 0
> _nfs41_proc_setup_sequence: 589505332:589505315:589505315:589505315
> slot id: 0
> seqid: 14
> max_slots: 16
> encode_compound: tag=
> RESERVE_SPACE(26998) failed in function encode_putfh
> ------------[ cut here ]------------
> kernel BUG at fs/nfs/nfs4xdr.c:1210!
> invalid opcode: 0000 [#1]
> Modules linked in: nfslayoutdriver nfs lockd nfs_acl sunrpc
> af_packet pcspkr pcnet32 mii i2c_piix4 i2c_core ide_cd intel_agp
> agpgart xfs edd ide_generic piix ide_disk ide_core
> CPU: 0
> EIP: 0060:[<c8c6a54c>] Not tainted VLI
> EFLAGS: 00010292 (2.6.18.3-largeio-pnfs-default #5)
> EIP is at encode_putfh+0x34/0x60 [nfs]
> eax: 00000038 ebx: 00000000 ecx: ffffffff edx: 00004ba4
> esi: 0000696e edi: 00006976 ebp: c5294050 esp: c5c25d14
> ds: 007b es: 007b ss: 0068
> Process cp (pid: 2216, ti=c5c24000 task=c5a7aab0 task.ti=c5c24000)
> Stack: c8c7c00c 00006976 c8c7841e c529604c c4de4cf0 c5c25d44
> c5a0d000 c8c6ced6
> 00000000 00000003 00000000 00000000 c529607c c5a0d004
> c52964dc c5a0d004
> 00000000 c4de4b84 c5a0d000 c8c6ce81 c8bd3a51 c8bd3af6
> c8bd0508 00000002
> Call Trace:
> [<c8c6ced6>] nfs41_xdr_enc_pnfs_write+0x55/0x6a [nfs]
> [<c8c6ce81>] nfs41_xdr_enc_pnfs_write+0x0/0x6a [nfs]
> [<c8bd3a51>] rpcauth_wrap_req+0x6c/0x74 [sunrpc]
> [<c8bd3af6>] rpcauth_marshcred+0x4b/0x52 [sunrpc]
> [<c8bd0508>] xprt_prepare_transmit+0x6c/0x75 [sunrpc]
> [<c8c6ce81>] nfs41_xdr_enc_pnfs_write+0x0/0x6a [nfs]
> [<c8bce3a8>] call_transmit+0x187/0x1e4 [sunrpc]
> [<c8c70d75>] nfs4_put_state_owner+0x16/0x78 [nfs]
> [<c8bd32a8>] __rpc_execute+0x73/0x19b [sunrpc]
> [<c0116c9c>] sigprocmask+0x93/0x9a
> [<c8c59db9>] nfs_execute_write+0x1e/0x2d [nfs]
> [<c8c59e33>] nfs_initiate_write+0x6b/0xd4 [nfs]
> [<c8860774>] filelayout_write_pagelist+0x15e/0x16a [nfslayoutdriver]
> [<c8c75b73>] pnfs_writepages+0x178/0x1f1 [nfs]
> [<c8c59f76>] nfs_write_rpcsetup+0xda/0x10c [nfs]
> [<c8c5a03c>] nfs_flush_one_common+0x94/0x9c [nfs]
> [<c8c5b2f5>] pnfs_flush_one+0xc0/0xf0 [nfs]
> [<c8c5995a>] nfs_flush_list+0x8d/0xd5 [nfs]
> [<c8c5b118>] nfs_sync_inode_wait+0x16a/0x241 [nfs]
> [<c8c762cc>] pnfs_file_write+0x21f/0x22b [nfs]
> [<c8c51af4>] nfs_file_flush+0x69/0x9d [nfs]
> [<c0143b9c>] filp_close+0x33/0x59
> [<c01025f9>] sysenter_past_esp+0x56/0x79
> Code: 0f b7 32 8d 7e 08 89 fa e8 20 e4 f6 ff 85 c0 89 c3 75 20 89 7c
> 24 04 c7 44 24 08 1e 84 c7 c8 c7 04 24 0c c0 c7 c8 e8 75 56 4a f7
> <0f> 0b ba 04 a2 bd c7 c8 c7 03 00 00 00 16 89 f0 89 f1 0f c8 8d
> EIP: [<c8c6a54c>] encode_putfh+0x34/0x60 [nfs] SS:ESP 0068:c5c25d14
>
>
> _______________________________________________
> pNFS mailing list
> pNFS at linux-nfs.org <mailto:pNFS at linux-nfs.org>
> http://linux-nfs.org/cgi-bin/mailman/listinfo/pnfs
> <http://linux-nfs.org/cgi-bin/mailman/listinfo/pnfs>
>
>
--
________________________________________________________________________
Tigran Mkrtchyan DESY, IT,
tigran.mkrtchyan at desy.de Notkestrasse 85,
Tel: + 49 40 89983946 Hamburg 22607,
Fax: + 49 40 89984429 Germany.
More information about the pNFS
mailing list