Date: Mon, 14 Mar 2016 18:48:56 -0500 From: Thomas Johnson <tommyj27@gmail.com> To: freebsd-fs@freebsd.org Subject: Intermittent hangs on VM with NFS-mounted root Message-ID: <CAMwYC7ZJ1YRcnzhDgwgShDQNBemJua=%2BB4-2N8gQ9AXV-dUqxg@mail.gmail.com> In-Reply-To: <CAMwYC7bsDoOogECV0uaU=MeA-_iNZJ%2B=rVS8GK-ehiwm6t%2BrzQ@mail.gmail.com> References: <CAMwYC7bsDoOogECV0uaU=MeA-_iNZJ%2B=rVS8GK-ehiwm6t%2BrzQ@mail.gmail.com>
next in thread | previous in thread | raw e-mail | index | archive | help
I have been trying to track down the cause of an ongoing issue with a FreeBSD 10.2 virtual machine that intermittently gets tied up in knots due to what appears to be an NFS issue. I'm hoping that someone can point me in the direction of a solution, or at least tell me where I might look next. The VM experiencing the issue is PXE-booted, with a number of NFS mounts, including the root. The VM is currently running 10.2, but I experienced the problem with 10.1 and 9.2 as well. This VM runs primarily crontabs that generate a lot of read/write activity on NFS. The VM is running on an ESXi 5.5 hypervisor. The behavior of the VM when it experiences the issue is similar to a host that has lost communication with an NFS server. The kernel seems to remain fully-functional, as do any processes that don't require ongoing access to NFS. For example, cron continues to fork for jobs (the jobs never run), top and tcpdump continue running in established shells. The output of tcpdump appears to show that there is bi-directional communication between the NFS client and server, but it appears to be all small packets, NFS calls such as lookup, access, and getattrs; there are no large data packets (as is the case in normal operation). I also have a shell that runs ps in a loop. The last iteration of this loop before it tips over shows many processes in a newnfs or newnfsre state. In an effort to isolate the cause of the issue, I have moved much of the original workload to other hosts, disabled TSO on the VM, and changed the virtual NIC type (from em to vmx). These measures have had no apparent impact on the host. The NFS server is a Netapp filer. Both client and server are using a 1500-byte MTU. What follows is relevant pieces of system configuration output. I am happy to include anything else that might be useful. * mount * fstab * ifconfig (storage adapter) * ps output (from problem state) tom@puma-2a:~-> mount 10.2.0.1:/vol/pxe/puma on / (nfs, read-only) devfs on /dev (devfs, local, multilabel) /dev/label/var on /mnt/var-disk (ufs, local) /dev/md0 on /md/etc (ufs, local) /dev/md1 on /md/root (ufs, local) /dev/md2 on /var/tmp (ufs, local) <above>:/md/etc on /etc (unionfs) <above>:/md/root on /root (unionfs) <above>:/mnt/var-disk on /var (unionfs) 10.2.0.1:/vol/production on /production (nfs) 10.2.0.1:/vol/archive on /archive (nfs) 10.2.0.1:/vol/home on /home (nfs) 10.2.0.1:/vol/scratch/puma on /scratch/puma (nfs) /dev/md3 on /var/toor (ufs, local) # Device Mountpoint FStype Options Dump Pass# /dev/label/swap none swap sw 0 0 /dev/label/var /mnt/var-disk ufs rw 2 2 md /md/etc mfs rw,-s32m,-S,-p755 2 0 md /md/root mfs rw,-s32m,-S,-p750 0 0 md /tmp mfs rw,-s250m,-S,-p1777 2 0 /md/etc /etc unionfs rw 0 0 /md/root /root unionfs rw 0 0 /mnt/var-disk /var unionfs rw 0 0 10.2.0.1:/vol/production /production nfs rw,wsize=32768,rsize=32768 0 0 10.2.0.1:/vol/archive /archive nfs rw,wsize=32768,rsize=32768 0 0 10.2.0.1:/vol/home /home nfs rw,wsize=32768,rsize=32768 0 0 10.2.0.1:/vol/scratch/puma /scratch/puma nfs rw,wsize=32768,rsize=32768 0 0 tom@puma-2a:~-> ifconfig vmx0 vmx0: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST> metric 0 mtu 1500 options=60009b<RXCSUM,TXCSUM,VLAN_MTU,VLAN_HWTAGGING,VLAN_HWCSUM,RXCSUM_IPV6,TXCSUM_IPV6> ether 00:50:56:03:a4:3e inet 10.2.0.19 netmask 0xffff0000 broadcast 10.2.255.255 inet6 fe80::250:56ff:fe03:a43e%vmx0 prefixlen 64 tentative scopeid 0x1 nd6 options=29<PERFORMNUD,IFDISABLED,AUTO_LINKLOCAL> media: Ethernet autoselect status: active PID PPID UID STAT MWCHAN F ELAPSED PENDING COMMAND 0 0 0 DLs - 10000280 189776 0 [kernel] 1 0 0 ILs wait 10004200 189776 0 - /sbin/init -- 375 1 0 Is select 10000000 189755 0 |-- dhclient: vmx1 [priv] (dhclient) 395 1 65 Is select 10000100 189755 0 |-- dhclient: vmx1 (dhclient) 396 1 0 Is select 10000000 189755 0 |-- /sbin/devd 488 1 928 Ss select 10000181 189754 0 |-- /usr/local/sbin/nslcd 492 1 0 Ss select 10000000 189754 0 |-- /usr/sbin/syslogd -s 619 1 0 Ss select 10000000 189750 0 |-- /usr/sbin/rpcbind 621 1 0 Ss select 10000000 189750 0 |-- /usr/sbin/rpc.statd 630 1 0 Ss rpcsvc 10000000 189750 0 |-- /usr/sbin/rpc.lockd 662 1 0 Ss select 10000080 189750 0 |-- /usr/sbin/ntpd -c /clx_conf/common/ntp.client.conf -p /var/run/ntpd.pid -f /var/db/ntpd.drift 751 1 0 Ds newnfs 10000100 189744 0 |-- /usr/local/libexec/postfix/master -w 753 751 125 I kqread 10004100 189744 0 | |-- qmgr -l -t unix -u 53051 751 125 D newnfs 10004100 2783 0 | |-- pickup -l -t unix -u 58472 751 125 D ufs 10004100 141 0 | `-- showq -t unix -u 758 1 181 Is select 10000100 189744 0 |-- /usr/local/sbin/nrpe2 -c /clx_conf/common/nrpe.cfg -d 788 1 0 Is select 10100100 189744 0 |-- /usr/sbin/sshd 24391 788 0 Ss select 10004100 46905 0 | |-- sshd: toor@pts/6 (sshd) 24401 24391 0 Is wait 10004002 46905 0 | | `-- -sh (sh) 24612 24401 0 I wait 10004002 46900 0 | | `-- ./sh 24999 24612 0 S+ wait 10004002 46890 0 | | `-- /var/toor/toor/rescue/sh ../loop_ps.sh 58719 24999 0 R+ - 10004002 0 0 | | `-- /var/toor/toor/rescue/ps -o pid,ppid,uid,state,mwchan,flags,etimes,sig,command -axwwd 27816 788 0 Ss select 10004100 128850 0 | |-- sshd: root@pts/2 (sshd) 27818 27816 0 Is pause 10004002 128850 0 | | `-- -csh (csh) 29279 27818 0 S+ bpf 10004002 128468 0 | | `-- tcpdump -i vmx0 -vvs 128 host 10.2.0.19 28016 788 0 Ss select 10004100 128764 0 | |-- sshd: root@pts/5 (sshd) 28018 28016 0 Is pause 10004002 128763 0 | | `-- -csh (csh) 28021 28018 0 S+ select 10004002 128763 0 | | `-- top -o cpu 72613 788 0 Is select 10004100 97767 0 | `-- sshd: someuser [priv] (sshd) 72616 72613 103 I select 10000100 97758 0 | `-- sshd: someuser@pts/0 (sshd) 72617 72616 103 Is+ ttyin 10004002 97758 0 | `-- -tcsh (tcsh) 911 1 0 Is select 10100000 189733 0 |-- /usr/sbin/inetd -wW -C 60 926 1 0 Ss select 10000000 189733 0 |-- /usr/sbin/bsnmpd -p /var/run/snmpd.pid 1148 1 0 Is select 10000000 189673 0 |-- screen -dRS cronme /bin/sh -c service cron onestart 2>&1 | /usr/local/bin/cron_dbg_syslog 1149 1148 0 Is+ wait 10004002 189673 0 | `-- /bin/sh -c service cron onestart 2>&1 | /usr/local/bin/cron_dbg_syslog 1150 1149 0 I+ wait 10004002 189673 0 | |-- /bin/sh /etc/rc.d/cron onestart 1157 1150 0 S+ nanslp 10104002 189673 0 | | `-- /usr/sbin/cron -x proc -j 30 -s 58601 1157 0 I+ wait 10000002 62 0 | | |-- cron: running job (cron) 58609 58601 800 Is piperd 10004000 61 0 | | | `-- /usr/sbin/sendmail -FCronDaemon -odi -oem -oi -t 58610 58609 800 D newnfs 10004100 61 0 | | | `-- /usr/local/sbin/postdrop -r 58708 1157 0 S+ piperd 10000002 2 0 | | |-- cron: running job (cron) 58713 58708 800 Ds newnfsre 10004000 2 0 | | | `-- /bin/sh -c (cd *snip* ) 58709 1157 0 D+ ppwait 10000002 2 0 | | |-- cron: running job (cron) 58716 58709 0 SV+ nanslp 10000012 2 0 | | | `-- cron: running job (cron) 58711 1157 0 D+ ppwait 10000002 2 0 | | `-- cron: running job (cron) 58714 58711 0 SV+ nanslp 10000012 2 0 | | `-- cron: running job (cron) 1151 1149 0 S+ piperd 10004002 189673 0 | `-- /usr/local/bin/perl /usr/local/bin/cron_dbg_syslog 2589 1 0 Ss kqread 10000080 71702 0 |-- /usr/sbin/nscd 58677 1 181 I wait 10000100 21 0 |-- /usr/local/sbin/nrpe2 -c /clx_conf/common/nrpe.cfg -d 58678 58677 181 I piperd 10000100 21 0 | `-- /usr/local/sbin/nrpe2 -c /clx_conf/common/nrpe.cfg -d 58679 58678 181 I piperd 10004000 21 0 | `-- /usr/local/bin/perl /clx_conf/common/nrpe2/check_postqueue 58680 58679 181 I wait 10004000 21 0 | `-- sh -c /usr/local/sbin/postqueue -p 2>&1 | tail -n 2 58681 58680 181 D newnfs 10004100 21 0 | |-- /usr/local/sbin/postqueue -p 58682 58680 181 I piperd 10004000 21 0 | `-- tail -n 2 875 1 800 S select 10004002 189733 0 |-- /usr/bin/perl /lynx/bin/sphynx2 936 1 0 Is+ ttyin 10004002 189733 0 |-- /usr/libexec/getty Pc ttyv0 937 1 0 Is+ ttyin 10004002 189733 0 |-- /usr/libexec/getty Pc ttyv1 938 1 0 Is+ ttyin 10004002 189733 0 |-- /usr/libexec/getty Pc ttyv2 939 1 0 Is+ ttyin 10004002 189733 0 |-- /usr/libexec/getty Pc ttyv3 940 1 0 Is+ ttyin 10004002 189733 0 |-- /usr/libexec/getty Pc ttyv4 941 1 0 Is+ ttyin 10004002 189733 0 |-- /usr/libexec/getty Pc ttyv5 942 1 0 Is+ ttyin 10004002 189733 0 |-- /usr/libexec/getty Pc ttyv6 943 1 0 Is+ ttyin 10004002 189733 0 `-- /usr/libexec/getty Pc ttyv7 2 0 0 DL - 10000284 189776 0 - [cam] 3 0 0 DL idle 10000204 189776 0 - [mpt_recovery0] 4 0 0 DL - 10000204 189776 0 - [fdc0] 5 0 0 DL waiting_ 10000204 189776 0 - [sctp_iterator] 6 0 0 DL umarcl 10000284 189776 0 - [pagedaemon] 7 0 0 DL psleep 10000204 189776 0 - [vmdaemon] 8 0 0 DL pgzero 10000204 189776 0 - [pagezero] 9 0 0 DL psleep 10000204 189776 0 - [bufdaemon] 10 0 0 DL audit_wo 10000204 189776 0 - [audit] 11 0 0 RL - 10000284 189776 0 - [idle] 12 0 0 WL - 10000284 189776 0 - [intr] 13 0 0 DL - 10000284 189776 0 - [geom] 14 0 0 DL - 10000204 189776 0 - [rand_harvestq] 15 0 0 DL vlruwt 10000204 189776 0 - [vnlru] 16 0 0 DL syncer 10000204 189776 0 - [syncer] 71 0 0 DL mdwait 10000204 189761 0 - [md0] 76 0 0 DL mdwait 10000204 189761 0 - [md1] 81 0 0 DL mdwait 10000204 189761 0 - [md2] 21304 0 0 DL mdwait 10000204 47452 0 - [md3]
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAMwYC7ZJ1YRcnzhDgwgShDQNBemJua=%2BB4-2N8gQ9AXV-dUqxg>