From owner-freebsd-fs@FreeBSD.ORG Tue Oct 2 10:26:42 2012 Return-Path: Delivered-To: freebsd-fs@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id 421DA10657AC for ; Tue, 2 Oct 2012 10:26:42 +0000 (UTC) (envelope-from ndenev@gmail.com) Received: from mail-we0-f182.google.com (mail-we0-f182.google.com [74.125.82.182]) by mx1.freebsd.org (Postfix) with ESMTP id B05878FC1C for ; Tue, 2 Oct 2012 10:26:41 +0000 (UTC) Received: by weyx43 with SMTP id x43so4129410wey.13 for ; Tue, 02 Oct 2012 03:26:40 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=from:content-type:date:subject:to:message-id:mime-version:x-mailer; bh=2mTea3Pr3WQ3nGmHPK5viRi6VkZex1MOw1gVS+/A7/E=; b=It77GCUMDC3r6WWP4Zt47FdVXqvvfWgyfRJR7u5FbGiWuP0kFCjvZYdxLy4a66wezd 2NQX4HGnwpCeJxxl0885N0MyQhtZSTzsS625Xh7AkPOk5Iz9XD/O4CZVXC6qqryLBDys ucMV/3bceLzAJafbculb9XAFs/B9TADH2ggNnZUujQ22g5qEeqppB6q1RQIJqVX7fpTg FI6zoyQioawRwzGxjWIAlxi13l1wOLWfeOdrxoM/rOMAx/j398LxVwNLjZWHfSqG36Vk 8ytIPdYPTUAqq8MQsTsol3wciekmioOmDdp0yCsSeOdE6dCDIXGbZytIBv6yEwGMYVDh fykQ== Received: by 10.180.80.33 with SMTP id o1mr17716714wix.14.1349173600387; Tue, 02 Oct 2012 03:26:40 -0700 (PDT) Received: from ndenevsa.sf.moneybookers.net (g1.moneybookers.com. [217.18.249.148]) by mx.google.com with ESMTPS id k20sm20963599wiv.11.2012.10.02.03.26.38 (version=TLSv1/SSLv3 cipher=OTHER); Tue, 02 Oct 2012 03:26:39 -0700 (PDT) From: Nikolay Denev Date: Tue, 2 Oct 2012 13:26:37 +0300 To: "" Message-Id: <906543F2-96BD-4519-B693-FD5AFB646F87@gmail.com> Mime-Version: 1.0 (Mac OS X Mail 6.1 \(1498\)) X-Mailer: Apple Mail (2.1498) Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: quoted-printable X-Content-Filtered-By: Mailman/MimeDel 2.1.5 Cc: Subject: nfs + zfs hangs on RELENG_9 X-BeenThere: freebsd-fs@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Filesystems List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 02 Oct 2012 10:26:42 -0000 Hi, I'm experimenting on a machine with both CTL and NFS exports to a Linux = host to run a Oracle DB instance. And now I'm seeing for a second time a ZFS IO hang after some activity = over the NFS mount. Now all IO to the pool where the NFS share is hangs, for example I did : root@goliath:/home/ndenev # du -ach /tank And it just hangs in there. procstat -kk output of the dd command : root@goliath:/home/ndenev # procstat -kk 38266 PID TID COMM TDNAME KSTACK = =20 38266 101997 du - mi_switch+0x186 = sleepq_wait+0x42 _cv_wait+0x121 txg_wait_open+0x85 dmu_tx_assign+0x170 = zfs_inactive+0xf1 zfs_freebsd_inactive+0x1a vinactive+0x8d vputx+0x2d8 = sys_fchdir+0x35a amd64_syscall+0x546 Xfast_syscall+0xf7=20 nfsd process is also in D state : root 1420 0.0 0.0 9912 584 ?? Ss Thu08PM 0:00.04 nfsd: = master (nfsd) root 1422 0.0 0.0 9912 2332 ?? D Thu08PM 5347:34.58 nfsd: = server (nfsd) root@goliath:/home/ndenev # procstat -kk 1420 PID TID COMM TDNAME KSTACK = =20 1420 100740 nfsd - mi_switch+0x186 = sleepq_catch_signals+0x2cc sleepq_wait_sig+0xc _cv_wait_sig+0x12e = seltdwait+0x110 kern_select+0x6ed sys_select+0x5d amd64_syscall+0x546 = Xfast_syscall+0xf7=20 root@goliath:/home/ndenev # procstat -kk 1422 PID TID COMM TDNAME KSTACK = =20 1422 101178 nfsd nfsd: master mi_switch+0x186 = sleepq_wait+0x42 _sx_xlock_hard+0x428 _sx_xlock+0x51 arc_buf_evict+0x84 = dbuf_clear+0x91 dbuf_free_range+0x469 dnode_free_range+0x2c4 = dmu_free_long_range_impl+0x13d dmu_free_long_range+0x4c zfs_rmnode+0x69 = zfs_inactive+0x66 zfs_freebsd_inactive+0x1a vinactive+0x8d vputx+0x2d8 = zfs_freebsd_rename+0xe1 VOP_RENAME_APV+0x46 nfsvno_rename+0x2cc=20 [=85 showing only master thread, as I'm running with maxthreads 196 and = the output is too verbose, I can provide it if needed =85]=20 There are these two kernel threads that look also waiting on some lock : 0 100423 kernel zio_write_intr_6 mi_switch+0x186 = sleepq_wait+0x42 _sx_xlock_hard+0x428 _sx_xlock+0x51 = buf_hash_insert+0x56 arc_write_done+0x8e zio_done+0x2ee zio_execute+0xc3 = zio_done+0x367 zio_execute+0xc3 zio_done+0x367 zio_execute+0xc3 = zio_done+0x367 zio_execute+0xc3 zio_done+0x367 zio_execute+0xc3 = zio_done+0x367 zio_execute+0xc3=20 0 101699 kernel zio_write_intr_7 mi_switch+0x186 = sleepq_wait+0x42 _sx_xlock_hard+0x428 _sx_xlock+0x51 = buf_hash_insert+0x56 arc_write_done+0x8e zio_done+0x2ee zio_execute+0xc3 = zio_done+0x367 zio_execute+0xc3 zio_done+0x367 zio_execute+0xc3 = taskqueue_run_locked+0x85 taskqueue_thread_loop+0x46 fork_exit+0x11f = fork_trampoline+0xe=20 And these threads are from zfskern kernel process : root@goliath:/home/ndenev # procstat -kk 7 PID TID COMM TDNAME KSTACK = =20 7 100192 zfskern arc_reclaim_thre mi_switch+0x186 = sleepq_wait+0x42 _sx_xlock_hard+0x428 _sx_xlock+0x51 = arc_buf_remove_ref+0x8a dbuf_rele_and_unlock+0x132 dbuf_evict+0x11 = dbuf_do_evict+0x53 arc_do_user_evicts+0xb4 arc_reclaim_thread+0x263 = fork_exit+0x11f fork_trampoline+0xe=20 7 100193 zfskern l2arc_feed_threa mi_switch+0x186 = sleepq_timedwait+0x42 _cv_timedwait+0x13c l2arc_feed_thread+0x1a3 = fork_exit+0x11f fork_trampoline+0xe=20 7 100536 zfskern txg_thread_enter mi_switch+0x186 = sleepq_wait+0x42 _cv_wait+0x121 txg_thread_wait+0x79 = txg_quiesce_thread+0xb5 fork_exit+0x11f fork_trampoline+0xe=20 7 100537 zfskern txg_thread_enter mi_switch+0x186 = sleepq_wait+0x42 _cv_wait+0x121 zio_wait+0x61 dsl_pool_sync+0xe0 = spa_sync+0x336 txg_sync_thread+0x136 fork_exit+0x11f fork_trampoline+0xe=20= 7 101811 zfskern txg_thread_enter mi_switch+0x186 = sleepq_wait+0x42 _cv_wait+0x121 txg_quiesce_thread+0x1fb fork_exit+0x11f = fork_trampoline+0xe=20 7 101812 zfskern txg_thread_enter mi_switch+0x186 = sleepq_wait+0x42 _cv_wait+0x121 zio_wait+0x61 dsl_pool_sync+0x2c3 = spa_sync+0x336 txg_sync_thread+0x136 fork_exit+0x11f fork_trampoline+0xe=20= 7 101813 zfskern zvol tank/oracle mi_switch+0x186 = sleepq_wait+0x42 _cv_wait+0x121 txg_wait_open+0x85 dmu_tx_assign+0x170 = zvol_strategy+0x27a zvol_geom_worker+0xf9 fork_exit+0x11f = fork_trampoline+0xe=20 7 101817 zfskern zvol tank/oracle mi_switch+0x186 = sleepq_wait+0x42 _sleep+0x390 zvol_geom_worker+0xec fork_exit+0x11f = fork_trampoline+0xe=20 7 101822 zfskern zvol tank/oracle mi_switch+0x186 = sleepq_wait+0x42 _sleep+0x390 zvol_geom_worker+0xec fork_exit+0x11f = fork_trampoline+0xe=20 7 101824 zfskern zvol tank/oracle mi_switch+0x186 = sleepq_wait+0x42 _cv_wait+0x121 txg_wait_open+0x85 dmu_tx_assign+0x170 = zvol_strategy+0x27a zvol_geom_worker+0xf9 fork_exit+0x11f = fork_trampoline+0xe=20 I'm running with the following NFS settings : nfs_server_enable=3D"YES" nfsv4_server_enable=3D"YES" nfsuserd_enable=3D"YES" rpc_statd_enable=3D"YES" rpc_lockd_enable=3D"YES" vfs.nfsd.minthreads=3D32 vfs.nfsd.maxthreads=3D196 root@goliath:/home/ndenev # cat /etc/exports V4: /tank -sec=3Dsys -network 10.0.0.0/8 /tank/oracle_db2 -maproot=3Droot -alldirs -network 10.XX.XX.XX = -mask 255.255.255.255=20 And the mount on the Linux machine is : goliath.neterra.moneybookers.net:/tank/oracle_db2 /mnt/goliath2 nfs = rw,bg,hard,nointr,tcp,actimeo=3D0,vers=3D3,timeo=3D600,rsize=3D32768,wsize= =3D32768 0 0 Any idea how this IO hang can be debugged further? Maybe more = information (or less :) ) is needed?