[Xen-API] Debian Wheezy xcp-xapi winbind hangs and times out on shutdown

[David Christensen <dpchrist@xxxxxxxxxxxxxxxx>]

xen-xapi:

I recently built a new computer with Debian Wheezy and xcp-xapi.  I've 
noticed that winbind hangs and times out on shutdown.  I can't remember 
if this happened prior to installing xcp-xapi (?).

How do I troubleshoot winbind hanging on shutdown?


TIA,

David

--

2012-04-30 08:54:31 root@i72600s ~
# cat /etc/default/winbind
# Defaults for winbind initscript
# sourced by /etc/init.d/winbind
#

#
# This is a POSIX shell fragment
#


# Winbind configuration
#WINBINDD_OPTS="-n"



2012-04-30 08:55:44 root@i72600s ~
# cat /etc/init.d/winbind
#!/bin/sh

### BEGIN INIT INFO
# Provides:          winbind
# Required-Start:    $network $remote_fs $syslog
# Required-Stop:     $network $remote_fs $syslog
# Default-Start:     2 3 4 5
# Default-Stop:      0 1 6
# Short-Description: start Winbind daemon
### END INIT INFO


PATH=/sbin:/bin:/usr/sbin:/usr/bin

[ -r /etc/default/winbind ] && . /etc/default/winbind

DAEMON=/usr/sbin/winbindd
PIDDIR=/var/run/samba
WINBINDPID=$PIDDIR/winbindd.pid

# clear conflicting settings from the environment
unset TMPDIR

# See if the daemon is there
test -x $DAEMON || exit 0

. /lib/lsb/init-functions

case "$1" in
        start)
                log_daemon_msg "Starting the Winbind daemon" "winbind"

                mkdir -p /var/run/samba/winbindd_privileged || return 1
                chgrp winbindd_priv $PIDDIR/winbindd_privileged/ || return 1
                chmod 0750 $PIDDIR/winbindd_privileged/ || return 1
		start-stop-daemon --start --quiet --oknodo --exec $DAEMON -- 
$WINBINDD_OPTS
                log_end_msg $?
                ;;

        stop)
                log_daemon_msg "Stopping the Winbind daemon" "winbind"
                start-stop-daemon --stop --quiet --oknodo --exec $DAEMON
                log_end_msg $?
                ;;

        restart|force-reload)
                $0 stop && sleep 2 && $0 start
                ;;

        status)
                status_of_proc -p $WINBINDPID $DAEMON winbind && exit 0 || exit 
$?
                ;;
        *)
                echo "Usage: /etc/init.d/winbind 
{start|stop|restart|force-reload|status}"
                exit 1
                ;;
esac




2012-04-30 08:59:02 root@i72600s ~
# grep -r winbind /var/log/*
/var/log/apt/term.log:Selecting previously unselected package winbind.
/var/log/apt/term.log:Unpacking winbind (from 
.../winbind_2%3a3.6.4-1_amd64.deb) ...
/var/log/apt/term.log:Selecting previously unselected package 
libpam-winbind:amd64.
/var/log/apt/term.log:Unpacking libpam-winbind:amd64 (from 
.../libpam-winbind_2%3a3.6.4-1_amd64.deb) ...
/var/log/apt/term.log:Setting up winbind (2:3.6.4-1) ...
/var/log/apt/term.log:Starting the Winbind daemon: winbind.
/var/log/apt/term.log:Setting up libpam-winbind:amd64 (2:3.6.4-1) ...
/var/log/apt/history.log:Install: blktap-dkms:amd64 (2.0.91-1, 
automatic), libpam-winbind:amd64 (3.6.4-1, automatic), 
linux-headers-amd64:amd64 (3.2+44, automatic), uuid-runtime:amd64 
(2.20.1-4, automatic), fakeroot:amd64 (1.18.2-1, automatic), 
librbd1:amd64 (0.43-1, automatic), xcp-storage-managers:amd64 (0.1.1-2, 
automatic), xen-hypervisor-4.1-amd64:amd64 (4.1.2-2, automatic), 
xen-utils-common:amd64 (4.1.2-1, automatic), qemu-keymaps:amd64 
(1.0.1+dfsg-1, automatic), libaio1:amd64 (0.3.109-2, automatic), 
libcrypto++9:amd64 (5.6.1-6, automatic), smbfs:amd64 (5.3-2, automatic), 
libiscsi1:amd64 (1.0.1-1, automatic), xcp-vncterm:amd64 (0.1-2, 
automatic), xen-utils-4.1:amd64 (4.1.2-2, automatic), 
libblktapctl0:amd64 (2.0.90-1, automatic), librados2:amd64 (0.43-1, 
automatic), libvhdio-2.0.90:amd64 (2.0.90-1, automatic), 
libxenstore3.0:amd64 (4.1.2-2, automatic), gcc-4.6:amd64 (4.6.3-1, 
automatic), libvhd0:amd64 (2.0.90-1, automatic), stunnel4:amd64 (4.52-1, 
automatic), linux-headers-3.2.0-2-amd64:amd64 (3.2.15-1, automatic), 
xcp-squeezed:amd64 (1.3-16, automatic), xcp-eliloader:amd64 (0.1-4, 
automatic), gcc:amd64 (4.6.2-4, automatic), python-xenapi:amd64 (1.3-16, 
automatic), dkms:amd64 (2.2.0.3-1, automatic), gawk:amd64 (4.0.1+dfsg-1, 
automatic), linux-kbuild-3.2:amd64 (3.2.7-2, automatic), 
blktap-utils:amd64 (2.0.90-1, automatic), libc6-dev:amd64 (2.13-30, 
automatic), libsigsegv2:amd64 (2.9-4, automatic), cifs-utils:amd64 
(5.3-2, automatic), qemu-utils:amd64 (1.0.1+dfsg-1, automatic), 
xcp-guest-templates:amd64 (0.1-3, automatic), libxen-4.1:amd64 (4.1.2-2, 
automatic), xcp-v6d:amd64 (1.3-16, automatic), linux-libc-dev:amd64 
(3.2.15-1, automatic), xcp-xapi:amd64 (1.3-16), manpages-dev:amd64 
(3.35-0.1, automatic), winbind:amd64 (3.6.4-1, automatic), 
bridge-utils:amd64 (1.5-2, automatic), libc-dev-bin:amd64 (2.13-30, 
automatic), binutils:amd64 (2.22-6, automatic), xcp-fe:amd64 (0.5.2-3, 
automatic), keyutils:amd64 (1.5.5-2, automatic), 
linux-headers-3.2.0-2-common:amd64 (3.2.15-1, automatic), make:amd64 
(3.81-8.2, automatic), xcp-xe:amd64 (1.3-16, automatic), 
xenstore-utils:amd64 (4.1.2-2, automatic)
/var/log/auth.log.1:Apr 27 21:42:20 i72600s groupadd[8456]: group added 
to /etc/group: name=winbindd_priv, GID=123
/var/log/auth.log.1:Apr 27 21:42:20 i72600s groupadd[8456]: group added 
to /etc/gshadow: name=winbindd_priv
/var/log/auth.log.1:Apr 27 21:42:20 i72600s groupadd[8456]: new group: 
name=winbindd_priv, GID=123
/var/log/auth.log.1:Apr 28 14:18:00 i72600s gdm-session-worker[4597]: 
pam_winbind(gdm3:auth): getting password (0x00000388)
/var/log/auth.log.1:Apr 28 14:18:00 i72600s gdm-session-worker[4597]: 
pam_winbind(gdm3:auth): Could not retrieve user's password
/var/log/dpkg.log:2012-04-27 21:41:59 install winbind:amd64 <none> 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status half-installed 
winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status half-installed 
winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status unpacked winbind:amd64 
2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status unpacked winbind:amd64 
2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 install libpam-winbind:amd64 
<none> 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status half-installed 
libpam-winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status half-installed 
libpam-winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status unpacked 
libpam-winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:41:59 status unpacked 
libpam-winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:19 configure winbind:amd64 2:3.6.4-1 
<none>
/var/log/dpkg.log:2012-04-27 21:42:19 status unpacked winbind:amd64 
2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:19 status unpacked winbind:amd64 
2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:19 status unpacked winbind:amd64 
2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:19 status unpacked winbind:amd64 
2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:19 status half-configured 
winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:20 status installed winbind:amd64 
2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:20 configure libpam-winbind:amd64 
2:3.6.4-1 <none>
/var/log/dpkg.log:2012-04-27 21:42:20 status unpacked 
libpam-winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:20 status half-configured 
libpam-winbind:amd64 2:3.6.4-1
/var/log/dpkg.log:2012-04-27 21:42:20 status installed 
libpam-winbind:amd64 2:3.6.4-1
/var/log/samba/log.winbindd:[2012/04/29 11:58:07.387607,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.winbindd:[2012/04/29 15:31:06,  0] 
winbindd/winbindd.c:1336(main)
/var/log/samba/log.winbindd:  winbindd version 3.6.4 started.
/var/log/samba/log.winbindd:[2012/04/29 15:31:06.042410,  0] 
winbindd/winbindd_cache.c:3147(initialize_winbindd_cache)
/var/log/samba/log.winbindd:  initialize_winbindd_cache: clearing cache 
and re-creating with version number 2
/var/log/samba/log.winbindd:[2012/04/29 16:01:00.913425,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.winbindd:[2012/04/29 16:02:29,  0] 
winbindd/winbindd.c:1336(main)
/var/log/samba/log.winbindd:  winbindd version 3.6.4 started.
/var/log/samba/log.winbindd:[2012/04/29 16:02:29.484990,  0] 
winbindd/winbindd_cache.c:3147(initialize_winbindd_cache)
/var/log/samba/log.winbindd:  initialize_winbindd_cache: clearing cache 
and re-creating with version number 2
/var/log/samba/log.winbindd:[2012/04/29 23:15:58.121524,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.winbindd:[2012/04/30 08:49:10,  0] 
winbindd/winbindd.c:1336(main)
/var/log/samba/log.winbindd:  winbindd version 3.6.4 started.
/var/log/samba/log.winbindd:[2012/04/30 08:49:10.842746,  0] 
winbindd/winbindd_cache.c:3147(initialize_winbindd_cache)
/var/log/samba/log.winbindd:  initialize_winbindd_cache: clearing cache 
and re-creating with version number 2
/var/log/samba/log.wb-I72600S:[2012/04/27 21:58:12.012104,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/27 23:07:24.660043,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/27 23:25:13.050986,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/28 14:18:06.280048,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/28 15:38:35.138139,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/28 16:21:02.391059,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/29 11:58:07.387594,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/29 16:01:00.913603,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)
/var/log/samba/log.wb-I72600S:[2012/04/29 23:15:58.121520,  0] 
winbindd/winbindd.c:211(winbindd_sig_term_handler)


2012-04-30 09:06:54 root@i72600s ~
# grep 'Apr 29 23' /var/log/messages
Apr 29 23:15:54 i72600s shutdown[3437]: shutting down for system halt
Apr 29 23:16:28 i72600s rsyslogd-2177: imuxsock begins to drop messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:34 i72600s rsyslogd-2177: imuxsock lost 282210 messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:34 i72600s rsyslogd-2177: imuxsock begins to drop messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:40 i72600s rsyslogd-2177: imuxsock lost 286410 messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:40 i72600s rsyslogd-2177: imuxsock begins to drop messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:46 i72600s rsyslogd-2177: imuxsock lost 289712 messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:46 i72600s rsyslogd-2177: imuxsock begins to drop messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:52 i72600s rsyslogd-2177: imuxsock lost 290233 messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:52 i72600s rsyslogd-2177: imuxsock begins to drop messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:58 i72600s rsyslogd-2177: imuxsock lost 290022 messages 
from pid 2313 due to rate-limiting
Apr 29 23:16:58 i72600s rsyslogd-2177: imuxsock begins to drop messages 
from pid 2313 due to rate-limiting
Apr 29 23:17:00 i72600s kernel: Kernel logging (proc) stopped.
Apr 29 23:17:00 i72600s rsyslogd: [origin software="rsyslogd" 
swVersion="5.8.10" x-pid="1476" x-info="http://www.rsyslog.com";] exiting 
on signal 15.

_______________________________________________
Xen-api mailing list
Xen-api@xxxxxxxxxxxxx
http://lists.xen.org/cgi-bin/mailman/listinfo/xen-api