0

I have a FreeNAS (9.10-STABLE-201605240427 ) server, and several CentOS 6.4 boxes. However, the CentOS boxes seem unable to write to a FreeNAS mount any file that's larger 4KB, regardless of whether they're mounted using CIFS or NFS (3 and 4).

For some odd reason, whenever you I try to write a file larger than 4KB (the page size), there appears to be some kind of deadlock.

Here's an excerpt of the NFS debug log from a CentOS machine, when I try to copy /bin/ls into the mount.

Sep  2 22:13:20 RAX-NERVE kernel: NFS: nfs_update_inode(0:17/4 fh_crc=0x2877d5c3 ct=2 info=0x227e7f)
Sep  2 22:13:20 RAX-NERVE kernel: NFS: permission(0:17/4), mask=0x1, res=0
Sep  2 22:13:20 RAX-NERVE kernel: NFS: atomic_lookup(0:17/4), ls
Sep  2 22:13:20 RAX-NERVE kernel: NFS: lookup(/ls)
Sep  2 22:13:20 RAX-NERVE kernel: NFS call  lookup ls
Sep  2 22:13:20 RAX-NERVE kernel: encode_compound: tag=
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_type: type=0100000
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_change: change attribute=8013396
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_size: file size=0
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_fsid: fsid=(0x76431d7a/0x9cf9cdde)
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_fileid: fileid=41
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_fs_locations: fs_locations done, error = 0
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_mode: file mode=0775
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_nlink: nlink=1
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_owner: uid=99
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_group: gid=99
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_rdev: rdev=(0x3:0xc7)
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_space_used: space used=512
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_time_access: atime=502412
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_time_metadata: ctime=1472850295
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_time_modify: mtime=1472850295
Sep  2 22:13:20 RAX-NERVE kernel: decode_attr_mounted_on_fileid: fileid=41
Sep  2 22:13:20 RAX-NERVE kernel: decode_getfattr_attrs: xdr returned -2097152
Sep  2 22:13:20 RAX-NERVE kernel: decode_getfattr_generic: xdr returned 0
Sep  2 22:13:20 RAX-NERVE kernel: NFS reply lookup: 0
Sep  2 22:13:20 RAX-NERVE kernel: NFS: nfs_fhget(0:17/41 fh_crc=0x2947d423 ct=1)
Sep  2 22:13:20 RAX-NERVE kernel: NFS: dentry_delete(/ls, 0)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: permission(0:17/4), mask=0x1, res=0
Sep  2 22:13:21 RAX-NERVE kernel: --> nfs_put_client({2})
Sep  2 22:13:21 RAX-NERVE kernel: encode_compound: tag=
Sep  2 22:13:21 RAX-NERVE kernel: encode_compound: tag=
Sep  2 22:13:21 RAX-NERVE kernel: nfs4_schedule_state_renewal: requeueing work. Lease period = 48
Sep  2 22:13:21 RAX-NERVE kernel: --> nfs_put_client({3})
Sep  2 22:13:21 RAX-NERVE kernel: --> nfs_put_client({2})
Sep  2 22:13:21 RAX-NERVE kernel: <-- nfs4_setup_sequence status=0
Sep  2 22:13:21 RAX-NERVE kernel: encode_compound: tag=
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_type: type=0100000
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_change: change attribute=8013396
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_size: file size=0
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_fsid: fsid=(0x76431d7a/0x9cf9cdde)
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_fileid: fileid=41
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_fs_locations: fs_locations done, error = 0
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_mode: file mode=0775
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_nlink: nlink=1
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_owner: uid=-2
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_group: gid=-2
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_rdev: rdev=(0x3:0xc7)
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_space_used: space used=512
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_time_access: atime=502412
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_time_metadata: ctime=1472850295
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_time_modify: mtime=1472850295
Sep  2 22:13:21 RAX-NERVE kernel: decode_attr_mounted_on_fileid: fileid=41
Sep  2 22:13:21 RAX-NERVE kernel: decode_getfattr_attrs: xdr returned -2097152
Sep  2 22:13:21 RAX-NERVE kernel: decode_getfattr_generic: xdr returned 0
Sep  2 22:13:21 RAX-NERVE kernel: encode_compound: tag=
Sep  2 22:13:21 RAX-NERVE kernel: NFS: nfs_update_inode(0:17/41 fh_crc=0x2947d423 ct=3 info=0x227e7f)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: nfs_fhget(0:17/41 fh_crc=0x2947d423 ct=3)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: nfsi 0xffff880117664930 disabling cache
Sep  2 22:13:21 RAX-NERVE kernel: NFS: permission(0:17/41), mask=0x22, res=0
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write(/ls, 109208@0)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@0)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@0)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@0)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 4096)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@4096)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@4096)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@4096)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 8192)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@8192)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@8192)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@8192)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 12288)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@12288)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@12288)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@12288)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 16384)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@16384)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@16384)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@16384)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 20480)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@20480)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@20480)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@20480)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 24576)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@24576)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@24576)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@24576)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 28672)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@28672)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@28672)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@28672)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 32768)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@32768)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@32768)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@32768)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 36864)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@36864)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@36864)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@36864)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 40960)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@40960)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@40960)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@40960)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 45056)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@45056)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@45056)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@45056)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 49152)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@49152)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@49152)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@49152)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 53248)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@53248)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@53248)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@53248)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 57344)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@57344)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@57344)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@57344)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 61440)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@61440)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@61440)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@61440)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 65536)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@65536)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@65536)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@65536)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 69632)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@69632)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@69632)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@69632)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 73728)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@73728)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@73728)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@73728)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 77824)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@77824)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@77824)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@77824)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 81920)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@81920)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@81920)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@81920)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 86016)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@86016)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@86016)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@86016)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 90112)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@90112)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@90112)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@90112)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 94208)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@94208)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@94208)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@94208)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 98304)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@98304)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@98304)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@98304)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 102400)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 4096@102400)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 4096@102400)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 4096@102400)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 106496)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_begin(/ls(41), 2712@106496)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: write_end(/ls(41), 2712@106496)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage(/ls 2712@106496)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:       nfs_updatepage returns 0 (isize 109208)
Sep  2 22:13:21 RAX-NERVE kernel: NFS: flush(/ls)
Sep  2 22:13:21 RAX-NERVE kernel: NFS:     0 initiated write call (req 0:17/41, 109208 bytes @ offset 0)
Sep  2 22:13:21 RAX-NERVE kernel: <-- nfs4_setup_sequence status=0
Sep  2 22:13:21 RAX-NERVE kernel: encode_compound: tag=
Sep  2 22:14:09 RAX-NERVE kernel: nfs4_renew_state: start
Sep  2 22:14:09 RAX-NERVE kernel: nfs4_renew_state: done
Sep  2 22:15:33 RAX-NERVE kernel: INFO: task cp:2850 blocked for more than 120 seconds.
Sep  2 22:15:33 RAX-NERVE kernel:      Not tainted 2.6.32-642.4.2.el6.x86_64 #1
Sep  2 22:15:33 RAX-NERVE kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep  2 22:15:33 RAX-NERVE kernel: cp            D 0000000000000003     0  2850   2296 0x00000080
Sep  2 22:15:33 RAX-NERVE kernel: ffff88012c3afc78 0000000000000082 ffff88012c3afbc8 ffffffffa051b3ee
Sep  2 22:15:33 RAX-NERVE kernel: ffff88012c3afbf8 ffffffffa051bc90 ffff88012c3afbe8 ffff88012c3afc28
Sep  2 22:15:33 RAX-NERVE kernel: ffff88012c77bc70 ffff880117664af8 ffff88012798fad8 ffff88012c3affd8
Sep  2 22:15:33 RAX-NERVE kernel: Call Trace:
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffffa051b3ee>] ? rpc_make_runnable+0x7e/0x80 [sunrpc]
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffffa051bc90>] ? rpc_execute+0x50/0xa0 [sunrpc]
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff8112e3f0>] ? sync_page+0x0/0x50
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff81549163>] io_schedule+0x73/0xc0
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff8112e42d>] sync_page+0x3d/0x50
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff81549c4f>] __wait_on_bit+0x5f/0x90
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff8112e663>] wait_on_page_bit+0x73/0x80
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff810a6920>] ? wake_bit_function+0x0/0x50
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff811447a5>] ? pagevec_lookup_tag+0x25/0x40
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff8112ea8b>] wait_on_page_writeback_range+0xfb/0x190
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff8112ec58>] filemap_write_and_wait_range+0x78/0x90
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff811cc92e>] vfs_fsync_range+0x7e/0x100
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff811cca1d>] vfs_fsync+0x1d/0x20
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffffa05bb9e0>] nfs_file_flush+0x70/0xa0 [nfs]
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff811967fc>] filp_close+0x3c/0x90
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff811968f5>] sys_close+0xa5/0x100
Sep  2 22:15:33 RAX-NERVE kernel: [<ffffffff8100b0d2>] system_call_fastpath+0x16/0x1b

I have absolutely no idea what could be causing this. Both Windows and OS X clients are able to mount and read/write from these partitions without issue. The devices are plugged directly into the same switch and, apart from a VLAN tag/virtual interface, there's no reason at all for the network to be at fault.

Was able to duplicate the issue on an Ubuntu box, so I'm thinking the fault is with the FreeNAS server itself, but a reinstall didn't do the trick.

0

Managed to solve it.

FreeNAS set a MTU of 9000 by default, which wasn't supported by the NIC. Therefore a bunch of packets were likely being dropped, hence the hang.

The fix was to add "mtu 1400" to the network interface settings.

It was a network issue. Hopefully this helps people in the same position.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.